Mercurial > hg > drupalISMI

comparison importFromOpenMind/importer/check_ismi_transaction_log.py @ 44:4692e90215eb

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
ISMI transaction log analyser follows thread IDs.
author casties
date Thu, 08 Dec 2016 20:41:33 +0100
parents bb5390f752fc
children f8cd7db4178c
comparison
equal deleted inserted replaced
43:bb5390f752fc 44:4692e90215eb
69 s += ",%s"%(node.get(nf, '')) 69 s += ",%s"%(node.get(nf, ''))
70 70
71 print(s, file=outFile) 71 print(s, file=outFile)
72 72
73 73
74 def parseStart(line): 74 def parseThread(line):
75 tstamp = None 75 tm = re.match('(\d+-\d+-\d+ \d+:\d+:\d+),\d+ (\S+)', line)
76 tm = re.match('(\d+-\d+-\d+ \d+:\d+:\d+)', line)
77 if tm: 76 if tm:
78 tstamp = tm.group(1) 77 tstamp = tm.group(1)
78 tid = tm.group(2)
79
80 return {'time': tstamp, 'tid': tid}
81
82 return None
83
84
85 def parseStart(line):
86 pt = parseThread(line)
87 tstamp = pt['time']
88 tid = pt['tid']
79 89
80 sm = re.search('START Saving (\w+) id=(\w+)', line) 90 sm = re.search('START Saving (\w+) id=(\w+)', line)
81 if sm: 91 if sm:
82 return {'time': tstamp, 'oc': sm.group(1), 'id': sm.group(2)} 92 return {'tid': tid, 'time': tstamp, 'oc': sm.group(1), 'id': sm.group(2)}
83 93
84 sm = re.search('START remove entity: user=\S+ entity=Entity\[rowId=\d+, id=(\d+)', line) 94 sm = re.search('START remove entity: user=\S+ entity=Entity\[rowId=\d+, id=(\d+)', line)
85 if sm: 95 if sm:
86 return {'time': tstamp, 'id': sm.group(1)} 96 return {'tid': tid, 'time': tstamp, 'id': sm.group(1)}
87 97
88 sm = re.search('END Saving (\w+) id=(\w+)', line) 98 sm = re.search('END Saving (\w+) id=(\w+)', line)
89 if sm: 99 if sm:
90 return {'time': tstamp, 'oc': sm.group(1), 'id': sm.group(2)} 100 return {'tid': tid, 'time': tstamp, 'oc': sm.group(1), 'id': sm.group(2)}
91 101
92 sm = re.search('END remove entity: user=\S+ entity=Entity\[rowId=\d+, id=(\d+)', line) 102 sm = re.search('END remove entity: user=\S+ entity=Entity\[rowId=\d+, id=(\d+)', line)
93 if sm: 103 if sm:
94 return {'time': tstamp, 'id': sm.group(1)} 104 return {'tid': tid, 'time': tstamp, 'id': sm.group(1)}
95 105
96 return None 106 return None
97 107
98 108
99 def parseSave(line): 109 def parseSave(line):
276 openSaves = {} 286 openSaves = {}
277 savingPrev = 0 287 savingPrev = 0
278 deleting = 0 288 deleting = 0
279 saveCtx = None 289 saveCtx = None
280 deleteCtx = None 290 deleteCtx = None
281 prevSaves = [] 291 prevSaves = {}
282 saves = [] 292 saves = {}
283 293
284 for line in f: 294 for line in f:
285 linecnt += 1 295 linecnt += 1
286 # 296 #
287 # parsing lines in order of specific match, not order of operation! 297 # parsing lines in order of specific match, not order of operation!
291 # make sure delete is off 301 # make sure delete is off
292 deleting = 0 302 deleting = 0
293 log('DEBUG', line) 303 log('DEBUG', line)
294 # parse time and id 304 # parse time and id
295 saveCtx = parseStart(line) 305 saveCtx = parseStart(line)
296 saveId = saveCtx['id'] 306 tid = saveCtx['tid']
307 saveId = "%s@%s"%(saveCtx['id'], tid)
297 if saveId in openSaves: 308 if saveId in openSaves:
298 log('ERROR', "Duplicate save for same id! %s"%saveCtx) 309 log('ERROR', "Duplicate save for same id! %s"%saveCtx)
299 # assume the first save was spurious 310 # assume the first save was spurious
300 saving -= 1 311 saving -= 1
301 312
306 # TODO: what now? 317 # TODO: what now?
307 318
308 elif '*** END Saving' in line: 319 elif '*** END Saving' in line:
309 saving -= 1 320 saving -= 1
310 saveCtx = parseStart(line) 321 saveCtx = parseStart(line)
311 saveId = saveCtx['id'] 322 tid = saveCtx['tid']
323 saveId = "%s@%s"%(saveCtx['id'], tid)
312 if saveId in openSaves: 324 if saveId in openSaves:
313 log('DEBUG', "End save matches start save: %s"%saveCtx) 325 log('DEBUG', "End save matches start save: %s"%saveCtx)
314 del openSaves[saveId] 326 del openSaves[saveId]
315 327
316 elif 'null' in openSaves: 328 elif "null@%s"%saveCtx['tid'] in openSaves:
317 log('DEBUG', "Assume end save (of %s) matches start save null: %s"%(len(openSaves), saveCtx)) 329 log('DEBUG', "Assume end save (of %s) matches start save null: %s"%(len(openSaves), saveCtx))
318 del openSaves['null'] 330 del openSaves["null@%s"%saveCtx['tid']]
319 331
320 else: 332 else:
321 log("ERROR", "End save without start save! %s"%saveCtx) 333 log("ERROR", "End save without start save! %s"%saveCtx)
322 334
323 # make sure delete is off 335 # make sure delete is off
329 341
330 elif saving < 0: 342 elif saving < 0:
331 log('ERROR', "Too many END saves!") 343 log('ERROR', "Too many END saves!")
332 break 344 break
333 345
346 if tid not in saves:
347 saves[tid] = []
348
349 if tid not in prevSaves:
350 prevSaves[tid] = []
351
334 log("INFO", "saving %s"%saveCtx) 352 log("INFO", "saving %s"%saveCtx)
335 log("INFO", "prev saves: %s"%len(prevSaves)) 353 log("INFO", "prev saves: %s"%len(prevSaves[tid]))
336 log("INFO", "saves: %s"%len(saves)) 354 log("INFO", "saves: %s"%len(saves[tid]))
337 355
338 if len(prevSaves) > 0: 356 if len(prevSaves[tid]) > 0:
339 compareNodeLists(prevSaves, saves, saveCtx, outFile) 357 compareNodeLists(prevSaves[tid], saves[tid], saveCtx, outFile)
340 358
341 prevSaves = [] 359 del prevSaves[tid]
342 saves = [] 360 del saves[tid]
343 361
344 elif '** START save entity' in line: 362 elif '** START save entity' in line:
345 pass 363 pass
346 364
347 elif '** END save entity' in line: 365 elif '** END save entity' in line:
386 404
387 if saving < 0: 405 if saving < 0:
388 log("ERROR", "Too many END save previous!") 406 log("ERROR", "Too many END save previous!")
389 407
390 elif 'save previous' in line: 408 elif 'save previous' in line:
409 # check thread ID
410 td = parseThread(line)
411 tid = td['tid']
412
391 data = parseSave(line) 413 data = parseSave(line)
392 if data is None: 414 if data is None:
393 log("DEBUG", "Error parsing line: %s"%line) 415 log("DEBUG", "Error parsing line: %s"%line)
394 continue 416 continue
395 417
401 or data.get('target-id', None) == delId: 423 or data.get('target-id', None) == delId:
402 log('DEBUG', "intentionally deleted node: %s"%data) 424 log('DEBUG', "intentionally deleted node: %s"%data)
403 425
404 else: 426 else:
405 log('ERROR', "Node without matching id in delete! %s"%data) 427 log('ERROR', "Node without matching id in delete! %s"%data)
406 prevSaves.append(data) 428 if tid in prevSaves:
429 prevSaves[tid].append(data)
430
431 else:
432 prevSaves[tid] = [data]
407 433
408 else: 434 else:
409 prevSaves.append(data) 435 if tid in prevSaves:
436 prevSaves[tid].append(data)
437
438 else:
439 prevSaves[tid] = [data]
410 440
411 elif 'save' in line: 441 elif 'save' in line:
442 # check thread ID
443 td = parseThread(line)
444 tid = td['tid']
445
412 data = parseSave(line) 446 data = parseSave(line)
413 if data is None: 447 if data is None:
414 log("DEBUG", "Error parsing line: %s"%line) 448 log("DEBUG", "Error parsing line: %s"%line)
415 continue 449 continue
416 450
417 saves.append(parseSave(line)) 451 if tid in saves:
452 saves[tid].append(data)
453
454 else:
455 saves[tid] = [data]
418 456
419 if maxLinecnt is not None and linecnt >= maxLinecnt: 457 if maxLinecnt is not None and linecnt >= maxLinecnt:
420 break 458 break
421 459
460 if len(saves) > 0:
461 log('ERROR', "%s unprocessed saves!"%len(saves))
462 log('DEBUG', saves)
463
464 if len(prevSaves) > 0:
465 log('ERROR', "%s unprocessed previous saves!"%len(prevSaves))
466 log('DEBUG', prevSaves)
467
422 log("SYSMSG", "%s lines of logfile scanned"%linecnt) 468 log("SYSMSG", "%s lines of logfile scanned"%linecnt)
423 469
424 470
425 # 471 #
426 # public static void main :-) 472 # public static void main :-)