time parsing in dmesg log

This is the place for queries that don't fit in any of the other categories.

time parsing in dmesg log

Postby raohiral » Fri Mar 01, 2013 4:10 pm

I am trying to parse time in python, need help in parsing time in log and print it..

below is the time format in my log:
2011/09/27 07:07:05 545 1322 I KERNEL : [15111.908075] Bluetooth: SCO socket layer initialized

I used this to read from file,
re.compile('^(\d{2})-(\d{2}) (\d{2}):(\d{2}):(\d{2})\.(\d{3}) (.*)')

but somehow its not working for me..any help appreciated.

Thanks
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Re: time parsing in dmesg log

Postby Yoriz » Fri Mar 01, 2013 4:38 pm

You want the re that finds the date & time ? this seems to work
Code: Select all
import re

line = ('2011/09/27 07:07:05 545 1322 I KERNEL : [15111.908075] Bluetooth:'
        ' SCO socket layer initialized')

found_date_time = re.search(r'\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2}', line)
if found_date_time:
    print found_date_time.group()

2011/09/27 07:07:05
New Users, Read This
Join the #python-forum IRC channel on irc.freenode.net!
Spam topic disapproval technician
Windows7, Python 2.7.4., WxPython 2.9.5.0., some Python 3.3
User avatar
Yoriz
 
Posts: 836
Joined: Fri Feb 08, 2013 1:35 am
Location: UK

Re: time parsing in dmesg log

Postby Mekire » Fri Mar 01, 2013 4:57 pm

Edit: Meh... I was going to suggest using strptime in the time module but I guess the re is shorter and if you don't actually need to do calculations with them it probably isn't worth the effort.

Code: Select all
import time
s = '2011/09/27 07:07:05 545 1322 I KERNEL : [15111.908075] Bluetooth: SCO socket layer initialized'
s = s.split()
t = time.strptime(s[0]+s[1],"%Y/%m/%d%H:%M:%S")
print(t)

time.struct_time(tm_year=2011, tm_mon=9, tm_mday=27, tm_hour=7, tm_min=7, tm_sec=5, tm_wday=1, tm_yday=270, tm_isdst=-1)

-Mek
User avatar
Mekire
 
Posts: 988
Joined: Thu Feb 07, 2013 11:33 pm
Location: Amakusa, Japan

Re: time parsing in dmesg log

Postby raohiral » Fri Mar 01, 2013 7:09 pm

Thanks Guys for help..

My code is like this for time stamp:
"2011/09/27 07:07:05 545 1322 I KERNEL : [15111.908075] Bluetooth:"

KERNEL_TIME_LIMIT = 131072.0


KERNEL_TIME_STAMP =\
re.compile('^(\d{2})-(\d{2}) (\d{2}):(\d{2}):(\d{2})\.(\d{3}) (.*)')
LOGCAT_TIME_STAMP =\
re.compile('^(\d{2})-(\d{2}) (\d{2}):(\d{2}):(\d{2})\.(\d{3}) (.*)')
def time_and_body(line):
n = KERNEL_TIME_STAMP.match(line)

if n is None:
return (None,None)
return (n.groups()[0]+'.'+n.groups()[1],n.groups()[2])
----------------------------------------------------------------------------------------------------------------
Before it was like below time format file has only this timestamp:

"[15111.908075] Bluetooth: SCO socket layer initialized"


and below for for [15111.908075] timeformat,

KERNEL_TIME_LIMIT = 131072.0

KERNEL_TIME_STAMP =\
re.compile('^<\d>\[ *(\d+)\.(\d{6})[^\]]*\] (.*)')
LOGCAT_TIME_STAMP =\
re.compile('^(\d{2})-(\d{2}) (\d{2}):(\d{2}):(\d{2})\.(\d{3}) (.*)')
def time_and_body(line):

n = KERNEL_TIME_STAMP.match(line)

if n is None:
return (None,None)
return (n.groups()[0]+'.'+n.groups()[1],n.groups()[2])

But after changing it for absolute time its not working for me..I need to covert it to absolute time format...not sure where I am making mistake....any suggestions?
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Re: time parsing in dmesg log

Postby Yoriz » Fri Mar 01, 2013 8:31 pm

