-! timeout 30
-$ $SG_TEST_EXENV ./pmm_simulator$EXEEXT ${srcdir:=.}/../../msg/msg_platform.xml ${srcdir:=.}/pmm.xml
-> [Jacquelin:master:(1) 0.000000] [pmm/INFO] Wait for peers for 2 sec
-> [Laroche:slave:(10) 0.000000] [pmm/INFO] Sensor 8 starting
-> [Gatien:slave:(9) 0.000000] [pmm/INFO] Sensor 7 starting
-> [McGee:slave:(8) 0.000000] [pmm/INFO] Sensor 6 starting
-> [iRMX:slave:(7) 0.000000] [pmm/INFO] Sensor 5 starting
-> [Disney:slave:(6) 0.000000] [pmm/INFO] Sensor 4 starting
-> [Geoff:slave:(5) 0.000000] [pmm/INFO] Sensor 3 starting
-> [TeX:slave:(4) 0.000000] [pmm/INFO] Sensor 2 starting
-> [Jean_Yves:slave:(3) 0.000000] [pmm/INFO] Sensor 1 starting
-> [Boivin:slave:(2) 0.000000] [pmm/INFO] Sensor 0 starting
-> [Jacquelin:master:(1) 2.879074] [pmm/INFO] Got only 1 pals. Wait 2 more seconds
-> [Jacquelin:master:(1) 4.879074] [pmm/INFO] Got only 3 pals. Wait 2 more seconds
-> [Jacquelin:master:(1) 8.034879] [pmm/INFO] Got only 4 pals. Wait 2 more seconds
-> [Jacquelin:master:(1) 10.945925] [pmm/INFO] Got only 7 pals. Wait 2 more seconds
-> [Jacquelin:master:(1) 12.945925] [pmm/INFO] Good. Got 9 pals
-> [Jacquelin:master:(1) 12.947329] [pmm/INFO] XXXXXXXXXXXXXXXXXXXXXX begin Multiplication
-> [Laroche:slave:(10) 15.396005] [pmm/INFO] Receive my pos (0,0) and assignment
-> [iRMX:slave:(7) 16.396517] [gras_msg/INFO] No callback for message 'dataB' (type:ONEWAY) from Laroche:3000. Queue it for later gras_msg_wait() use.
-> [Gatien:slave:(9) 16.421423] [pmm/INFO] Receive my pos (0,1) and assignment
-> [McGee:slave:(8) 17.136174] [pmm/INFO] Receive my pos (0,2) and assignment
-> [Disney:slave:(6) 17.505383] [gras_msg/INFO] No callback for message 'dataB' (type:ONEWAY) from Gatien:3000. Queue it for later gras_msg_wait() use.
-> [Geoff:slave:(5) 17.844782] [gras_msg/INFO] No callback for message 'dataB' (type:ONEWAY) from McGee:3000. Queue it for later gras_msg_wait() use.
-> [Boivin:slave:(2) 17.928810] [gras_msg/INFO] No callback for message 'dataB' (type:ONEWAY) from McGee:3000. Queue it for later gras_msg_wait() use.
-> [TeX:slave:(4) 17.959568] [gras_msg/INFO] No callback for message 'dataB' (type:ONEWAY) from Laroche:3000. Queue it for later gras_msg_wait() use.
-> [Jean_Yves:slave:(3) 19.252626] [gras_msg/INFO] No callback for message 'dataB' (type:ONEWAY) from Gatien:3000. Queue it for later gras_msg_wait() use.
-> [iRMX:slave:(7) 19.845316] [pmm/INFO] Receive my pos (1,0) and assignment
-> [Disney:slave:(6) 21.312500] [pmm/INFO] Receive my pos (1,1) and assignment
-> [Geoff:slave:(5) 21.317052] [pmm/INFO] Receive my pos (1,2) and assignment
-> [TeX:slave:(4) 22.775453] [pmm/INFO] Receive my pos (2,0) and assignment
-> [Jean_Yves:slave:(3) 23.519740] [pmm/INFO] Receive my pos (2,1) and assignment
-> [Boivin:slave:(2) 24.363634] [pmm/INFO] Receive my pos (2,2) and assignment
-> [Jacquelin:master:(1) 43.582596] [pmm/INFO] XXXXXXXXXXXXXXXXXXXXXX Ok, the result matches expectations
-> [Laroche:slave:(10) 45.022156] [gras/INFO] Exiting GRAS
-> [Gatien:slave:(9) 46.041077] [gras/INFO] Exiting GRAS
-> [McGee:slave:(8) 46.751369] [gras/INFO] Exiting GRAS
-> [iRMX:slave:(7) 49.184579] [gras/INFO] Exiting GRAS
-> [Disney:slave:(6) 50.642444] [gras/INFO] Exiting GRAS
-> [Geoff:slave:(5) 50.646869] [gras/INFO] Exiting GRAS
-> [TeX:slave:(4) 52.095979] [gras/INFO] Exiting GRAS
-> [Jean_Yves:slave:(3) 52.835637] [gras/INFO] Exiting GRAS
-> [Jacquelin:master:(1) 53.674253] [gras/INFO] Exiting GRAS
-> [Boivin:slave:(2) 53.674253] [gras/INFO] Exiting GRAS
+#! ./tesh
+
+! output sort
+$ $SG_TEST_EXENV ./pmm_simulator$EXEEXT ${srcdir:=.}/../../msg/msg_platform.xml ${srcdir:=.}/pmm.xml --log=root.fmt:[%10.6r]%e(%i:%P@%h)%e%m%n
+> [ 0.000156] (1:master@Jacquelin) Wait for peers for 2 sec
+> [ 0.000156] (2:slave@Boivin) Sensor 0 starting
+> [ 0.000156] (3:slave@Jean_Yves) Sensor 1 starting
+> [ 0.000156] (4:slave@TeX) Sensor 2 starting
+> [ 0.000156] (5:slave@Geoff) Sensor 3 starting
+> [ 0.000156] (6:slave@Disney) Sensor 4 starting
+> [ 0.000156] (7:slave@iRMX) Sensor 5 starting
+> [ 0.000156] (8:slave@McGee) Sensor 6 starting
+> [ 0.000156] (9:slave@Gatien) Sensor 7 starting
+> [ 0.000156] (10:slave@Laroche) Sensor 8 starting
+> [ 2.416827] (1:master@Jacquelin) Got only 2 pals (of 9). Wait 2 more seconds
+> [ 4.476356] (1:master@Jacquelin) Got only 3 pals (of 9). Wait 2 more seconds
+> [ 6.476356] (1:master@Jacquelin) Got only 5 pals (of 9). Wait 2 more seconds
+> [ 9.355676] (1:master@Jacquelin) Got only 6 pals (of 9). Wait 2 more seconds
+> [ 12.524103] (1:master@Jacquelin) Good. Got 9 pals
+> [ 12.525507] (1:master@Jacquelin) XXXXXXXXXXXXXXXXXXXXXX begin Multiplication
+> [ 14.369401] (2:slave@Boivin) Receive my pos (0,0) and assignment
+> [ 15.113688] (3:slave@Jean_Yves) Receive my pos (0,1) and assignment
+> [ 16.572089] (4:slave@TeX) Receive my pos (0,2) and assignment
+> [ 16.576641] (5:slave@Geoff) Receive my pos (1,0) and assignment
+> [ 18.043825] (6:slave@Disney) Receive my pos (1,1) and assignment
+> [ 20.492624] (7:slave@iRMX) Receive my pos (1,2) and assignment
+> [ 21.207375] (8:slave@McGee) Receive my pos (2,0) and assignment
+> [ 22.232792] (9:slave@Gatien) Receive my pos (2,1) and assignment
+> [ 23.681469] (10:slave@Laroche) Receive my pos (2,2) and assignment
+> [ 73.318369] (1:master@Jacquelin) XXXXXXXXXXXXXXXXXXXXXX Ok, the result matches expectations
+> [ 74.156986] (2:slave@Boivin) Exiting GRAS
+> [ 74.896643] (3:slave@Jean_Yves) Exiting GRAS
+> [ 76.345754] (4:slave@TeX) Exiting GRAS
+> [ 76.350179] (5:slave@Geoff) Exiting GRAS
+> [ 77.808044] (6:slave@Disney) Exiting GRAS
+> [ 80.241254] (7:slave@iRMX) Exiting GRAS
+> [ 80.951545] (8:slave@McGee) Exiting GRAS
+> [ 81.970467] (9:slave@Gatien) Exiting GRAS
+> [ 83.410027] (1:master@Jacquelin) Exiting GRAS
+> [ 83.410027] (10:slave@Laroche) Exiting GRAS
