# HG changeset patch
# User casties
# Date 1481226093 -3600
# Node ID 4692e90215ebb6d02767450f7d08e8e895b67ba4
# Parent  bb5390f752fc04153da32f5f664894d6616fe78e
ISMI transaction log analyser follows thread IDs.

diff -r bb5390f752fc -r 4692e90215eb importFromOpenMind/importer/check_ismi_transaction_log.py
--- a/importFromOpenMind/importer/check_ismi_transaction_log.py	Thu Dec 08 19:19:02 2016 +0100
+++ b/importFromOpenMind/importer/check_ismi_transaction_log.py	Thu Dec 08 20:41:33 2016 +0100
@@ -71,27 +71,37 @@
     print(s, file=outFile)
 
 
-def parseStart(line):
-    tstamp = None
-    tm = re.match('(\d+-\d+-\d+ \d+:\d+:\d+)', line)
+def parseThread(line):
+    tm = re.match('(\d+-\d+-\d+ \d+:\d+:\d+),\d+ (\S+)', line)
     if tm:
         tstamp = tm.group(1)
+        tid = tm.group(2)
+        
+        return {'time': tstamp, 'tid': tid}
+    
+    return None
+
+
+def parseStart(line):
+    pt = parseThread(line)
+    tstamp = pt['time']
+    tid = pt['tid']
         
     sm = re.search('START Saving (\w+) id=(\w+)', line)
     if sm:
-        return {'time': tstamp, 'oc': sm.group(1), 'id': sm.group(2)}
+        return {'tid': tid, 'time': tstamp, 'oc': sm.group(1), 'id': sm.group(2)}
     
     sm = re.search('START remove entity: user=\S+ entity=Entity\[rowId=\d+, id=(\d+)', line)
     if sm:
-        return {'time': tstamp, 'id': sm.group(1)}
+        return {'tid': tid, 'time': tstamp, 'id': sm.group(1)}
     
     sm = re.search('END Saving (\w+) id=(\w+)', line)
     if sm:
-        return {'time': tstamp, 'oc': sm.group(1), 'id': sm.group(2)}
+        return {'tid': tid, 'time': tstamp, 'oc': sm.group(1), 'id': sm.group(2)}
     
     sm = re.search('END remove entity: user=\S+ entity=Entity\[rowId=\d+, id=(\d+)', line)
     if sm:
-        return {'time': tstamp, 'id': sm.group(1)}
+        return {'tid': tid, 'time': tstamp, 'id': sm.group(1)}
     
     return None
 
@@ -278,8 +288,8 @@
         deleting = 0
         saveCtx = None
         deleteCtx = None
-        prevSaves = []
-        saves = []
+        prevSaves = {}
+        saves = {}
         
         for line in f:
             linecnt += 1
@@ -293,7 +303,8 @@
                 log('DEBUG', line)
                 # parse time and id
                 saveCtx = parseStart(line)
-                saveId = saveCtx['id']
+                tid = saveCtx['tid']
+                saveId = "%s@%s"%(saveCtx['id'], tid)
                 if saveId in openSaves:
                     log('ERROR', "Duplicate save for same id! %s"%saveCtx)
                     # assume the first save was spurious
@@ -308,14 +319,15 @@
             elif '*** END Saving' in line:
                 saving -= 1
                 saveCtx = parseStart(line)
-                saveId = saveCtx['id']
+                tid = saveCtx['tid']
+                saveId = "%s@%s"%(saveCtx['id'], tid)
                 if saveId in openSaves:
                     log('DEBUG', "End save matches start save: %s"%saveCtx)
                     del openSaves[saveId]
                     
-                elif 'null' in openSaves:
+                elif "null@%s"%saveCtx['tid'] in openSaves:
                     log('DEBUG', "Assume end save (of %s) matches start save null: %s"%(len(openSaves), saveCtx))
-                    del openSaves['null']
+                    del openSaves["null@%s"%saveCtx['tid']]
                     
                 else:
                     log("ERROR", "End save without start save! %s"%saveCtx)
@@ -331,15 +343,21 @@
                     log('ERROR', "Too many END saves!")
                     break
                     
+                if tid not in saves:
+                    saves[tid] = []
+                    
+                if tid not in prevSaves:
+                    prevSaves[tid] = []
+                    
                 log("INFO", "saving %s"%saveCtx)
-                log("INFO", "prev saves: %s"%len(prevSaves))
-                log("INFO", "saves: %s"%len(saves))
+                log("INFO", "prev saves: %s"%len(prevSaves[tid]))
+                log("INFO", "saves: %s"%len(saves[tid]))
                 
-                if len(prevSaves) > 0:
-                    compareNodeLists(prevSaves, saves, saveCtx, outFile)
+                if len(prevSaves[tid]) > 0:
+                    compareNodeLists(prevSaves[tid], saves[tid], saveCtx, outFile)
                 
-                prevSaves = []
-                saves = []
+                del prevSaves[tid]
+                del saves[tid]
                             
             elif '** START save entity' in line:
                 pass
@@ -388,6 +406,10 @@
                     log("ERROR", "Too many END save previous!")
             
             elif 'save previous' in line:
+                # check thread ID
+                td = parseThread(line)
+                tid = td['tid']
+                    
                 data = parseSave(line)
                 if data is None:
                     log("DEBUG", "Error parsing line: %s"%line)
@@ -403,22 +425,46 @@
                     
                     else:
                         log('ERROR', "Node without matching id in delete! %s"%data)
-                        prevSaves.append(data)
+                        if tid in prevSaves:
+                            prevSaves[tid].append(data)
+                            
+                        else:
+                            prevSaves[tid] = [data]
                         
                 else:
-                    prevSaves.append(data)
+                    if tid in prevSaves:
+                        prevSaves[tid].append(data)
+                        
+                    else:
+                        prevSaves[tid] = [data]
                 
             elif 'save' in line:
+                # check thread ID
+                td = parseThread(line)
+                tid = td['tid']
+                    
                 data = parseSave(line)
                 if data is None:
                     log("DEBUG", "Error parsing line: %s"%line)
                     continue
                 
-                saves.append(parseSave(line))
+                if tid in saves:
+                    saves[tid].append(data)
+                    
+                else:
+                    saves[tid] = [data]
 
             if maxLinecnt is not None and linecnt >= maxLinecnt:
                 break
                 
+        if len(saves) > 0:
+            log('ERROR', "%s unprocessed saves!"%len(saves))
+            log('DEBUG', saves)
+            
+        if len(prevSaves) > 0:
+            log('ERROR', "%s unprocessed previous saves!"%len(prevSaves))            
+            log('DEBUG', prevSaves)
+        
         log("SYSMSG", "%s lines of logfile scanned"%linecnt)