You should use code tags when you post code, otherwise it loses indentation and just blends in with normal text see this post
To make it clear what you need to achieve, give an expected range of inputs and the output from it required.
New Users, Read This
Join the #python-forum IRC channel on irc.freenode.net!
Spam topic disapproval technician
Windows7, Python 2.7.4., WxPython 2.9.5.0., some Python 3.3
User avatar
Yoriz
 
Posts: 836
Joined: Fri Feb 08, 2013 1:35 am
Location: UK

Re: time parsing in dmesg log

Postby raohiral » Fri Mar 01, 2013 9:30 pm

Finally I found solution to parse absolute time using groups()

Code: Select all

KERNEL_TIME_STAMP =\
    re.compile('^(\d{2})-(\d{2}) (\d{2}):(\d{2}):(\d{2})\.(\d{3}) (.*)')

def time_and_body(line):
    print line
    n = KERNEL_TIME_STAMP.match(line)
       
    if n is None:
        return (None,None)
    k_time = n.groups()[2]+'.'+n.groups()[3]+'.'+n.groups()[4]+'.'+n.groups()[5]
    print k_time
    return (k_time,n.groups()[6])


I was able to parse it successfully, "07:07:05 545"

Thanks for help and tips..really appreciate...
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Re: time parsing in dmesg log

Postby Yoriz » Fri Mar 01, 2013 9:48 pm

When i run your code on the line
Code: Select all
line = ('2011/09/27 07:07:05 545 1322 I KERNEL : [15111.908075] Bluetooth:'
        ' SCO socket layer initialized')

it returned the following for me
Code: Select all
(None, None)

Does this do what you need it to
Code: Select all
line = ('2011/09/27 07:07:05 545 1322 I KERNEL : [15111.908075] Bluetooth:'
        ' SCO socket layer initialized')
KERNEL_TIME_STAMP = re.compile(r'(\d{2}:\d{2}:\d{2}) (\d{3})')


def time_and_body2(line):
    result = KERNEL_TIME_STAMP.search(line)
    return result.groups() if result else (None, None)

print time_and_body2(line)

Returns the following for me
Code: Select all
('07:07:05', '545')
New Users, Read This
Join the #python-forum IRC channel on irc.freenode.net!
Spam topic disapproval technician
Windows7, Python 2.7.4., WxPython 2.9.5.0., some Python 3.3
User avatar
Yoriz
 
Posts: 836
Joined: Fri Feb 08, 2013 1:35 am
Location: UK

Re: time parsing in dmesg log

Postby raohiral » Fri Mar 01, 2013 10:28 pm

Yeah I was getting the result I wanted with the one I used.
My output was also,

'16:06:58.837'

But solution you gave me was perfect, I used it and with less code lines its giving me same output,

'16:06:58.837' .

So, thanks for giving proper solution.

One more thing,

I have defined

Code: Select all
cur_state['kernel_time_stamp'] = ' ' as string

#This is where its defining current time from log,

def __current_time(c):
    return int(c['kernel_time_stamp'])

----------------------------------------------------------------

current time is called here,

def roll(fobj_in, fobj_out):
    cur_state = __init_cur()
    live_sessions = dict()
    live_sessions['full'] = None
    live_sessions['discharge'] = None
    live_sessions['charge'] = None
    live_sessions['active'] = None
    live_sessions['suspend'] = None
    live_sessions['wakeup'] = None # started from wakeup_wakelock, ended
    live_sessions['last_active'] = None

    try:
        l = fobj_in.readline()
     
        while (len(l)):
            t,b = time_and_body(l)
            if t is not None:
                cur_state['kernel_time_stamp'] = t
               
                if not live_sessions['full']:
                    live_sessions['full'] = FullLogSession(
                        start = t,
                       
                        start_time = __current_time(cur_state))
                   
                    live_sessions['discharge'] = DischargeSession(
                        start = t,
                        start_time = __current_time(cur_state))
                for k in REGEX.keys():
                    r,f = REGEX[k]
                    m = r.match(b)
                    if m is not None:
                        if f in globals().keys():
                            hook = globals()[f]
                            hook(live_sessions, cur_state, m)
            l = fobj_in.readline()
        # close all live sessions
        __close_sessions(live_sessions, cur_state)
        live_sessions['full'].end = cur_state['kernel_time_stamp']
        live_sessions['full'].end_time = __current_time(cur_state)
        live_sessions['full'].duration = __duration(live_sessions['full'])\
            + live_sessions['full'].rtc_only
    except:
        __debug_print_all(live_sessions, cur_state)
        raise
    if not TECH and not VERBOSE:
        if cur_state['cpu1_on'] > 0:
            live_sessions['full'].cpu1_time += __current_time(cur_state) - cur_state['cpu1_on']
        if cur_state['charging_start'] > 0:
            live_sessions['full'].usb_time += __current_time(cur_state) - cur_state['charging_start']
    return live_sessions['full']




