CODEWITHSUNDEEP
python
susja
susja

Reputation: 321

Time formatting using logging module in python

I am planning to use logging module to monitor elapsed time for each script execution(event). I used this code:

import logging
import time

logging.basicConfig(filename='example.log', filemode='w', format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p', level=logging.INFO)
logging.info('Start:')
time.sleep(5)
logging.info('Complete:')

print("Hello World!")

In example.log I have this:

01/14/2015 09:16:15 PM Start:
01/14/2015 09:16:20 PM Complete:

My goal: I want to calculate elapsed time i.e. between Complete and Start and I can't easily subtract 09:16:20 PM - 09:16:15 PM.

My question: how could I reformat datefmt in basicConfig in order to get time in seconds. I want to do simple operation by subtracting two values and monitoring when it's too long. Thanks

Upvotes: 0

Views: 3236

Answers (3)

khampson
khampson

Reputation: 15296

Delorean can help you with the parsing and conversion to regular timedate objects, so you can determine the delta.

The following code takes the format you have in your logs and can calculate the delta:

from delorean import Delorean
from delorean import parse

st = parse("01/14/2015 09:16:15 PM")
end = parse("01/14/2015 09:16:20 PM")

diff = end.naive() - st.naive()

print diff

The output is:

0:00:05

st and end are both Delorean objects with timezone UTC, e.g.

>>> print st
Delorean(datetime=2015-01-14 21:16:15+00:00, timezone=UTC)

diff is a datetime.timedelta object, e.g.

>>> diff = end.naive() - st.naive()
>>> type(diff)
<type 'datetime.timedelta'>

Upvotes: 1

Alex Martelli
Alex Martelli

Reputation: 881477

I would recommend you leave basicConfig as is, for readability, and later, when you read the logs, extract the date and time by datetime parsing. E.g:

>>> import datetime
>>> datefmt = '%m/%d/%Y %I:%M:%S %p'  # the same you used for logging
>>> logline = '01/14/2015 09:16:15 PM Start:'  # as read from the log
>>> datetime.datetime.strptime(' '.join(x.split()[:3]), datefmt)
datetime.datetime(2015, 1, 14, 21, 16, 15)
>>> _.timestamp()
1421298975.0

These are your seconds-since-the-epoch, so getting the difference in seconds between the time stamps of successive lines in the log is easy. (The .timestamp() part requires Python 3.3 or better, but in earlier version you can take the difference between the datetime objects and call the total_seconds method on that time-difference object).

Upvotes: 1

rchang
rchang

Reputation: 5236

You can try calling basicConfig with this format instead:

logging.basicConfig(filename='example.log', filemode='w', format='%(created)f %(message)s', level=logging.INFO)

This should generate the following log entries (your times will differ obviously):

1421288969.379916 Start:
1421288974.385206 Complete:

I'm inferring from your question that you're going to parse the log file afterwards to compute durations. %(created)f produces the number of seconds elapsed since the epoch as floating point values, so hopefully this will facilitate your computation.

Upvotes: 1

Related Questions