time parsing in dmesg log

[raohiral]

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

[Yoriz]

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

[Mekire]

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

[raohiral]

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?

[Yoriz]

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.

[raohiral]

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...

[Yoriz]

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')

[raohiral]

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.

[Yoriz]

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')

[raohiral]

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.

[Yoriz]

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

You can only call int with numerical string values

[raohiral]

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

[Yoriz]

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

[raohiral]

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'

[Yoriz]

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.

[raohiral]

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

[Yoriz]

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']




[raohiral]

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

[Yoriz]

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

[raohiral]

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>