Now if I use string its throwing me error saying,

ValueError: invalid literal for int() with base 10: '16:25:51.946' ..

so how do I get proper start time in order to parse my log.

Thanks again for your help.
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Re: time parsing in dmesg log

Postby Yoriz » Fri Mar 01, 2013 10:29 pm

studying your code a bit more this seems more likely the result your after
Code: Select all
line = ('2011/09/27 07:07:05 545 1322 I KERNEL : [15111.908075] Bluetooth:'
        ' SCO socket layer initialized')


KERNEL_TIME_STAMP = re.compile(r'(\d{2}):(\d{2}):(\d{2}) (\d{3}) (.*)')


def time_and_body3(line):
    result = KERNEL_TIME_STAMP.search(line)
    if result:
        groups = result.groups()
        return '{}.{}.{}.{}'.format(*groups[:4]), groups[4]
    return (None, None)

print time_and_body3(line)

('07.07.05.545', '1322 I KERNEL : [15111.908075] Bluetooth: SCO socket layer initialized')
New Users, Read This
Join the #python-forum IRC channel on irc.freenode.net!
Spam topic disapproval technician
Windows7, Python 2.7.4., WxPython 2.9.5.0., some Python 3.3
User avatar
Yoriz
 
Posts: 836
Joined: Fri Feb 08, 2013 1:35 am
Location: UK

Re: time parsing in dmesg log

Postby raohiral » Fri Mar 01, 2013 10:45 pm

My code is based on this time format,

[ 4685.842361,0] panel_disable is called

and now I have my logs with absolute time format,

02-28 16:06:59.738 269 434 I KERNEL : [ 4685.842361,0] panel_disable is called

so I needed to parse "16:06:59.738" absolute time.. But when I defined

Code: Select all
cur_state['kernel_time_stamp'] = ' ' as string


its throwing error I mentioned in my previous post.
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Re: time parsing in dmesg log

Postby Yoriz » Fri Mar 01, 2013 10:46 pm

raohiral wrote:ValueError: invalid literal for int() with base 10: '16:25:51.946' ..

You can only call int with numerical string values
New Users, Read This
Join the #python-forum IRC channel on irc.freenode.net!
Spam topic disapproval technician
Windows7, Python 2.7.4., WxPython 2.9.5.0., some Python 3.3
User avatar
Yoriz
 
Posts: 836
Joined: Fri Feb 08, 2013 1:35 am
Location: UK

Re: time parsing in dmesg log

Postby raohiral » Fri Mar 01, 2013 10:50 pm

below error,
Code: Select all
KERNEL_TIME_STAMP =\
    re.compile(r'(\d{2}:\d{2}:\d{2}.\d{3}) (.*)')  #re.compile('^<\d>\[ *(\d+)\.(\d{6})[^\]]*\] (.*)')
LOGCAT_TIME_STAMP =\
    re.compile('^(\d{2})-(\d{2}) (\d{2}):(\d{2}):(\d{2})\.(\d{3}) (.*)')
def time_and_body(line):
    print line
    n = KERNEL_TIME_STAMP.search(line)
    if n:
        groups = n.groups()
        return '{}.{}.{}.{}'.format(*groups[:4]), groups[4]
    return (None, None)
   


Traceback (most recent call last):
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 1326, in <module>
f = roll(fobj_in, fobj_out)
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 927, in roll
t,b = time_and_body(l)
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 325, in time_and_body
return '{}.{}.{}.{}'.format(*groups[:4]), groups[4]
ValueError: zero length field name in format
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Re: time parsing in dmesg log

Postby Yoriz » Fri Mar 01, 2013 11:03 pm

