Timestamp in logfile

Asked by Steen

import logging
logging.__init__(0)
logging.basicConfig(filename="C:\\Users\\user\\Desktop\\Iconlogfile.log", level=logging.INFO)

and then use:
logging.info('device picked and ready for test')
everytime i have to print to log file.

everything works!....great...:0)

But i need timestamp of every post
so instead of:
INFO:root:DB8 MKII picked and ready for test
INFO:root:software found

i would like:
11:10:10:DB8 MKII picked and ready for test
11.10.20:software found

and so on?

Question information

Language:
English Edit question
Status:
Solved
For:
SikuliX Edit question
Assignee:
No assignee Edit question
Solved by:
RaiMan
Solved:
Last query:
Last reply:
Revision history for this message
RaiMan (raimund-hocke) said :
#1

tstamp = time.strftime("%H:%M:%S")

found at ;-) http://docs.python.org/library/time.html#time.strftime

import time not necessary, already done by Sikuli.

Revision history for this message
RaiMan (raimund-hocke) said :
#2

BTW: to compose the log message you can use the % operator:

e.g.

logMsg "%s %s"%(time.strftime("%H:%M:%S"), "some message text")

Revision history for this message
Steen (steenc) said :
#3

could you do an example of my code?

been looking on that at python but cant make it work.

Revision history for this message
Best RaiMan (raimund-hocke) said :
#4

???? all you need is in the 2 comments above

here you are:

logging.info("%s %s"%(time.strftime("%H:%M:%S"), 'device picked and ready for test'))

Revision history for this message
Steen (steenc) said :
#5

fantastisk....THX....

Revision history for this message
Steen (steenc) said :
#6

Thanks RaiMan, that solved my question.

Revision history for this message
Jason D Tran (jasondtran) said :
#7

When you specify:

logging.basicConfig(filename="C:\\Users\\user\\Desktop\\Iconlogfile.log", level=logging.INFO)

Is it in append mode already? (File will be created if it's not exist, and new info will be appended at the end if it's already exist)

Also, how would you open and close file for logging?

Revision history for this message
Steen (steenc) said :
#8

@Jason
yes it appends.

i have made this:
to start:
import logging
import os

#show all levels (INFO, WARNING, ERROR)
logger.setLevel(logging.INFO)

the use in the script:
logger.info('your pants are going to burn')
logger.warning('your pants are soaked in petrol')
logger.error('you are now burning')

at the end of script:
logger.removeHandler(hdlr)
logging.shutdown

Revision history for this message
Jason D Tran (jasondtran) said :
#9

Thanks for your response Steen!

I got this error when tried your suggestion:
NameError: name 'logger' is not defined

I am more interested in writing log into a file. I want to write a log file whether a test case is failed or passed after it's executed. Thanks!

Revision history for this message
RaiMan (raimund-hocke) said :
#10

@ Jason

The example in comment #8 is not correct.
As it is written, all words "logger" have to be replaced by "logging".
And you have to add a
logging.basicConfig(filename=r"C:\some-folder\mylogfile.txt", level=logging.INFO)

to tell the logging handler to what file to append your messages.

A good starting point for the use of Python's logging feature is:
http://docs.python.org/howto/logging.html#logging-basic-tutorial

--- I want to write a log file whether a test case is failed or passed after it's executed.
What are you talking about?
- test cases in Sikuli IDE's unit test feature?
- test cases in Sikuli scripts using Python's unittest feature? (see faq 1804)
- or what else? coding example?

Revision history for this message
Jason D Tran (jasondtran) said :
#11

@ RaiMan

I tried this and it worked the first run (log file created with log info), but I got error on second and there after:

import logging
logging.basicConfig(filename='/Users/fitlab/SikuliLog/new.log',level=logging.DEBUG)
logging.debug('This message should go to the log file')
logging.info('So should this')
logging.warning('And this, too')

------
Traceback (most recent call last):
 File "/Applications/Sikuli-IDE.app/Contents/Resources/Java/sikuli-script.jar/Lib/logging/__init__.py", line 750, in emit
 File "/Applications/Sikuli-IDE.app/Contents/Resources/Java/sikuli-script.jar/Lib/logging/__init__.py", line 750, in emit
ValueError: I/O operation on closed file

Do I need to open/close file? and how?

Another interesting thing: run same script on another Mac system, log file was not created. Any idea?

Revision history for this message
RaiMan (raimund-hocke) said :
#12

@ Jason

There seems to be some conflict with Sikuli's own use of Python's logging feature.

So you should use your own logging handler.

This is a basic template for messages going to a file:

import logging # once at beginning of script

# initialization
myHandler = logging.FileHandler('/Users/fitlab/SikuliLog/new.log')
myLog = logging.getLogger()
myLog.addHandler(myHandler)
myLog.setLevel(logging.DEBUG)

# usage
myLog.debug('This message should go to the log file')
myLog.info('So should this')
myLog.warning('And this, too')

# shutdown (a must in the IDE ! )
myHandler.close()

This worked as expected on my Mac Lion.

--- log file was not created ??
using
myHandler = logging.FileHandler('/Users/fitlab/SikuliLog/new.log')

the folder
/Users/fitlab/SikuliLog

has to be there (not auto created) before running the script.

Revision history for this message
Jason D Tran (jasondtran) said :
#13

Thanks so much for helping, RaiMan!

Trying your suggested script: It works, but I got this error:

Traceback (most recent call last):
 File "/Applications/Sikuli-IDE.app/Contents/Resources/Java/sikuli-script.jar/Lib/logging/__init__.py", line 750, in emit
 File "/Applications/Sikuli-IDE.app/Contents/Resources/Java/sikuli-script.jar/Lib/logging/__init__.py", line 750, in emit
