p Tracing master/slave application
-$ $SG_TEST_EXENV ${bindir:=.}/tracing/ms$EXEEXT --cfg=tracing:1 --cfg=tracing/filename:tracing/ms.trace --cfg=tracing/categorized:1 --cfg=tracing/uncategorized:1 --cfg=triva/categorized:tracing/ms.cat.plist --cfg=triva/uncategorized:tracing/ms.uncat.plist --log=instr_paje.thres:debug --log=instr_paje_trace.thres:debug "--log=root.fmt:[%10.6r]%e\(%i:%P@%h\)%e%m%n" ${srcdir:=.}/tracing/platform.xml ${srcdir:=.}/tracing/deployment.xml
+$ $SG_TEST_EXENV ${bindir:=.}/tracing/ms$EXEEXT --cfg=tracing:1 --cfg=tracing/buffer:1 --cfg=tracing/buffer:1 --cfg=tracing/filename:tracing/ms.trace --cfg=tracing/categorized:1 --cfg=tracing/uncategorized:1 --cfg=triva/categorized:tracing/ms.cat.plist --cfg=triva/uncategorized:tracing/ms.uncat.plist --log=instr_paje.thres:debug --log=instr_paje_trace.thres:debug "--log=root.fmt:[%10.6r]%e\(%i:%P@%h\)%e%m%n" ${srcdir:=.}/tracing/platform.xml ${srcdir:=.}/tracing/deployment.xml
> [ 0.000000] (0:@) Configuration change: Set 'tracing' to '1'
+> [ 0.000000] (0:@) Configuration change: Set 'tracing/buffer' to '1'
+> [ 0.000000] (0:@) Configuration change: Set 'tracing/buffer' to '1'
> [ 0.000000] (0:@) Configuration change: Set 'tracing/filename' to 'tracing/ms.trace'
> [ 0.000000] (0:@) Configuration change: Set 'tracing/categorized' to '1'
> [ 0.000000] (0:@) Configuration change: Set 'tracing/uncategorized' to '1'
> [ 0.017364] (0:@) TRACE_paje_dump_buffer: ends
> [ 0.168126] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.017364
> [ 0.168126] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.017364, buffersize=2)
-> [ 0.168126] (0:@) insert_into_buffer: inserted at end
+> [ 0.168126] (0:@) insert_into_buffer: inserted at end, pos = 2
> [ 0.168126] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.017364
> [ 0.168126] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.017364, buffersize=3)
> [ 0.168126] (0:@) insert_into_buffer: inserted at end, pos = 3
> [ 0.168126] (0:@) new_pajeSubVariable: event_type=10, timestamp=0.168126
> [ 0.168126] (0:@) insert_into_buffer: insert event_type=10, timestamp=0.168126, buffersize=4)
-> [ 0.168126] (0:@) insert_into_buffer: inserted at end
+> [ 0.168126] (0:@) insert_into_buffer: inserted at end, pos = 4
> [ 0.168126] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.017364
> [ 0.168126] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.017364, buffersize=5)
> [ 0.168126] (0:@) insert_into_buffer: inserted at 4
> [ 0.188676] (0:@) TRACE_paje_dump_buffer: ends
> [ 0.386279] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.188676
> [ 0.386279] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.188676, buffersize=16)
-> [ 0.386279] (0:@) insert_into_buffer: inserted at end
+> [ 0.386279] (0:@) insert_into_buffer: inserted at end, pos = 16
> [ 0.386279] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.188676
> [ 0.386279] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.188676, buffersize=17)
> [ 0.386279] (0:@) insert_into_buffer: inserted at end, pos = 17
> [ 0.386279] (0:@) new_pajeSubVariable: event_type=10, timestamp=0.386279
> [ 0.386279] (0:@) insert_into_buffer: insert event_type=10, timestamp=0.386279, buffersize=18)
-> [ 0.386279] (0:@) insert_into_buffer: inserted at end
+> [ 0.386279] (0:@) insert_into_buffer: inserted at end, pos = 18
> [ 0.386279] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.188676
> [ 0.386279] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.188676, buffersize=19)
> [ 0.386279] (0:@) insert_into_buffer: inserted at 18
> [ 0.511874] (0:@) insert_into_buffer: inserted at end, pos = 58
> [ 0.511874] (0:@) new_pajeSubVariable: event_type=10, timestamp=0.511874
> [ 0.511874] (0:@) insert_into_buffer: insert event_type=10, timestamp=0.511874, buffersize=59)
-> [ 0.511874] (0:@) insert_into_buffer: inserted at end
+> [ 0.511874] (0:@) insert_into_buffer: inserted at end, pos = 59
> [ 0.511874] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.386279
> [ 0.511874] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.386279, buffersize=60)
> [ 0.511874] (0:@) insert_into_buffer: inserted at 59
> [ 0.526739] (0:@) insert_into_buffer: inserted at end, pos = 76
> [ 0.526739] (0:@) new_pajeSubVariable: event_type=10, timestamp=0.526739
> [ 0.526739] (0:@) insert_into_buffer: insert event_type=10, timestamp=0.526739, buffersize=77)
-> [ 0.526739] (0:@) insert_into_buffer: inserted at end
+> [ 0.526739] (0:@) insert_into_buffer: inserted at end, pos = 77
> [ 0.526739] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.511874
> [ 0.526739] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.511874, buffersize=78)
> [ 0.526739] (0:@) insert_into_buffer: inserted at 77
> [ 0.547074] (0:@) TRACE_paje_dump_buffer: ends
> [ 0.742611] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.547074
> [ 0.742611] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.547074, buffersize=90)
-> [ 0.742611] (0:@) insert_into_buffer: inserted at end
+> [ 0.742611] (0:@) insert_into_buffer: inserted at end, pos = 90
> [ 0.742611] (0:@) new_pajeSubVariable: event_type=10, timestamp=0.742611
> [ 0.742611] (0:@) insert_into_buffer: insert event_type=10, timestamp=0.742611, buffersize=91)
-> [ 0.742611] (0:@) insert_into_buffer: inserted at end
+> [ 0.742611] (0:@) insert_into_buffer: inserted at end, pos = 91
> [ 0.742611] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.547074
> [ 0.742611] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.547074, buffersize=92)
> [ 0.742611] (0:@) insert_into_buffer: inserted at 91
> [ 0.744775] (0:@) TRACE_paje_dump_buffer: ends
> [ 0.744775] (2:slave@Tremblay) new_pajeAddVariable: event_type=9, timestamp=0.744775
> [ 0.744775] (2:slave@Tremblay) insert_into_buffer: insert event_type=9, timestamp=0.744775, buffersize=106)
-> [ 0.744775] (2:slave@Tremblay) insert_into_buffer: inserted at end
+> [ 0.744775] (2:slave@Tremblay) insert_into_buffer: inserted at end, pos = 106
> [ 0.744775] (1:master@Tremblay) new_pajeSetVariable: event_type=8, timestamp=0.744775
> [ 0.744775] (1:master@Tremblay) insert_into_buffer: insert event_type=8, timestamp=0.744775, buffersize=107)
> [ 0.744775] (1:master@Tremblay) insert_into_buffer: inserted at end, pos = 107
> [ 0.823468] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.168126
> [ 0.823468] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.168126, buffersize=108)
-> [ 0.823468] (0:@) insert_into_buffer: inserted at 0
+> [ 0.823468] (0:@) insert_into_buffer: inserted at beginning
> [ 0.823468] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.168126
> [ 0.823468] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.168126, buffersize=109)
> [ 0.823468] (0:@) insert_into_buffer: inserted at 1
> [ 0.823468] (0:@) new_pajeSubVariable: event_type=10, timestamp=0.823468
> [ 0.823468] (0:@) insert_into_buffer: insert event_type=10, timestamp=0.823468, buffersize=110)
-> [ 0.823468] (0:@) insert_into_buffer: inserted at end
+> [ 0.823468] (0:@) insert_into_buffer: inserted at end, pos = 110
> [ 0.823468] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.168126
> [ 0.823468] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.168126, buffersize=111)
> [ 0.823468] (0:@) insert_into_buffer: inserted at 2
> [ 0.838668] (0:@) TRACE_paje_dump_buffer: ends
> [ 0.989430] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.838668
> [ 0.989430] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.838668, buffersize=68)
-> [ 0.989430] (0:@) insert_into_buffer: inserted at end
+> [ 0.989430] (0:@) insert_into_buffer: inserted at end, pos = 68
> [ 0.989430] (0:@) new_pajeSubVariable: event_type=10, timestamp=0.989430
> [ 0.989430] (0:@) insert_into_buffer: insert event_type=10, timestamp=0.989430, buffersize=69)
-> [ 0.989430] (0:@) insert_into_buffer: inserted at end
+> [ 0.989430] (0:@) insert_into_buffer: inserted at end, pos = 69
> [ 0.989430] (0:@) TRACE_paje_dump_buffer: dump until 0.386279. starts
> [ 0.989430] (0:@) TRACE_paje_dump_buffer: ends
> [ 0.989430] (1:master@Tremblay) new_pajeSetVariable: event_type=8, timestamp=0.989430
> [ 0.989430] (0:@) insert_into_buffer: inserted at end, pos = 75
> [ 1.041621] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.386279
> [ 1.041621] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.386279, buffersize=76)
-> [ 1.041621] (0:@) insert_into_buffer: inserted at 0
+> [ 1.041621] (0:@) insert_into_buffer: inserted at beginning
> [ 1.041621] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.386279
> [ 1.041621] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.386279, buffersize=77)
> [ 1.041621] (0:@) insert_into_buffer: inserted at 1
> [ 1.041621] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.041621
> [ 1.041621] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.041621, buffersize=78)
-> [ 1.041621] (0:@) insert_into_buffer: inserted at end
+> [ 1.041621] (0:@) insert_into_buffer: inserted at end, pos = 78
> [ 1.041621] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.386279
> [ 1.041621] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.386279, buffersize=79)
> [ 1.041621] (0:@) insert_into_buffer: inserted at 2
> [ 1.254485] (0:@) insert_into_buffer: inserted at 46
> [ 1.254485] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.254485
> [ 1.254485] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.254485, buffersize=49)
-> [ 1.254485] (0:@) insert_into_buffer: inserted at end
+> [ 1.254485] (0:@) insert_into_buffer: inserted at end, pos = 49
> [ 1.254485] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.989430
> [ 1.254485] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.989430, buffersize=50)
> [ 1.254485] (0:@) insert_into_buffer: inserted at 47
> [ 1.259775] (0:@) insert_into_buffer: inserted at end, pos = 64
> [ 1.259775] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.259775
> [ 1.259775] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.259775, buffersize=65)
-> [ 1.259775] (0:@) insert_into_buffer: inserted at end
+> [ 1.259775] (0:@) insert_into_buffer: inserted at end, pos = 65
> [ 1.259775] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.254485
> [ 1.259775] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.254485, buffersize=66)
> [ 1.259775] (0:@) insert_into_buffer: inserted at 65
> [ 1.261939] (0:@) TRACE_paje_dump_buffer: ends
> [ 1.261939] (2:slave@Tremblay) new_pajeAddVariable: event_type=9, timestamp=1.261939
> [ 1.261939] (2:slave@Tremblay) insert_into_buffer: insert event_type=9, timestamp=1.261939, buffersize=78)
-> [ 1.261939] (2:slave@Tremblay) insert_into_buffer: inserted at end
+> [ 1.261939] (2:slave@Tremblay) insert_into_buffer: inserted at end, pos = 78
> [ 1.261939] (1:master@Tremblay) new_pajeSetVariable: event_type=8, timestamp=1.261939
> [ 1.261939] (1:master@Tremblay) insert_into_buffer: insert event_type=8, timestamp=1.261939, buffersize=79)
> [ 1.261939] (1:master@Tremblay) insert_into_buffer: inserted at end, pos = 79
> [ 1.557837] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.526739
> [ 1.557837] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.526739, buffersize=80)
-> [ 1.557837] (0:@) insert_into_buffer: inserted at 0
+> [ 1.557837] (0:@) insert_into_buffer: inserted at beginning
> [ 1.557837] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.526739
> [ 1.557837] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.526739, buffersize=81)
> [ 1.557837] (0:@) insert_into_buffer: inserted at 1
> [ 1.557837] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.557837
> [ 1.557837] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.557837, buffersize=82)
-> [ 1.557837] (0:@) insert_into_buffer: inserted at end
+> [ 1.557837] (0:@) insert_into_buffer: inserted at end, pos = 82
> [ 1.557837] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.526739
> [ 1.557837] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.526739, buffersize=83)
> [ 1.557837] (0:@) insert_into_buffer: inserted at 2
> [ 1.644772] (0:@) insert_into_buffer: inserted at 14
> [ 1.644772] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.644772
> [ 1.644772] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.644772, buffersize=49)
-> [ 1.644772] (0:@) insert_into_buffer: inserted at end
+> [ 1.644772] (0:@) insert_into_buffer: inserted at end, pos = 49
> [ 1.644772] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.989430
> [ 1.644772] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.989430, buffersize=50)
> [ 1.644772] (0:@) insert_into_buffer: inserted at 15
> [ 1.698296] (0:@) insert_into_buffer: inserted at end, pos = 58
> [ 1.698296] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.698296
> [ 1.698296] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.698296, buffersize=59)
-> [ 1.698296] (0:@) insert_into_buffer: inserted at end
+> [ 1.698296] (0:@) insert_into_buffer: inserted at end, pos = 59
> [ 1.698296] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.644772
> [ 1.698296] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.644772, buffersize=60)
> [ 1.698296] (0:@) insert_into_buffer: inserted at 59
> [ 1.771649] (0:@) insert_into_buffer: inserted at end, pos = 70
> [ 1.771649] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.771649
> [ 1.771649] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.771649, buffersize=71)
-> [ 1.771649] (0:@) insert_into_buffer: inserted at end
+> [ 1.771649] (0:@) insert_into_buffer: inserted at end, pos = 71
> [ 1.771649] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.698296
> [ 1.771649] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.698296, buffersize=72)
> [ 1.771649] (0:@) insert_into_buffer: inserted at 71
> [ 1.771649] (0:@) TRACE_paje_dump_buffer: ends
> [ 1.773709] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.742611
> [ 1.773709] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.742611, buffersize=78)
-> [ 1.773709] (0:@) insert_into_buffer: inserted at 0
+> [ 1.773709] (0:@) insert_into_buffer: inserted at beginning
> [ 1.773709] (0:@) new_pajeAddVariable: event_type=9, timestamp=0.742611
> [ 1.773709] (0:@) insert_into_buffer: insert event_type=9, timestamp=0.742611, buffersize=79)
> [ 1.773709] (0:@) insert_into_buffer: inserted at 1
> [ 1.773709] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.773709
> [ 1.773709] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.773709, buffersize=80)
-> [ 1.773709] (0:@) insert_into_buffer: inserted at end
+> [ 1.773709] (0:@) insert_into_buffer: inserted at end, pos = 80
> [ 1.773709] (0:@) new_pajeSetVariable: event_type=8, timestamp=0.742611
> [ 1.773709] (0:@) insert_into_buffer: insert event_type=8, timestamp=0.742611, buffersize=81)
> [ 1.773709] (0:@) insert_into_buffer: inserted at 2
> [ 1.864258] (0:@) insert_into_buffer: inserted at end, pos = 38
> [ 1.864258] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.864258
> [ 1.864258] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.864258, buffersize=39)
-> [ 1.864258] (0:@) insert_into_buffer: inserted at end
+> [ 1.864258] (0:@) insert_into_buffer: inserted at end, pos = 39
> [ 1.864258] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.773709
> [ 1.864258] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.773709, buffersize=40)
> [ 1.864258] (0:@) insert_into_buffer: inserted at 39
> [ 1.866422] (0:@) TRACE_paje_dump_buffer: ends
> [ 1.866422] (2:slave@Tremblay) new_pajeAddVariable: event_type=9, timestamp=1.866422
> [ 1.866422] (2:slave@Tremblay) insert_into_buffer: insert event_type=9, timestamp=1.866422, buffersize=44)
-> [ 1.866422] (2:slave@Tremblay) insert_into_buffer: inserted at end
+> [ 1.866422] (2:slave@Tremblay) insert_into_buffer: inserted at end, pos = 44
> [ 1.866422] (1:master@Tremblay) new_pajeSetVariable: event_type=8, timestamp=1.866422
> [ 1.866422] (1:master@Tremblay) insert_into_buffer: insert event_type=8, timestamp=1.866422, buffersize=45)
> [ 1.866422] (1:master@Tremblay) insert_into_buffer: inserted at end, pos = 45
> [ 1.886758] (0:@) TRACE_paje_dump_buffer: ends
> [ 1.915117] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.259775
> [ 1.915117] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.259775, buffersize=46)
-> [ 1.915117] (0:@) insert_into_buffer: inserted at 0
+> [ 1.915117] (0:@) insert_into_buffer: inserted at beginning
> [ 1.915117] (0:@) new_pajeSubVariable: event_type=10, timestamp=1.915117
> [ 1.915117] (0:@) insert_into_buffer: insert event_type=10, timestamp=1.915117, buffersize=47)
-> [ 1.915117] (0:@) insert_into_buffer: inserted at end
+> [ 1.915117] (0:@) insert_into_buffer: inserted at end, pos = 47
> [ 1.915117] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.259775
> [ 1.915117] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.259775, buffersize=48)
> [ 1.915117] (0:@) insert_into_buffer: inserted at 1
> [ 1.915117] (0:@) TRACE_paje_dump_buffer: ends
> [ 2.082294] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.915117
> [ 2.082294] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.915117, buffersize=50)
-> [ 2.082294] (0:@) insert_into_buffer: inserted at end
+> [ 2.082294] (0:@) insert_into_buffer: inserted at end, pos = 50
> [ 2.082294] (0:@) new_pajeSubVariable: event_type=10, timestamp=2.082294
> [ 2.082294] (0:@) insert_into_buffer: insert event_type=10, timestamp=2.082294, buffersize=51)
-> [ 2.082294] (0:@) insert_into_buffer: inserted at end
+> [ 2.082294] (0:@) insert_into_buffer: inserted at end, pos = 51
> [ 2.082294] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.915117
> [ 2.082294] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.915117, buffersize=52)
> [ 2.082294] (0:@) insert_into_buffer: inserted at 51
> [ 2.102845] (0:@) TRACE_paje_dump_buffer: ends
> [ 2.300447] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.102845
> [ 2.300447] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.102845, buffersize=84)
-> [ 2.300447] (0:@) insert_into_buffer: inserted at end
+> [ 2.300447] (0:@) insert_into_buffer: inserted at end, pos = 84
> [ 2.300447] (0:@) new_pajeSubVariable: event_type=10, timestamp=2.300447
> [ 2.300447] (0:@) insert_into_buffer: insert event_type=10, timestamp=2.300447, buffersize=85)
-> [ 2.300447] (0:@) insert_into_buffer: inserted at end
+> [ 2.300447] (0:@) insert_into_buffer: inserted at end, pos = 85
> [ 2.300447] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.102845
> [ 2.300447] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.102845, buffersize=86)
> [ 2.300447] (0:@) insert_into_buffer: inserted at 85
> [ 2.376132] (0:@) insert_into_buffer: inserted at end, pos = 114
> [ 2.376132] (0:@) new_pajeSubVariable: event_type=10, timestamp=2.376132
> [ 2.376132] (0:@) insert_into_buffer: insert event_type=10, timestamp=2.376132, buffersize=115)
-> [ 2.376132] (0:@) insert_into_buffer: inserted at end
+> [ 2.376132] (0:@) insert_into_buffer: inserted at end, pos = 115
> [ 2.376132] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.300447
> [ 2.376132] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.300447, buffersize=116)
> [ 2.376132] (0:@) insert_into_buffer: inserted at 115
> [ 2.378296] (0:@) TRACE_paje_dump_buffer: ends
> [ 2.378296] (1:master@Tremblay) new_pajeSetVariable: event_type=8, timestamp=2.378296
> [ 2.378296] (1:master@Tremblay) insert_into_buffer: insert event_type=8, timestamp=2.378296, buffersize=118)
-> [ 2.378296] (1:master@Tremblay) insert_into_buffer: inserted at end
+> [ 2.378296] (1:master@Tremblay) insert_into_buffer: inserted at end, pos = 118
> [ 2.378296] (2:slave@Tremblay) new_pajeAddVariable: event_type=9, timestamp=2.378296
> [ 2.378296] (2:slave@Tremblay) insert_into_buffer: insert event_type=9, timestamp=2.378296, buffersize=119)
> [ 2.378296] (2:slave@Tremblay) insert_into_buffer: inserted at end, pos = 119
> [ 2.519600] (0:@) insert_into_buffer: inserted at 18
> [ 2.519600] (0:@) new_pajeSubVariable: event_type=10, timestamp=2.519600
> [ 2.519600] (0:@) insert_into_buffer: insert event_type=10, timestamp=2.519600, buffersize=121)
-> [ 2.519600] (0:@) insert_into_buffer: inserted at end
+> [ 2.519600] (0:@) insert_into_buffer: inserted at end, pos = 121
> [ 2.519600] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.864258
> [ 2.519600] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.864258, buffersize=122)
> [ 2.519600] (0:@) insert_into_buffer: inserted at 19
> [ 2.534800] (0:@) TRACE_paje_dump_buffer: ends
> [ 2.685562] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.534800
> [ 2.685562] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.534800, buffersize=124)
-> [ 2.685562] (0:@) insert_into_buffer: inserted at end
+> [ 2.685562] (0:@) insert_into_buffer: inserted at end, pos = 124
> [ 2.685562] (0:@) new_pajeSubVariable: event_type=10, timestamp=2.685562
> [ 2.685562] (0:@) insert_into_buffer: insert event_type=10, timestamp=2.685562, buffersize=125)
-> [ 2.685562] (0:@) insert_into_buffer: inserted at end
+> [ 2.685562] (0:@) insert_into_buffer: inserted at end, pos = 125
> [ 2.685562] (0:@) TRACE_paje_dump_buffer: dump until 1.698296. starts
> [ 2.685562] (0:@) TRACE_paje_dump_buffer: ends
> [ 2.685562] (1:master@Tremblay) new_pajeSetVariable: event_type=8, timestamp=2.685562
> [ 2.685562] (0:@) insert_into_buffer: inserted at end, pos = 131
> [ 2.729394] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.698296
> [ 2.729394] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.698296, buffersize=132)
-> [ 2.729394] (0:@) insert_into_buffer: inserted at 0
+> [ 2.729394] (0:@) insert_into_buffer: inserted at beginning
> [ 2.729394] (0:@) new_pajeSubVariable: event_type=10, timestamp=2.729394
> [ 2.729394] (0:@) insert_into_buffer: insert event_type=10, timestamp=2.729394, buffersize=133)
-> [ 2.729394] (0:@) insert_into_buffer: inserted at end
+> [ 2.729394] (0:@) insert_into_buffer: inserted at end, pos = 133
> [ 2.729394] (0:@) new_pajeAddVariable: event_type=9, timestamp=1.698296
> [ 2.729394] (0:@) insert_into_buffer: insert event_type=9, timestamp=1.698296, buffersize=134)
> [ 2.729394] (0:@) insert_into_buffer: inserted at 1
> [ 2.742626] (0:@) TRACE_paje_dump_buffer: ends
> [ 2.869854] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.742626
> [ 2.869854] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.742626, buffersize=46)
-> [ 2.869854] (0:@) insert_into_buffer: inserted at end
+> [ 2.869854] (0:@) insert_into_buffer: inserted at end, pos = 46
> [ 2.869854] (0:@) new_pajeSubVariable: event_type=10, timestamp=2.869854
> [ 2.869854] (0:@) insert_into_buffer: insert event_type=10, timestamp=2.869854, buffersize=47)
-> [ 2.869854] (0:@) insert_into_buffer: inserted at end
+> [ 2.869854] (0:@) insert_into_buffer: inserted at end, pos = 47
> [ 2.869854] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.742626
> [ 2.869854] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.742626, buffersize=48)
> [ 2.869854] (0:@) insert_into_buffer: inserted at 47
> [ 2.888006] (0:@) insert_into_buffer: inserted at end, pos = 58
> [ 2.888006] (0:@) new_pajeSubVariable: event_type=10, timestamp=2.888006
> [ 2.888006] (0:@) insert_into_buffer: insert event_type=10, timestamp=2.888006, buffersize=59)
-> [ 2.888006] (0:@) insert_into_buffer: inserted at end
+> [ 2.888006] (0:@) insert_into_buffer: inserted at end, pos = 59
> [ 2.888006] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.869854
> [ 2.888006] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.869854, buffersize=60)
> [ 2.888006] (0:@) insert_into_buffer: inserted at 59
> [ 2.890170] (0:@) TRACE_paje_dump_buffer: ends
> [ 2.890170] (1:master@Tremblay) new_pajeSetVariable: event_type=8, timestamp=2.890170
> [ 2.890170] (1:master@Tremblay) insert_into_buffer: insert event_type=8, timestamp=2.890170, buffersize=62)
-> [ 2.890170] (1:master@Tremblay) insert_into_buffer: inserted at end
+> [ 2.890170] (1:master@Tremblay) insert_into_buffer: inserted at end, pos = 62
> [ 2.890170] (2:slave@Tremblay) new_pajeAddVariable: event_type=9, timestamp=2.890170
> [ 2.890170] (2:slave@Tremblay) insert_into_buffer: insert event_type=9, timestamp=2.890170, buffersize=63)
> [ 2.890170] (2:slave@Tremblay) insert_into_buffer: inserted at end, pos = 63
> [ 2.955790] (0:@) insert_into_buffer: inserted at 30
> [ 2.955790] (0:@) new_pajeSubVariable: event_type=10, timestamp=2.955790
> [ 2.955790] (0:@) insert_into_buffer: insert event_type=10, timestamp=2.955790, buffersize=65)
-> [ 2.955790] (0:@) insert_into_buffer: inserted at end
+> [ 2.955790] (0:@) insert_into_buffer: inserted at end, pos = 65
> [ 2.955790] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.300447
> [ 2.955790] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.300447, buffersize=66)
> [ 2.955790] (0:@) insert_into_buffer: inserted at 31
> [ 2.976340] (0:@) TRACE_paje_dump_buffer: ends
> [ 3.113392] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.082294
> [ 3.113392] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.082294, buffersize=68)
-> [ 3.113392] (0:@) insert_into_buffer: inserted at 0
+> [ 3.113392] (0:@) insert_into_buffer: inserted at beginning
> [ 3.113392] (0:@) new_pajeSubVariable: event_type=10, timestamp=3.113392
> [ 3.113392] (0:@) insert_into_buffer: insert event_type=10, timestamp=3.113392, buffersize=69)
-> [ 3.113392] (0:@) insert_into_buffer: inserted at end
+> [ 3.113392] (0:@) insert_into_buffer: inserted at end, pos = 69
> [ 3.113392] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.082294
> [ 3.113392] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.082294, buffersize=70)
> [ 3.113392] (0:@) insert_into_buffer: inserted at 1
> [ 3.173943] (0:@) insert_into_buffer: inserted at end, pos = 34
> [ 3.173943] (0:@) new_pajeSubVariable: event_type=10, timestamp=3.173943
> [ 3.173943] (0:@) insert_into_buffer: insert event_type=10, timestamp=3.173943, buffersize=35)
-> [ 3.173943] (0:@) insert_into_buffer: inserted at end
+> [ 3.173943] (0:@) insert_into_buffer: inserted at end, pos = 35
> [ 3.173943] (0:@) new_pajeAddVariable: event_type=9, timestamp=3.113392
> [ 3.173943] (0:@) insert_into_buffer: insert event_type=9, timestamp=3.113392, buffersize=36)
> [ 3.173943] (0:@) insert_into_buffer: inserted at 35
> [ 3.194279] (0:@) TRACE_paje_dump_buffer: ends
> [ 3.340904] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.685562
> [ 3.340904] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.685562, buffersize=52)
-> [ 3.340904] (0:@) insert_into_buffer: inserted at 0
+> [ 3.340904] (0:@) insert_into_buffer: inserted at beginning
> [ 3.340904] (0:@) new_pajeSubVariable: event_type=10, timestamp=3.340904
> [ 3.340904] (0:@) insert_into_buffer: insert event_type=10, timestamp=3.340904, buffersize=53)
-> [ 3.340904] (0:@) insert_into_buffer: inserted at end
+> [ 3.340904] (0:@) insert_into_buffer: inserted at end, pos = 53
> [ 3.340904] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.685562
> [ 3.340904] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.685562, buffersize=54)
> [ 3.340904] (0:@) insert_into_buffer: inserted at 1
> [ 3.389815] (0:@) insert_into_buffer: inserted at end, pos = 68
> [ 3.389815] (0:@) new_pajeSubVariable: event_type=10, timestamp=3.389815
> [ 3.389815] (0:@) insert_into_buffer: insert event_type=10, timestamp=3.389815, buffersize=69)
-> [ 3.389815] (0:@) insert_into_buffer: inserted at end
+> [ 3.389815] (0:@) insert_into_buffer: inserted at end, pos = 69
> [ 3.389815] (0:@) new_pajeAddVariable: event_type=9, timestamp=3.340904
> [ 3.389815] (0:@) insert_into_buffer: insert event_type=9, timestamp=3.340904, buffersize=70)
> [ 3.389815] (0:@) insert_into_buffer: inserted at 69
> [ 3.399880] (0:@) insert_into_buffer: inserted at end, pos = 102
> [ 3.399880] (0:@) new_pajeSubVariable: event_type=10, timestamp=3.399880
> [ 3.399880] (0:@) insert_into_buffer: insert event_type=10, timestamp=3.399880, buffersize=103)
-> [ 3.399880] (0:@) insert_into_buffer: inserted at end
+> [ 3.399880] (0:@) insert_into_buffer: inserted at end, pos = 103
> [ 3.399880] (0:@) new_pajeAddVariable: event_type=9, timestamp=3.389815
> [ 3.399880] (0:@) insert_into_buffer: insert event_type=9, timestamp=3.389815, buffersize=104)
> [ 3.399880] (0:@) insert_into_buffer: inserted at 103
> [ 3.829285] (0:@) insert_into_buffer: inserted at 40
> [ 3.829285] (0:@) new_pajeSubVariable: event_type=10, timestamp=3.829285
> [ 3.829285] (0:@) insert_into_buffer: insert event_type=10, timestamp=3.829285, buffersize=107)
-> [ 3.829285] (0:@) insert_into_buffer: inserted at end
+> [ 3.829285] (0:@) insert_into_buffer: inserted at end, pos = 107
> [ 3.829285] (0:@) new_pajeAddVariable: event_type=9, timestamp=3.173943
> [ 3.829285] (0:@) insert_into_buffer: insert event_type=9, timestamp=3.173943, buffersize=108)
> [ 3.829285] (0:@) insert_into_buffer: inserted at 41
> [ 3.849836] (0:@) TRACE_paje_dump_buffer: ends
> [ 3.900952] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.869854
> [ 3.900952] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.869854, buffersize=110)
-> [ 3.900952] (0:@) insert_into_buffer: inserted at 0
+> [ 3.900952] (0:@) insert_into_buffer: inserted at beginning
> [ 3.900952] (0:@) new_pajeSubVariable: event_type=10, timestamp=3.900952
> [ 3.900952] (0:@) insert_into_buffer: insert event_type=10, timestamp=3.900952, buffersize=111)
-> [ 3.900952] (0:@) insert_into_buffer: inserted at end
+> [ 3.900952] (0:@) insert_into_buffer: inserted at end, pos = 111
> [ 3.900952] (0:@) new_pajeAddVariable: event_type=9, timestamp=2.869854
> [ 3.900952] (0:@) insert_into_buffer: insert event_type=9, timestamp=2.869854, buffersize=112)
> [ 3.900952] (0:@) insert_into_buffer: inserted at 1
> [ 3.914183] (0:@) TRACE_paje_dump_buffer: ends
> [ 4.420913] (0:@) new_pajeAddVariable: event_type=9, timestamp=3.389815
> [ 4.420913] (0:@) insert_into_buffer: insert event_type=9, timestamp=3.389815, buffersize=6)
-> [ 4.420913] (0:@) insert_into_buffer: inserted at 0
+> [ 4.420913] (0:@) insert_into_buffer: inserted at beginning
> [ 4.420913] (0:@) new_pajeSubVariable: event_type=10, timestamp=4.420913
> [ 4.420913] (0:@) insert_into_buffer: insert event_type=10, timestamp=4.420913, buffersize=7)
-> [ 4.420913] (0:@) insert_into_buffer: inserted at end
+> [ 4.420913] (0:@) insert_into_buffer: inserted at end, pos = 7
> [ 4.420913] (0:@) new_pajeAddVariable: event_type=9, timestamp=3.389815
> [ 4.420913] (0:@) insert_into_buffer: insert event_type=9, timestamp=3.389815, buffersize=8)
> [ 4.420913] (0:@) insert_into_buffer: inserted at 1