You have a different KERNEL_TIME_STAMP to mine in time_and_body3
Code: Select all
KERNEL_TIME_STAMP = re.compile(r'(\d{2}):(\d{2}):(\d{2}) (\d{3}) (.*)')  # mine
KERNEL_TIME_STAMP = re.compile(r'(\d{2}:\d{2}:\d{2}.\d{3}) (.*)')  # yours
New Users, Read This
Join the #python-forum IRC channel on irc.freenode.net!
Spam topic disapproval technician
Windows7, Python 2.7.4., WxPython 2.9.5.0., some Python 3.3
User avatar
Yoriz
 
Posts: 836
Joined: Fri Feb 08, 2013 1:35 am
Location: UK

Re: time parsing in dmesg log

Postby raohiral » Fri Mar 01, 2013 11:32 pm

sorry mt bad..changed it..but when I run the code..again I am seeing this error,


Traceback (most recent call last):
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 1327, in <module>
f = roll(fobj_in, fobj_out)
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 951, in roll
live_sessions['full'].end = cur_state['kernel_time_stamp']
AttributeError: 'NoneType' object has no attribute 'end'
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Re: time parsing in dmesg log

Postby Yoriz » Fri Mar 01, 2013 11:45 pm

You have a live_sessions['full'] that is not being set by a FullLogSession
Code: Select all
live_sessions['full'] = FullLogSession(
                        start = t,
                       
                        start_time = __current_time(cur_state))

it still has the initial value you set as None
Code: Select all
live_sessions['full'] = None

I think thats why your getting the error when trying to set
Code: Select all
live_sessions['full'].end = cur_state['kernel_time_stamp']

you cant set an end attribute to None.
New Users, Read This
Join the #python-forum IRC channel on irc.freenode.net!
Spam topic disapproval technician
Windows7, Python 2.7.4., WxPython 2.9.5.0., some Python 3.3
User avatar
Yoriz
 
Posts: 836
Joined: Fri Feb 08, 2013 1:35 am
Location: UK

Re: time parsing in dmesg log

Postby raohiral » Sat Mar 02, 2013 12:17 am

I changed end attribute to NONE,

Code: Select all
class FullLogSession(Session):
    def __init__(self,
                 start=UNKNOWN,
                 start_time=0,
                 end=-2, #UNKNOWN,
                 duration=0.0,
                 cost=0.0,
                 typ=UNKNOWN,
                 reason = UNKNOWN):
        super(FullLogSession, self).__init__(
            start, start_time, end, duration, cost, typ, reason)
        self.discharge_sessions = list()
        self.tops = dict()

        self.tops['cost_displayon'] = Top('cost')
        self.tops['duration_displayon'] = Top('duration')

        self.tops['cost_active'] = Top('cost')
        self.tops['duration_active'] = Top('duration')

        self.tops['cost_awoken'] = Top('cost')
        self.tops['duration_awoken'] = Top('duration')

        if not TECH and not VERBOSE:
            self.usb_time = 0.0
            self.cpu1_time = 0.0
            self.full_stats = dict()
            self.full_stats['BACKGROUND'] = dict()
            self.full_stats['ABORT'] = dict()
            self.full_stats['DEVICE'] = dict()
            self.full_stats['DISPLAY'] = dict()
            self.full_stats['DISPLAYOFF'] = dict()
            self.full_stats['LONGEST'] = dict()
            self.active_sum = Sum()
            self.suspend_sum = Sum()
            self.head = 0.0
            self.tail = 0.0


Still showing me error,

Traceback (most recent call last):
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 1328, in <module>
f = roll(fobj_in, fobj_out)
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 952, in roll
live_sessions['full'].end = cur_state['kernel_time_stamp']
AttributeError: 'NoneType' object has no attribute 'end'


I believe
Code: Select all
def __current_time(c):
    return float(c['kernel_time_stamp'])
   


here its having issue to convert string into float/int..

so I used
Code: Select all
def __current_time(c):
    return len(c['kernel_time_stamp'])
   


after that it started showing me above error..

need your help to resolve this...

Thanks
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Re: time parsing in dmesg log

Postby Yoriz » Sat Mar 02, 2013 12:32 am