ValueError: I/O operation on closed file

----

I also see this error after playing with above script for awhile (Python version in my Mac Lion is 2.7.1):

Traceback (most recent call last):
 File "/var/folders/__/xmjv8nnd0rd6bqvrpbggrfd80000gn/T/sikuli-tmp7724115150528538567.py", line 1, in
 import logging
 File "/Applications/Sikuli-IDE.app/Contents/Resources/Java/sikuli-script.jar/Lib/sikuli/SikuliImporter.py", line 45, in load_module
 File "/Applications/Sikuli-IDE.app/Contents/Resources/Java/sikuli-script.jar/Lib/sikuli/SikuliImporter.py", line 25, in _load_module
ImportError: No module named logging

Revision history for this message
RaiMan (raimund-hocke) said :
#14

--- Python version in my Mac Lion is 2.7.1
@ Jason

Python has nothing to do with Sikuli. All modules that are needed by the Jython interpreter, that comes bundled with Sikuli, are taken from from within the normal Sikuli installation.

With a few exceptions (modules written in pure Python) standard C-Python modules cannot be used with Jython/Sikuli. Furthermore Sikuli's Jython (as Jython generally in the moment) is on "Python language level" 2.5.

--- I also see this error after playing with above script for awhile
Not sure what you mean by that: running it over and over again or making changes/additions.
This kind of import error usually happens, if the module (logging in this case) cannot be found on sys.path (did you make any changes to that?) or if a folder logging.sikuli can be found by Sikuli's import feature, that is invalid.

--- ValueError: I/O operation on closed file
What is done on this line 750?
The error message tells, that logging.__init__ is run. This should only happen once at the beginning of a script. Do not place more than one "import logging" statement in your script.

Revision history for this message
RaiMan (raimund-hocke) said :
#15

@Jason

Sorry, the last topic was rubbish ;-)

--- ValueError: I/O operation on closed file
What is done on the line in the script, that caused the error?
The error message tells, that logging.__init__ is run. This should only happen once at the beginning of a script. Do not place more than one "import logging" statement in your script.

Revision history for this message
Jason D Tran (jasondtran) said :
#16

Basically, I just run the script that you provided.

1st time: info is wrote to log file
2nd time and after: info is wrote to log file, but I also see "ValueError: I/O operation on closed file"

Regarding "ImportError: No module named logging", I closed the file then reboot system then try again, I am not see the error anymore... it's kinda weird.

Revision history for this message
RaiMan (raimund-hocke) said :
#17

please send me the .sikuli zipped to my mail at https://launchpad.net/~raimund-hocke

I have to check it myself.

Revision history for this message
RaiMan (raimund-hocke) said :
#18

@ Jason
I checked the situation again with the script you sent me.

--1. script naming
A script should not be named like a module, that you are importing in the script itself. This collides with Sikuli's support for importing other Sikuli scripts.
So I first had to rename the script to something else than Logging.sikuli, to get the import logging to work at all.
You have to do this too.

--2. ValueError: I/O operation on closed file
This error happens in the __init__.py module of the logging module, when import is processed. There seems to be some bug.
Using the following sequence instead of the simple import, solves the problem:

# once at beginning of script
import logging
reload(logging)

Revision history for this message
RaiMan (raimund-hocke) said :
#19

@ Jason

The log file extension ".log" seems to collide with Sikuli's import feature and Sikuli's internal use of the logging feature.
You might get Sikuli messages into your log file.

I found that naming the log files with an extension .txt avoids this problem situation.

Revision history for this message
Jason D Tran (jasondtran) said :
#20

Thanks! That resolved the issues.

What is your suggestion about write to a log file from multiple scripts? As below example, the Suite script would call Create script, and I want to able to write to log file within Create script also.

==========================

suite.sikuli
-----
from sikuli import*

import logging # once at beginning of script
reload(logging)

# initialization
myHandler = logging.FileHandler('/Users/fitlab/SikuliLog/new.txt')
myLog = logging.getLogger()
myLog.addHandler(myHandler)
myLog.setLevel(logging.DEBUG)

import Create

myLog.info('Calling Create script...')
Create.MyCreate()

# shutdown (a must in the IDE ! )
myHandler.close()

create.sikuli
---
from sikuli import *
def MyCreate():
   openApp("Safari")
   myLog.info("launch Safari")

Revision history for this message
RaiMan (raimund-hocke) said :
#21

@ Jason
Might be the time, to think about posting extra questions ;-)

It seems, that you are going into more complex structures.
So you have to think about the usage of classes, that would give you more flexibility and features.

Taking your example using a class (quick and dirty ;-):

==========================

# -------------------------- suite.sikuli
from sikuli import*

import logging # once at beginning of script
reload(logging)

# initialization
myHandler = logging.FileHandler('/Users/fitlab/SikuliLog/new.txt')
myLog = logging.getLogger()
myLog.addHandler(myHandler)
myLog.setLevel(logging.DEBUG)

from create import *

myLog.info('Calling Create script...')
aSafari = myApp("Safari", myLog)
aSafari.create()

# shutdown (a must in the IDE ! )
myHandler.close()

# -------------------------- create.sikuli
from sikuli import *

class myApp:

    def __init__(self, appname, myLogger = None):
        if appname:
            self.appname = appname
        else:
            self.appname = "no-app-given
        self.myLogger = myLogger

    def create(self):
       openApp(self.appname)
       if self.myLogger: self.myLogger.info("launch "+self.appname)

With this approach, you can enrich the class myApp with every functionality you need and use it with every app. You might even create a subclass with additional features for Safar (e.g. open an url).

On Top it makes sense, to wrap the logging into your own class, to get more possibilities to control the logging in the different corners of your solution.