Difference between revisions of "Timeline.py"
Jump to navigation
Jump to search
PeterHarding (talk | contribs) (New page: <pre> #!/usr/bin/env perl # # $Id:$ # #------------------------------------------------- @types = ('backline', 'frontline', 'teamlead', 'operations'); @nodes = ('node1', 'node2', 'node3'...) |
PeterHarding (talk | contribs) |
||
| (One intermediate revision by the same user not shown) | |||
| Line 1: | Line 1: | ||
<pre> | <pre> | ||
#!/usr/bin/env | #! /usr/bin/env python | ||
# | |||
# Purpose: Parse and display an informix log file | |||
# | # | ||
# $Id:$ | # $Id:$ | ||
# | # | ||
#------------------------------------------------- | #--------------------------------------------------------------------- | ||
""" | |||
Parse BL's log files to show the underlying function invocation | |||
sequence in the designated log file. Also show timing of start | |||
of function. | |||
""" | |||
#--------------------------------------------------------------------- | |||
import re | |||
import os | |||
import sys | |||
import time | |||
import getopt | |||
import pickle | |||
#--------------------------------------------------------------------- | |||
__version__ = "1.1.2" | |||
debugFlg = 0 | |||
stdoutFlg = 0 | |||
verboseFlg = 0 | |||
wallclockFlg = 0 | |||
rewriteFlg = 0 | |||
filename = "logs.sorted" | |||
mode = None | |||
data = None | |||
td_start = None | |||
vuser = "068" | |||
SPACES = " " | |||
started = {} | |||
node_map = None | |||
#--------------------------------------------------------------------- | |||
def startSeconds(s): | |||
return time.mktime(time.strptime(s, "%Y-%m-%d %H:%M:%S")) | |||
#--------------------------------------------------------------------- | |||
def seconds(hms): | |||
s = hms.split(':') | |||
return ((s[0] * 60) + s[1]) * 60 + s[2] | |||
#--------------------------------------------------------------------- | |||
def hms(t_secs): | |||
hm = t_secs / 60 | |||
hours = hm / 60 | |||
mins = hm % 60 | |||
secs = t_secs % 60 | |||
return "%02d:%02d:%02d" % ( hours, mins, secs) | |||
#--------------------------------------------------------------------- | |||
def parse(filename): | |||
outfile = "timeline.txt" | |||
try: | |||
ifo = open(filename, 'r') | |||
except IOError, msg: | |||
sys.stderr.write(filename + ': cannot open: ' + `msg` + '\n') | |||
sys.exit(1) | |||
if stdoutFlg == 1: | |||
ofo = os.dup(sys.stdout) | |||
else: | |||
try: | |||
ofo = open(outfile, 'w') | |||
except IOError, msg: | |||
sys.stderr.write(outfile + ': cannot open: ' + `msg` + '\n') | |||
sys.exit(1) | |||
depth = 0 | |||
depth_max = 0 | |||
cnt = 0 | |||
cnt_fail = 0 | |||
last_hms = None | |||
start = None | |||
end = None | |||
idx = [] | |||
marks = [] | |||
for i in range(25): | |||
idx.append(i) | |||
marks.append(' ') | |||
while 1: | |||
line = ifo.readline() | |||
if not line: break | |||
line = line[:-1] | |||
if re.search("^[^0-9]", line): | |||
continue | |||
if re.search("^#", line): | |||
continue | |||
if re.search("^$", line): | |||
continue | |||
if re.search("^\r$", line): | |||
continue | |||
cnt += 1 | |||
p = line.split(' ', 6) | |||
# print p | |||
hms_elapsed = p[0] | |||
hms_wallclock = p[2].replace("]","") | |||
vuser = p[3] | |||
file_lineno = p[4] | |||
task = p[5] | |||
if re.search(r'TxStart', p[6]): | |||
s = p[6].split(' ') | |||
#mode = s[0] | |||
mode = "START" | |||
tmatch = re.search(r'\[(.*?)\]', s[1]) | |||
if tmatch: | |||
type = tmatch.group(1) | |||
subtx = type.replace(task, "") | |||
subtx = subtx.replace("_", "") | |||
signature = ':'.join((type, vuser)) | |||
# print "Signature [%s]" % signature | |||
col = idx.pop() | |||
marks[col] = 'v' | |||
start = col | |||
depth += 1 | |||
if not started.has_key(signature): | |||
started[signature] = col | |||
elif not started[signature]: | |||
started[signature] = col | |||
else: | |||
print "%s already started" % signature | |||
sys.exit(0) | |||
elif re.search(r'TxEnd', p[6]): | |||
s = p[6].split(' ') | |||
mode = "*END*" | |||
tmatch = re.search(r'\[(.*?)\]', s[1]) | |||
if tmatch: | |||
type = tmatch.group(1) | |||
subtx = type.replace(task, "") | |||
subtx = subtx.replace("_", "") | |||
tmatch = re.search(r'\[(.*?)\]', s[2]) | |||
if tmatch: | |||
elapsed = float(tmatch.group(1)) | |||
tmatch = re.search(r'\[(.*?)\]', s[3]) | |||
if tmatch: | |||
status = tmatch.group(1) | |||
tmatch = re.search(r'\[(.*?)\]', s[6]) | |||
if tmatch: | |||
username = tmatch.group(1) | |||
tmatch = re.search(r'\[(.*?)\]', s[7]) | |||
if tmatch: | |||
obj = tmatch.group(1) | |||
signature = ':'.join((type, vuser)) | |||
# print "Signature [%s]" % signature | |||
if started.has_key(signature): | |||
# print "%s ending" % type | |||
col = started[signature] | |||
if status == "LR_FAIL": | |||
cnt_fail += 1 | |||
status = "@" | |||
marks[col] = '+' | |||
else: | |||
status = " " | |||
marks[col] = '*' | |||
end = col | |||
idx.append(col) | |||
started[signature] = None | |||
depth -= 1 | |||
else: | |||
print "%s not started" % type | |||
sys.exit(1) | |||
else: | |||
continue | |||
if depth > depth_max: | |||
depth_max = depth | |||
if hms_elapsed == last_hms: | |||
hms_elapsed = SPACES | |||
hms_wallclock = SPACES | |||
else: | |||
last_hms = hms_elapsed | |||
marker = ''.join(marks) | |||
if mode == "START": | |||
print >>ofo, "%s %s %s %s %s %s %-30s %s " % (hms_elapsed, marker, hms_wallclock, vuser, node_map[vuser], mode, task[0:30], subtx[0:25]) | |||
else: | |||
if elapsed > 30: | |||
flg = "!" | |||
else: | |||
flg = " " | |||
print >>ofo, "%s %s %s %s %s %s %s%s %5.2f %-30s %-25s %s %s" % (hms_elapsed, marker, hms_wallclock, vuser, node_map[vuser], mode, status, flg, elapsed, task[0:30], subtx[0:25], username, obj) | |||
if start: | |||
marks[start] = '|' | |||
start = None | |||
if end: | |||
marks[end] = ' ' | |||
end = None | |||
ifo.close() | |||
ofo.close() | |||
print >>sys.stderr, "Processed %d lines (%d LR_FAIL) (max depth %d)" % (cnt, cnt_fail, depth_max) | |||
#--------------------------------------------------------------------- | |||
def main(): | |||
global filename | |||
global td_start | |||
global debugFlg | |||
global stdoutFlg | |||
global verboseFlg | |||
global rewriteFlg | |||
global wallclockFlg | |||
global node_map | |||
try: | |||
opts, args = getopt.getopt(sys.argv[1:], "df:ors:tvVw?") | |||
except getopt.error, msg: | |||
print __doc__ | |||
return 1 | |||
for o, a in opts: | |||
if o == '-d': | |||
debugFlg = 1 | |||
elif o == '-f': | |||
filename = a | |||
elif o == '-o': | |||
stdoutFlg = 1 | |||
elif o == '-s': | |||
td_start = a | |||
elif o == '-v': | |||
verboseFlg = 1 | |||
elif o == '-V': | |||
print "Version: %s" % __version__ | |||
return 1 | |||
elif o == '-r': | |||
rewriteFlg = 1 | |||
elif o == '-t': | |||
rewriteFlg = 1 | |||
wallclockFlg = 1 | |||
elif o == '-w': | |||
wallclockFlg = 1 | |||
elif o == '-?': | |||
print __doc__ | |||
return 1 | |||
if (debugFlg): | |||
print ">> Flg %s" % debugFlg | |||
f = open('node_map.dump', 'r') | |||
node_map = pickle.load(f) | |||
if args: | |||
for arg in args: | |||
parse(arg) | |||
else: | |||
parse(filename) | |||
return 1 | |||
#---- | #--------------------------------------------------------------------- | ||
if __name__ == '__main__' or __name__ == sys.argv[0]: | |||
sys.exit(main()) | |||
#--------------------------------------------------------------------- | |||
""" | |||
Revision History: | |||
Date Who Description | |||
-------- --- -------------------------------------------------- | |||
20040617 plh Initial implementation | |||
Problems to fix: | |||
To Do: | |||
Issues: | |||
""" | |||
""" | |||
00:00:08 [2004-06-16 18:24:21] 043 ../lib/Login.c:41 FL_Login Login - (VUser Frontline:43) | |||
00:00:08 [2004-06-16 18:24:21] 043 ../lib/Login.c:44 FL_Login host [node2.perf:7001] username [FaMELGTW] password [FaMELGTW] | |||
00:00:08 [2004-06-16 18:24:21] 043 ../lib/Utils.c:1209 FL_Login start transaction [FL_Login_Home] | |||
00:00:10 [2004-06-16 18:24:23] 043 ../lib/Utils.c:1110 FL_Login end transaction [FL_Login_Home] | |||
00:00:10 [2004-06-16 18:24:23] 043 ../lib/Utils.c:1134 FL_Login transaction result [FL_Login_Home] [2.403497] [LR_PASS] [0.000000] | |||
00:00:15 [2004-06-16 18:24:28] 065 ../lib/Login.c:41 BL_Login Login - (VUser Backline:65) | |||
00:00:15 [2004-06-16 18:24:28] 065 ../lib/Login.c:44 BL_Login host [node2.perf:7001] username [BaMELGTW] password [BaMELGTW] | |||
00:00:15 [2004-06-16 18:24:28] 065 ../lib/Utils.c:1209 BL_Login start transaction [BL_Login_Home] | |||
00:00:18 [2004-06-16 18:24:31] 065 ../lib/Utils.c:1110 BL_Login end transaction [BL_Login_Home] | |||
00:00:18 [2004-06-16 18:24:31] 065 ../lib/Utils.c:1134 BL_Login transaction result [BL_Login_Home] [2.181031] [LR_PASS] [0.000000] | |||
00:00:19 [2004-06-16 18:24:32] 043 ../lib/Utils.c:1209 FL_Login start transaction [FL_Login_Redirect] | |||
00:00:21 [2004-06-16 18:24:34] 043 ../lib/Utils.c:1110 FL_Login end transaction [FL_Login_Redirect] | |||
00:00:21 [2004-06-16 18:24:34] 043 ../lib/Utils.c:1134 FL_Login transaction result [FL_Login_Redirect] [0.781231] [LR_PASS] [0.000000] | |||
00:00:27 [2004-06-16 18:24:40] 065 ../lib/Utils.c:1209 BL_Login start transaction [BL_Login_Redirect] | |||
00:00:29 [2004-06-16 18:24:42] 065 ../lib/Utils.c:1110 BL_Login end transaction [BL_Login_Redirect] | |||
00:00:29 [2004-06-16 18:24:42] 065 ../lib/Utils.c:1134 BL_Login transaction result [BL_Login_Redirect] [0.131494] [LR_PASS] [0.000000] | |||
00:00:32 [2004-06-16 18:24:45] 043 ../lib/Utils.c:1224 FL_Login start transaction [FL_Login_NotificationInitFrame] | |||
00:00:34 [2004-06-16 18:24:47] 043 ../lib/Utils.c:1110 FL_Login end transaction [FL_Login_NotificationInitFrame] | |||
00:00:34 [2004-06-16 18:24:47] 043 ../lib/Utils.c:1134 FL_Login transaction result [FL_Login_NotificationInitFrame] [0.041493] [LR_PASS] [0.000000] | |||
00:00:39 [2004-06-16 18:24:52] 065 ../lib/Utils.c:1224 BL_Login start transaction [BL_Login_NotificationInitFrame] | |||
00:00:41 [2004-06-16 18:24:54] 065 ../lib/Utils.c:1110 BL_Login end transaction [BL_Login_NotificationInitFrame] | |||
00:00:41 [2004-06-16 18:24:54] 065 ../lib/Utils.c:1134 BL_Login transaction result [BL_Login_NotificationInitFrame] [0.041671] [LR_PASS] [0.000000] | |||
00:00:44 [2004-06-16 18:24:57] 043 ../lib/Utils.c:1209 FL_Login start transaction [FL_Login_Send] | |||
00:00:51 [2004-06-16 18:25:04] 065 ../lib/Utils.c:1209 BL_Login start transaction [BL_Login_Send] | |||
00:01:00 [2004-06-16 18:25:13] 043 ../lib/Utils.c:1110 FL_Login end transaction [FL_Login_Send] | |||
00:01:00 [2004-06-16 18:25:13] 043 ../lib/Utils.c:1134 FL_Login transaction result [FL_Login_Send] [16.080589] [LR_PASS] [0.001000] | |||
00:01:04 [2004-06-16 18:25:17] 065 ../lib/Utils.c:1110 BL_Login end transaction [BL_Login_Send] | |||
00:01:04 [2004-06-16 18:25:17] 065 ../lib/Utils.c:1134 BL_Login transaction result [BL_Login_Send] [12.559203] [LR_PASS] [0.000000] | |||
00:01:10 [2004-06-16 18:25:23] 043 ../lib/NotificationInit.c:6 FL_NotificationInit global_current_action_name [NotificationInit] | |||
00:01:10 [2004-06-16 18:25:23] 043 ../lib/Utils.c:1224 FL_NotificationInit start transaction [FL_NotificationInit_InitFrame] | |||
""" | |||
</pre> | </pre> | ||
[[Category:Python]] | [[Category:Python]] | ||
[[Category:Log Analysis]] | [[Category:Log Analysis]] | ||
[[Category:Examples]] | |||
Latest revision as of 17:09, 19 July 2009
#! /usr/bin/env python
#
# Purpose: Parse and display an informix log file
#
# $Id:$
#
#---------------------------------------------------------------------
"""
Parse BL's log files to show the underlying function invocation
sequence in the designated log file. Also show timing of start
of function.
"""
#---------------------------------------------------------------------
import re
import os
import sys
import time
import getopt
import pickle
#---------------------------------------------------------------------
__version__ = "1.1.2"
debugFlg = 0
stdoutFlg = 0
verboseFlg = 0
wallclockFlg = 0
rewriteFlg = 0
filename = "logs.sorted"
mode = None
data = None
td_start = None
vuser = "068"
SPACES = " "
started = {}
node_map = None
#---------------------------------------------------------------------
def startSeconds(s):
return time.mktime(time.strptime(s, "%Y-%m-%d %H:%M:%S"))
#---------------------------------------------------------------------
def seconds(hms):
s = hms.split(':')
return ((s[0] * 60) + s[1]) * 60 + s[2]
#---------------------------------------------------------------------
def hms(t_secs):
hm = t_secs / 60
hours = hm / 60
mins = hm % 60
secs = t_secs % 60
return "%02d:%02d:%02d" % ( hours, mins, secs)
#---------------------------------------------------------------------
def parse(filename):
outfile = "timeline.txt"
try:
ifo = open(filename, 'r')
except IOError, msg:
sys.stderr.write(filename + ': cannot open: ' + `msg` + '\n')
sys.exit(1)
if stdoutFlg == 1:
ofo = os.dup(sys.stdout)
else:
try:
ofo = open(outfile, 'w')
except IOError, msg:
sys.stderr.write(outfile + ': cannot open: ' + `msg` + '\n')
sys.exit(1)
depth = 0
depth_max = 0
cnt = 0
cnt_fail = 0
last_hms = None
start = None
end = None
idx = []
marks = []
for i in range(25):
idx.append(i)
marks.append(' ')
while 1:
line = ifo.readline()
if not line: break
line = line[:-1]
if re.search("^[^0-9]", line):
continue
if re.search("^#", line):
continue
if re.search("^$", line):
continue
if re.search("^\r$", line):
continue
cnt += 1
p = line.split(' ', 6)
# print p
hms_elapsed = p[0]
hms_wallclock = p[2].replace("]","")
vuser = p[3]
file_lineno = p[4]
task = p[5]
if re.search(r'TxStart', p[6]):
s = p[6].split(' ')
#mode = s[0]
mode = "START"
tmatch = re.search(r'\[(.*?)\]', s[1])
if tmatch:
type = tmatch.group(1)
subtx = type.replace(task, "")
subtx = subtx.replace("_", "")
signature = ':'.join((type, vuser))
# print "Signature [%s]" % signature
col = idx.pop()
marks[col] = 'v'
start = col
depth += 1
if not started.has_key(signature):
started[signature] = col
elif not started[signature]:
started[signature] = col
else:
print "%s already started" % signature
sys.exit(0)
elif re.search(r'TxEnd', p[6]):
s = p[6].split(' ')
mode = "*END*"
tmatch = re.search(r'\[(.*?)\]', s[1])
if tmatch:
type = tmatch.group(1)
subtx = type.replace(task, "")
subtx = subtx.replace("_", "")
tmatch = re.search(r'\[(.*?)\]', s[2])
if tmatch:
elapsed = float(tmatch.group(1))
tmatch = re.search(r'\[(.*?)\]', s[3])
if tmatch:
status = tmatch.group(1)
tmatch = re.search(r'\[(.*?)\]', s[6])
if tmatch:
username = tmatch.group(1)
tmatch = re.search(r'\[(.*?)\]', s[7])
if tmatch:
obj = tmatch.group(1)
signature = ':'.join((type, vuser))
# print "Signature [%s]" % signature
if started.has_key(signature):
# print "%s ending" % type
col = started[signature]
if status == "LR_FAIL":
cnt_fail += 1
status = "@"
marks[col] = '+'
else:
status = " "
marks[col] = '*'
end = col
idx.append(col)
started[signature] = None
depth -= 1
else:
print "%s not started" % type
sys.exit(1)
else:
continue
if depth > depth_max:
depth_max = depth
if hms_elapsed == last_hms:
hms_elapsed = SPACES
hms_wallclock = SPACES
else:
last_hms = hms_elapsed
marker = ''.join(marks)
if mode == "START":
print >>ofo, "%s %s %s %s %s %s %-30s %s " % (hms_elapsed, marker, hms_wallclock, vuser, node_map[vuser], mode, task[0:30], subtx[0:25])
else:
if elapsed > 30:
flg = "!"
else:
flg = " "
print >>ofo, "%s %s %s %s %s %s %s%s %5.2f %-30s %-25s %s %s" % (hms_elapsed, marker, hms_wallclock, vuser, node_map[vuser], mode, status, flg, elapsed, task[0:30], subtx[0:25], username, obj)
if start:
marks[start] = '|'
start = None
if end:
marks[end] = ' '
end = None
ifo.close()
ofo.close()
print >>sys.stderr, "Processed %d lines (%d LR_FAIL) (max depth %d)" % (cnt, cnt_fail, depth_max)
#---------------------------------------------------------------------
def main():
global filename
global td_start
global debugFlg
global stdoutFlg
global verboseFlg
global rewriteFlg
global wallclockFlg
global node_map
try:
opts, args = getopt.getopt(sys.argv[1:], "df:ors:tvVw?")
except getopt.error, msg:
print __doc__
return 1
for o, a in opts:
if o == '-d':
debugFlg = 1
elif o == '-f':
filename = a
elif o == '-o':
stdoutFlg = 1
elif o == '-s':
td_start = a
elif o == '-v':
verboseFlg = 1
elif o == '-V':
print "Version: %s" % __version__
return 1
elif o == '-r':
rewriteFlg = 1
elif o == '-t':
rewriteFlg = 1
wallclockFlg = 1
elif o == '-w':
wallclockFlg = 1
elif o == '-?':
print __doc__
return 1
if (debugFlg):
print ">> Flg %s" % debugFlg
f = open('node_map.dump', 'r')
node_map = pickle.load(f)
if args:
for arg in args:
parse(arg)
else:
parse(filename)
return 1
#---------------------------------------------------------------------
if __name__ == '__main__' or __name__ == sys.argv[0]:
sys.exit(main())
#---------------------------------------------------------------------
"""
Revision History:
Date Who Description
-------- --- --------------------------------------------------
20040617 plh Initial implementation
Problems to fix:
To Do:
Issues:
"""
"""
00:00:08 [2004-06-16 18:24:21] 043 ../lib/Login.c:41 FL_Login Login - (VUser Frontline:43)
00:00:08 [2004-06-16 18:24:21] 043 ../lib/Login.c:44 FL_Login host [node2.perf:7001] username [FaMELGTW] password [FaMELGTW]
00:00:08 [2004-06-16 18:24:21] 043 ../lib/Utils.c:1209 FL_Login start transaction [FL_Login_Home]
00:00:10 [2004-06-16 18:24:23] 043 ../lib/Utils.c:1110 FL_Login end transaction [FL_Login_Home]
00:00:10 [2004-06-16 18:24:23] 043 ../lib/Utils.c:1134 FL_Login transaction result [FL_Login_Home] [2.403497] [LR_PASS] [0.000000]
00:00:15 [2004-06-16 18:24:28] 065 ../lib/Login.c:41 BL_Login Login - (VUser Backline:65)
00:00:15 [2004-06-16 18:24:28] 065 ../lib/Login.c:44 BL_Login host [node2.perf:7001] username [BaMELGTW] password [BaMELGTW]
00:00:15 [2004-06-16 18:24:28] 065 ../lib/Utils.c:1209 BL_Login start transaction [BL_Login_Home]
00:00:18 [2004-06-16 18:24:31] 065 ../lib/Utils.c:1110 BL_Login end transaction [BL_Login_Home]
00:00:18 [2004-06-16 18:24:31] 065 ../lib/Utils.c:1134 BL_Login transaction result [BL_Login_Home] [2.181031] [LR_PASS] [0.000000]
00:00:19 [2004-06-16 18:24:32] 043 ../lib/Utils.c:1209 FL_Login start transaction [FL_Login_Redirect]
00:00:21 [2004-06-16 18:24:34] 043 ../lib/Utils.c:1110 FL_Login end transaction [FL_Login_Redirect]
00:00:21 [2004-06-16 18:24:34] 043 ../lib/Utils.c:1134 FL_Login transaction result [FL_Login_Redirect] [0.781231] [LR_PASS] [0.000000]
00:00:27 [2004-06-16 18:24:40] 065 ../lib/Utils.c:1209 BL_Login start transaction [BL_Login_Redirect]
00:00:29 [2004-06-16 18:24:42] 065 ../lib/Utils.c:1110 BL_Login end transaction [BL_Login_Redirect]
00:00:29 [2004-06-16 18:24:42] 065 ../lib/Utils.c:1134 BL_Login transaction result [BL_Login_Redirect] [0.131494] [LR_PASS] [0.000000]
00:00:32 [2004-06-16 18:24:45] 043 ../lib/Utils.c:1224 FL_Login start transaction [FL_Login_NotificationInitFrame]
00:00:34 [2004-06-16 18:24:47] 043 ../lib/Utils.c:1110 FL_Login end transaction [FL_Login_NotificationInitFrame]
00:00:34 [2004-06-16 18:24:47] 043 ../lib/Utils.c:1134 FL_Login transaction result [FL_Login_NotificationInitFrame] [0.041493] [LR_PASS] [0.000000]
00:00:39 [2004-06-16 18:24:52] 065 ../lib/Utils.c:1224 BL_Login start transaction [BL_Login_NotificationInitFrame]
00:00:41 [2004-06-16 18:24:54] 065 ../lib/Utils.c:1110 BL_Login end transaction [BL_Login_NotificationInitFrame]
00:00:41 [2004-06-16 18:24:54] 065 ../lib/Utils.c:1134 BL_Login transaction result [BL_Login_NotificationInitFrame] [0.041671] [LR_PASS] [0.000000]
00:00:44 [2004-06-16 18:24:57] 043 ../lib/Utils.c:1209 FL_Login start transaction [FL_Login_Send]
00:00:51 [2004-06-16 18:25:04] 065 ../lib/Utils.c:1209 BL_Login start transaction [BL_Login_Send]
00:01:00 [2004-06-16 18:25:13] 043 ../lib/Utils.c:1110 FL_Login end transaction [FL_Login_Send]
00:01:00 [2004-06-16 18:25:13] 043 ../lib/Utils.c:1134 FL_Login transaction result [FL_Login_Send] [16.080589] [LR_PASS] [0.001000]
00:01:04 [2004-06-16 18:25:17] 065 ../lib/Utils.c:1110 BL_Login end transaction [BL_Login_Send]
00:01:04 [2004-06-16 18:25:17] 065 ../lib/Utils.c:1134 BL_Login transaction result [BL_Login_Send] [12.559203] [LR_PASS] [0.000000]
00:01:10 [2004-06-16 18:25:23] 043 ../lib/NotificationInit.c:6 FL_NotificationInit global_current_action_name [NotificationInit]
00:01:10 [2004-06-16 18:25:23] 043 ../lib/Utils.c:1224 FL_NotificationInit start transaction [FL_NotificationInit_InitFrame]
"""