ive added comment to your code
Code: Select all
    cur_state['kernel_time_stamp'] = ' ' as string

    #This is where its defining current time from log,

    def __current_time(c):
        return int(c['kernel_time_stamp'])

    ----------------------------------------------------------------

    current time is called here,

    def roll(fobj_in, fobj_out):
        cur_state = __init_cur()
        live_sessions = dict()
        live_sessions['full'] = None ################# set to None here
        live_sessions['discharge'] = None
        live_sessions['charge'] = None
        live_sessions['active'] = None
        live_sessions['suspend'] = None
        live_sessions['wakeup'] = None # started from wakeup_wakelock, ended
        live_sessions['last_active'] = None

        try:
            l = fobj_in.readline()
            while (len(l)):
                t,b = time_and_body(l)
                if t is not None: ################ t must be resulting to None because one of your readlines is not a re match so the following code is skipped
                    cur_state['kernel_time_stamp'] = t
                   
                    if not live_sessions['full']:
                        live_sessions['full'] = FullLogSession( ################### this is not called
                            start = t,
                           
                            start_time = __current_time(cur_state))
                       
                        live_sessions['discharge'] = DischargeSession(
                            start = t,
                            start_time = __current_time(cur_state))
                    for k in REGEX.keys():
                        r,f = REGEX[k]
                        m = r.match(b)
                        if m is not None:
                            if f in globals().keys():
                                hook = globals()[f]
                                hook(live_sessions, cur_state, m)
                l = fobj_in.readline()
            # close all live sessions #################################################### the code is carrying on from here
            __close_sessions(live_sessions, cur_state)
            live_sessions['full'].end = cur_state['kernel_time_stamp'] ########################## this cannot be set as live_sessions['full'] = None
            live_sessions['full'].end_time = __current_time(cur_state)
            live_sessions['full'].duration = __duration(live_sessions['full'])\
                + live_sessions['full'].rtc_only
        except:
            __debug_print_all(live_sessions, cur_state)
            raise
        if not TECH and not VERBOSE:
            if cur_state['cpu1_on'] > 0:
                live_sessions['full'].cpu1_time += __current_time(cur_state) - cur_state['cpu1_on']
            if cur_state['charging_start'] > 0:
                live_sessions['full'].usb_time += __current_time(cur_state) - cur_state['charging_start']
        return live_sessions['full']


New Users, Read This
Join the #python-forum IRC channel on irc.freenode.net!
Spam topic disapproval technician
Windows7, Python 2.7.4., WxPython 2.9.5.0., some Python 3.3
User avatar
Yoriz
 
Posts: 836
Joined: Fri Feb 08, 2013 1:35 am
Location: UK

Re: time parsing in dmesg log

Postby raohiral » Sat Mar 02, 2013 5:47 am

Thanks so much for tips...

Code: Select all
def __current_time(c):
    return float(c['kernel_time_stamp'])


Still getting this error,

Traceback (most recent call last):
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 1328, in <module>
f = roll(fobj_in, fobj_out)
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 937, in roll
start_time = __current_time(cur_state))
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 37, in __current_time
return float(c['kernel_time_stamp'])
TypeError: float() argument must be a string or a number
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Re: time parsing in dmesg log

Postby Yoriz » Sat Mar 02, 2013 11:26 am

The float error is a similar error to the one you had with int.
Code: Select all
TypeError: float() argument must be a string or a number

You are probably trying to call float on None, its has to be a string or number that can be turned into a float or you will get that error
New Users, Read This
Join the #python-forum IRC channel on irc.freenode.net!
Spam topic disapproval technician
Windows7, Python 2.7.4., WxPython 2.9.5.0., some Python 3.3
User avatar
Yoriz
 
Posts: 836
Joined: Fri Feb 08, 2013 1:35 am
Location: UK

Re: time parsing in dmesg log

Postby raohiral » Mon Mar 04, 2013 3:29 am

Thanks for help..

I tried giving string and number but still getting this error,

cur_state['kernel_time_stamp'] = ' '

error:

Traceback (most recent call last):
File "C:\Bug2Go-scripts\pm_log_parser_new.py", line 1328, in <module>
raohiral
 
Posts: 18
Joined: Fri Mar 01, 2013 3:59 pm

Next

Return to General Coding Help

Who is online

Users browsing this forum: Baldyr, W3C [Linkcheck] and 2 guests