[14:36:13.779] INFO: === Welcome to pxar ===
[14:36:13.779] INFO: === Today: 2015/09/14
[14:36:13.779] INFO: readRocDacs: M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C0.dat .. M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C15.dat
[14:36:13.780] INFO: readTbmDacs: M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/tbmParameters_C0a.dat .. M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/tbmParameters_C0b.dat
[14:36:13.780] INFO: readMaskFile: M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/defaultMaskFile.dat
[14:36:13.780] INFO: readTrimFile: M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters_C0.dat .. M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters_C15.dat
[14:36:13.851] INFO: clk: 4
[14:36:13.851] INFO: ctr: 4
[14:36:13.851] INFO: sda: 19
[14:36:13.851] INFO: tin: 9
[14:36:13.851] INFO: level: 15
[14:36:13.851] INFO: triggerdelay: 0
[14:36:13.851] QUIET: Instanciating API for pxar prod-10+20~g6580e80
[14:36:13.851] INFO: Log level: INFO
[14:36:13.863] INFO: Found DTB DTB_WS8ZAW
[14:36:13.877] QUIET: Connection to board DTB_WS8ZAW opened.
[14:36:13.881] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 85
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WS8ZAW
MAC address: 40D855118055
Hostname: pixelDTB085
Comment:
------------------------------------------------------
[14:36:13.883] INFO: RPC call hashes of host and DTB match: 397073690
[14:36:15.483] INFO: DUT info:
[14:36:15.483] INFO: The DUT currently contains the following objects:
[14:36:15.484] INFO: 2 TBM Cores tbm08c (2 ON)
[14:36:15.484] INFO: TBM Core alpha (0): 7 registers set
[14:36:15.484] INFO: TBM Core beta (1): 7 registers set
[14:36:15.484] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:36:15.484] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.484] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:36:15.885] INFO: enter 'restricted' command line mode
[14:36:15.885] INFO: enter test to run
[14:36:15.885] INFO: test: Pretest no parameter change
[14:36:15.885] INFO: running: pretest
[14:36:15.892] INFO: ######################################################################
[14:36:15.892] INFO: PixTestPretest::doTest()
[14:36:15.892] INFO: ######################################################################
[14:36:15.895] INFO: ----------------------------------------------------------------------
[14:36:15.895] INFO: PixTestPretest::programROC()
[14:36:15.895] INFO: ----------------------------------------------------------------------
[14:36:33.914] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[14:36:33.915] INFO: IA differences per ROC: 20.1 20.1 20.1 20.1 20.1 20.1 20.1 20.9 20.1 20.9 20.1 20.9 20.1 20.1 20.9 20.9
[14:36:33.976] INFO: ----------------------------------------------------------------------
[14:36:33.976] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[14:36:33.976] INFO: ----------------------------------------------------------------------
[14:36:36.948] INFO: PixTestPretest::setVana() done, Module Ia 385.1 mA = 24.0688 mA/ROC
[14:36:36.950] INFO: ----------------------------------------------------------------------
[14:36:36.950] INFO: PixTestPretest::findTiming()
[14:36:36.950] INFO: ----------------------------------------------------------------------
[14:36:36.950] INFO: PixTestCmd::init()
[14:36:37.578] WARNING: Not unmasking DUT, not setting Calibrate bits!
[14:38:18.381] INFO: TBM phases: 160MHz: 1, 400MHz: 6, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[14:38:18.381] INFO: (success/tries = 100/100), width = 3
[14:38:18.383] INFO: ----------------------------------------------------------------------
[14:38:18.383] INFO: PixTestPretest::findWorkingPixel()
[14:38:18.383] INFO: ----------------------------------------------------------------------
[14:38:18.522] INFO: Expecting 231680 events.
[14:38:23.712] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (1) != Token Chain Length (8)
[14:38:23.715] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (21) != TBM ID (2)
[14:38:26.374] INFO: 231680 events read in total (7073ms).
[14:38:26.378] INFO: Test took 7992ms.
[14:38:26.831] INFO: Found working pixel in all ROCs: col/row = 12/22
[14:38:26.867] INFO: ----------------------------------------------------------------------
[14:38:26.867] INFO: PixTestPretest::setVthrCompCalDel()
[14:38:26.867] INFO: ----------------------------------------------------------------------
[14:38:26.002] INFO: Expecting 231680 events.
[14:38:34.711] INFO: 231680 events read in total (6931ms).
[14:38:34.715] INFO: Test took 7845ms.
[14:38:35.200] INFO: PixTestPretest::setVthrCompCalDel() done
[14:38:35.201] INFO: CalDel: 170 167 143 131 142 131 131 152 145 147 132 149 133 142 132 138
[14:38:35.201] INFO: VthrComp: 51 51 52 51 51 51 51 51 51 51 51 51 51 51 51 51
[14:38:35.204] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C0.dat
[14:38:35.204] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C1.dat
[14:38:35.204] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C2.dat
[14:38:35.204] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C3.dat
[14:38:35.205] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C4.dat
[14:38:35.205] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C5.dat
[14:38:35.205] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C6.dat
[14:38:35.205] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C7.dat
[14:38:35.205] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C8.dat
[14:38:35.205] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C9.dat
[14:38:35.206] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C10.dat
[14:38:35.206] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C11.dat
[14:38:35.206] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C12.dat
[14:38:35.206] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C13.dat
[14:38:35.206] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C14.dat
[14:38:35.207] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters_C15.dat
[14:38:35.207] INFO: write tbm parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/tbmParameters_C0a.dat
[14:38:35.207] INFO: write tbm parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/tbmParameters_C0b.dat
[14:38:35.207] INFO: PixTestPretest::doTest() done, duration: 139 seconds
[14:38:35.269] INFO: enter test to run
[14:38:35.269] INFO: test: FullTest no parameter change
[14:38:35.269] INFO: running: fulltest
[14:38:35.269] INFO: ######################################################################
[14:38:35.270] INFO: PixTestFullTest::doTest()
[14:38:35.270] INFO: ######################################################################
[14:38:35.271] INFO: ######################################################################
[14:38:35.271] INFO: PixTestAlive::doTest()
[14:38:35.271] INFO: ######################################################################
[14:38:35.273] INFO: ----------------------------------------------------------------------
[14:38:35.273] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:38:35.273] INFO: ----------------------------------------------------------------------
[14:38:35.622] INFO: Expecting 41600 events.
[14:38:39.809] INFO: 41600 events read in total (3408ms).
[14:38:39.810] INFO: Test took 4536ms.
[14:38:39.816] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:40.269] INFO: PixTestAlive::aliveTest() done
[14:38:40.269] INFO: number of dead pixels per ROC: 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:38:40.271] INFO: ----------------------------------------------------------------------
[14:38:40.271] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:38:40.271] INFO: ----------------------------------------------------------------------
[14:38:40.628] INFO: Expecting 41600 events.
[14:38:43.590] INFO: 41600 events read in total (2184ms).
[14:38:43.590] INFO: Test took 3317ms.
[14:38:43.590] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:43.591] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[14:38:44.068] INFO: PixTestAlive::maskTest() done
[14:38:44.068] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:38:44.069] INFO: ----------------------------------------------------------------------
[14:38:44.069] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:38:44.069] INFO: ----------------------------------------------------------------------
[14:38:44.427] INFO: Expecting 41600 events.
[14:38:48.636] INFO: 41600 events read in total (3430ms).
[14:38:48.636] INFO: Test took 4564ms.
[14:38:48.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:49.091] INFO: PixTestAlive::addressDecodingTest() done
[14:38:49.091] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:38:49.091] INFO: PixTestAlive::doTest() done, duration: 13 seconds
[14:38:49.101] INFO: ######################################################################
[14:38:49.101] INFO: PixTestBBMap::doTest() Ntrig = 16, VcalS = 250 (high range)
[14:38:49.101] INFO: ######################################################################
[14:38:49.104] INFO: ---> dac: VthrComp name: calSMap ntrig: 16 dacrange: 0 .. 149 (-1/-1) hits flags = 2 (plus default)
[14:38:49.133] INFO: dacScan split into 1 runs with ntrig = 16
[14:38:49.133] INFO: run 1 of 1
[14:38:49.480] INFO: Expecting 9984000 events.
[14:39:18.552] INFO: 1208992 events read in total (28293ms).
[14:39:46.871] INFO: 2407776 events read in total (56612ms).
[14:40:15.234] INFO: 3600704 events read in total (84976ms).
[14:40:43.328] INFO: 4779936 events read in total (113069ms).
[14:41:11.429] INFO: 5960976 events read in total (141170ms).
[14:41:39.473] INFO: 7146576 events read in total (169214ms).
[14:42:07.532] INFO: 8340544 events read in total (197273ms).
[14:42:35.598] INFO: 9543280 events read in total (225339ms).
[14:42:46.159] INFO: 9984000 events read in total (235900ms).
[14:42:46.199] INFO: Test took 237067ms.
[14:42:46.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:06.563] INFO: PixTestBBMap::doTest() done, duration: 257 seconds
[14:43:06.563] INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[14:43:06.563] INFO: separation cut (per ROC): 108 114 140 111 112 119 107 117 111 102 109 101 113 136 108 110
[14:43:06.647] INFO: ######################################################################
[14:43:06.647] INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:43:06.648] INFO: ######################################################################
[14:43:06.648] INFO: ----------------------------------------------------------------------
[14:43:06.648] INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:43:06.648] INFO: ----------------------------------------------------------------------
[14:43:06.648] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (-1/-1) hits flags = 16 (plus default)
[14:43:06.663] INFO: dacScan split into 1 runs with ntrig = 50
[14:43:06.663] INFO: run 1 of 1
[14:43:07.011] INFO: Expecting 31200000 events.
[14:43:30.672] INFO: 1191650 events read in total (22875ms).
[14:43:55.328] INFO: 2360550 events read in total (47531ms).
[14:44:19.949] INFO: 3526500 events read in total (72152ms).
[14:44:44.631] INFO: 4693400 events read in total (96834ms).
[14:45:09.258] INFO: 5857000 events read in total (121461ms).
[14:45:33.934] INFO: 7025200 events read in total (146137ms).
[14:45:58.599] INFO: 8189550 events read in total (170802ms).
[14:46:23.228] INFO: 9351350 events read in total (195431ms).
[14:46:47.839] INFO: 10513500 events read in total (220042ms).
[14:47:12.459] INFO: 11675550 events read in total (244662ms).
[14:47:36.994] INFO: 12833150 events read in total (269197ms).
[14:48:01.458] INFO: 13988050 events read in total (293661ms).
[14:48:25.966] INFO: 15145500 events read in total (318169ms).
[14:48:50.359] INFO: 16289150 events read in total (342562ms).
[14:49:14.702] INFO: 17428250 events read in total (366906ms).
[14:49:39.021] INFO: 18566700 events read in total (391224ms).
[14:50:03.312] INFO: 19696800 events read in total (415515ms).
[14:50:27.517] INFO: 20828100 events read in total (439720ms).
[14:50:51.777] INFO: 21959900 events read in total (463980ms).
[14:51:15.979] INFO: 23090600 events read in total (488182ms).
[14:51:40.141] INFO: 24222500 events read in total (512344ms).
[14:52:04.304] INFO: 25349550 events read in total (536507ms).
[14:52:28.435] INFO: 26478850 events read in total (560638ms).
[14:52:52.471] INFO: 27605000 events read in total (584674ms).
[14:53:16.618] INFO: 28731450 events read in total (608821ms).
[14:53:40.772] INFO: 29861550 events read in total (632975ms).
[14:54:04.996] INFO: 31007200 events read in total (657199ms).
[14:54:09.397] INFO: 31200000 events read in total (661600ms).
[14:54:09.437] INFO: Test took 662774ms.
[14:54:09.531] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:09.731] INFO: dumping ASCII scurve output file: SCurveData
[14:54:11.242] INFO: dumping ASCII scurve output file: SCurveData
[14:54:12.689] INFO: dumping ASCII scurve output file: SCurveData
[14:54:14.128] INFO: dumping ASCII scurve output file: SCurveData
[14:54:15.582] INFO: dumping ASCII scurve output file: SCurveData
[14:54:17.067] INFO: dumping ASCII scurve output file: SCurveData
[14:54:18.507] INFO: dumping ASCII scurve output file: SCurveData
[14:54:19.001] INFO: dumping ASCII scurve output file: SCurveData
[14:54:21.452] INFO: dumping ASCII scurve output file: SCurveData
[14:54:22.910] INFO: dumping ASCII scurve output file: SCurveData
[14:54:24.427] INFO: dumping ASCII scurve output file: SCurveData
[14:54:25.883] INFO: dumping ASCII scurve output file: SCurveData
[14:54:27.380] INFO: dumping ASCII scurve output file: SCurveData
[14:54:28.827] INFO: dumping ASCII scurve output file: SCurveData
[14:54:30.231] INFO: dumping ASCII scurve output file: SCurveData
[14:54:31.701] INFO: dumping ASCII scurve output file: SCurveData
[14:54:33.187] INFO: PixTestScurves::scurves() done
[14:54:33.187] INFO: Vcal mean: 77.29 95.29 109.39 89.28 80.01 98.45 79.35 91.76 88.10 71.24 88.92 80.07 88.34 110.33 83.43 94.97
[14:54:33.187] INFO: Vcal RMS: 4.11 6.29 5.92 5.10 4.14 5.54 4.66 5.60 5.34 5.15 5.52 5.34 5.58 5.84 5.90 6.73
[14:54:33.187] INFO: PixTestScurves::fullTest() done, duration: 686 seconds
[14:54:33.267] INFO: ######################################################################
[14:54:33.267] INFO: PixTestTrim::doTest()
[14:54:33.267] INFO: ######################################################################
[14:54:33.269] INFO: ----------------------------------------------------------------------
[14:54:33.269] INFO: PixTestTrim::trimTest() ntrig = 20, vcal = 35
[14:54:33.269] INFO: ----------------------------------------------------------------------
[14:54:33.355] INFO: ---> VthrComp thr map (minimal VthrComp)
[14:54:33.355] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 20 dacrange: 0 .. 159 (-1/-1) hits flags = 16 (plus default)
[14:54:33.366] INFO: dacScan split into 1 runs with ntrig = 20
[14:54:33.366] INFO: run 1 of 1
[14:54:33.720] INFO: Expecting 13312000 events.
[14:55:04.024] INFO: 1445860 events read in total (29516ms).
[14:55:33.495] INFO: 2884260 events read in total (58987ms).
[14:56:02.985] INFO: 4318360 events read in total (88477ms).
[14:56:32.384] INFO: 5743820 events read in total (117876ms).
[14:57:01.750] INFO: 7170360 events read in total (147242ms).
[14:57:31.161] INFO: 8602320 events read in total (176653ms).
[14:58:00.088] INFO: 10036460 events read in total (205580ms).
[14:58:29.484] INFO: 11473980 events read in total (234976ms).
[14:58:58.562] INFO: 12911880 events read in total (264054ms).
[14:59:07.021] INFO: 13312000 events read in total (272513ms).
[14:59:07.062] INFO: Test took 273696ms.
[14:59:07.123] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:25.979] INFO: ROC 0 VthrComp = 81
[14:59:25.980] INFO: ROC 1 VthrComp = 93
[14:59:25.980] INFO: ROC 2 VthrComp = 107
[14:59:25.980] INFO: ROC 3 VthrComp = 95
[14:59:25.980] INFO: ROC 4 VthrComp = 88
[14:59:25.980] INFO: ROC 5 VthrComp = 98
[14:59:25.980] INFO: ROC 6 VthrComp = 83
[14:59:25.980] INFO: ROC 7 VthrComp = 95
[14:59:25.980] INFO: ROC 8 VthrComp = 92
[14:59:25.981] INFO: ROC 9 VthrComp = 76
[14:59:25.981] INFO: ROC 10 VthrComp = 92
[14:59:25.981] INFO: ROC 11 VthrComp = 80
[14:59:25.981] INFO: ROC 12 VthrComp = 93
[14:59:25.981] INFO: ROC 13 VthrComp = 106
[14:59:25.981] INFO: ROC 14 VthrComp = 87
[14:59:25.981] INFO: ROC 15 VthrComp = 93
[14:59:25.981] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[14:59:25.981] INFO: ---> dac: vcal name: TrimThr1 ntrig: 20 dacrange: 0 .. 159 (-1/-1) hits flags = 16 (plus default)
[14:59:25.993] INFO: dacScan split into 1 runs with ntrig = 20
[14:59:25.993] INFO: run 1 of 1
[14:59:26.344] INFO: Expecting 13312000 events.
[14:59:51.515] INFO: 917900 events read in total (24385ms).
[15:00:15.910] INFO: 1832600 events read in total (48780ms).
[15:00:40.152] INFO: 2745400 events read in total (73022ms).
[15:01:04.583] INFO: 3660560 events read in total (97453ms).
[15:01:29.111] INFO: 4575160 events read in total (121981ms).
[15:01:53.596] INFO: 5490760 events read in total (146466ms).
[15:02:18.053] INFO: 6407600 events read in total (170923ms).
[15:02:42.420] INFO: 7317760 events read in total (195291ms).
[15:03:06.885] INFO: 8226080 events read in total (219755ms).
[15:03:31.331] INFO: 9131880 events read in total (244201ms).
[15:03:55.745] INFO: 10037420 events read in total (268615ms).
[15:04:20.143] INFO: 10940720 events read in total (293013ms).
[15:04:44.507] INFO: 11843980 events read in total (317377ms).
[15:05:08.773] INFO: 12745880 events read in total (341643ms).
[15:05:22.606] INFO: 13312000 events read in total (355476ms).
[15:05:22.663] INFO: Test took 356670ms.
[15:05:22.830] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:46.845] INFO: roc 0 with ID = 0 has maximal Vcal 56.1034 for pixel 51/16 mean/min/max = 44.4966/32.5743/56.4188
[15:05:46.845] INFO: roc 1 with ID = 1 has maximal Vcal 60.0774 for pixel 41/0 mean/min/max = 45.7997/31.4474/60.1519
[15:05:46.845] INFO: roc 2 with ID = 2 has maximal Vcal 64.7927 for pixel 35/79 mean/min/max = 48.7775/32.5622/64.9929
[15:05:46.846] INFO: roc 3 with ID = 3 has maximal Vcal 56.518 for pixel 11/79 mean/min/max = 44.4668/32.06/56.8735
[15:05:46.846] INFO: roc 4 with ID = 4 has maximal Vcal 56.6473 for pixel 24/1 mean/min/max = 44.8378/32.949/56.7267
[15:05:46.846] INFO: roc 5 with ID = 5 has maximal Vcal 59.6595 for pixel 0/78 mean/min/max = 45.9246/32.1082/59.7409
[15:05:46.846] INFO: roc 6 with ID = 6 has maximal Vcal 58.9112 for pixel 13/10 mean/min/max = 45.3868/31.7553/59.0183
[15:05:46.847] INFO: roc 7 with ID = 7 has maximal Vcal 60.0327 for pixel 17/71 mean/min/max = 46.2984/32.2472/60.3497
[15:05:46.847] INFO: roc 8 with ID = 8 has maximal Vcal 58.2861 for pixel 12/79 mean/min/max = 45.091/31.853/58.329
[15:05:46.847] INFO: roc 9 with ID = 9 has maximal Vcal 58.0459 for pixel 20/78 mean/min/max = 46.0384/33.803/58.2737
[15:05:46.848] INFO: roc 10 with ID = 10 has maximal Vcal 58.7032 for pixel 18/1 mean/min/max = 45.9077/32.9961/58.8194
[15:05:46.848] INFO: roc 11 with ID = 11 has maximal Vcal 59.9307 for pixel 11/77 mean/min/max = 46.2168/32.1521/60.2815
[15:05:46.848] INFO: roc 12 with ID = 12 has maximal Vcal 58.0766 for pixel 22/79 mean/min/max = 45.4574/32.4098/58.5051
[15:05:46.848] INFO: roc 13 with ID = 13 has maximal Vcal 64.9531 for pixel 37/8 mean/min/max = 49.251/33.5161/64.9859
[15:05:46.849] INFO: roc 14 with ID = 14 has maximal Vcal 61.2051 for pixel 24/69 mean/min/max = 46.33/31.2088/61.4512
[15:05:46.849] INFO: roc 15 with ID = 15 has maximal Vcal 63.9619 for pixel 9/70 mean/min/max = 47.3857/30.7963/63.9751
[15:05:46.849] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:05:46.981] INFO: Expecting 1029120 events.
[15:06:06.168] INFO: 1029120 events read in total (18408ms).
[15:06:06.174] INFO: Expecting 1029120 events.
[15:06:25.156] INFO: 1029120 events read in total (18351ms).
[15:06:25.163] INFO: Expecting 1029120 events.
[15:06:44.274] INFO: 1029120 events read in total (18478ms).
[15:06:44.284] INFO: Expecting 1029120 events.
[15:07:03.289] INFO: 1029120 events read in total (18391ms).
[15:07:03.305] INFO: Expecting 1029120 events.
[15:07:22.441] INFO: 1029120 events read in total (18515ms).
[15:07:22.460] INFO: Expecting 1029120 events.
[15:07:41.427] INFO: 1029120 events read in total (18357ms).
[15:07:41.443] INFO: Expecting 1029120 events.
[15:08:00.218] INFO: 1029120 events read in total (18152ms).
[15:08:00.236] INFO: Expecting 1029120 events.
[15:08:19.142] INFO: 1029120 events read in total (18286ms).
[15:08:19.163] INFO: Expecting 1029120 events.
[15:08:37.253] INFO: 1029120 events read in total (17475ms).
[15:08:37.276] INFO: Expecting 1029120 events.
[15:08:56.342] INFO: 1029120 events read in total (18448ms).
[15:08:56.367] INFO: Expecting 1029120 events.
[15:09:15.308] INFO: 1029120 events read in total (18340ms).
[15:09:15.335] INFO: Expecting 1029120 events.
[15:09:34.273] INFO: 1029120 events read in total (18331ms).
[15:09:34.308] INFO: Expecting 1029120 events.
[15:09:53.363] INFO: 1029120 events read in total (18457ms).
[15:09:53.400] INFO: Expecting 1029120 events.
[15:10:12.600] INFO: 1029120 events read in total (18607ms).
[15:10:12.633] INFO: Expecting 1029120 events.
[15:10:31.823] INFO: 1029120 events read in total (18601ms).
[15:10:31.861] INFO: Expecting 1029120 events.
[15:10:50.863] INFO: 1029120 events read in total (18419ms).
[15:10:50.901] INFO: Test took 304052ms.
[15:10:51.899] INFO: ---> dac: vcal name: TrimThr2 ntrig: 20 dacrange: 0 .. 199 (-1/-1) hits flags = 16 (plus default)
[15:10:51.909] INFO: dacScan split into 1 runs with ntrig = 20
[15:10:51.909] INFO: run 1 of 1
[15:10:52.260] INFO: Expecting 16640000 events.
[15:11:16.920] INFO: 842120 events read in total (23881ms).
[15:11:40.743] INFO: 1681460 events read in total (47704ms).
[15:12:04.474] INFO: 2520660 events read in total (71435ms).
[15:12:28.288] INFO: 3359480 events read in total (95249ms).
[15:12:52.129] INFO: 4199920 events read in total (119090ms).
[15:13:15.938] INFO: 5039100 events read in total (142899ms).
[15:13:39.688] INFO: 5879720 events read in total (166649ms).
[15:14:03.456] INFO: 6719640 events read in total (190417ms).
[15:14:27.238] INFO: 7559620 events read in total (214199ms).
[15:14:51.046] INFO: 8399740 events read in total (238007ms).
[15:15:14.816] INFO: 9234060 events read in total (261777ms).
[15:15:38.521] INFO: 10068420 events read in total (285482ms).
[15:16:02.226] INFO: 10900080 events read in total (309187ms).
[15:16:25.916] INFO: 11730840 events read in total (332877ms).
[15:16:49.776] INFO: 12562260 events read in total (356737ms).
[15:17:13.614] INFO: 13392740 events read in total (380575ms).
[15:17:37.406] INFO: 14222500 events read in total (404367ms).
[15:18:01.199] INFO: 15051800 events read in total (428160ms).
[15:18:25.006] INFO: 15881680 events read in total (451967ms).
[15:18:46.763] INFO: 16640000 events read in total (473724ms).
[15:18:46.850] INFO: Test took 474940ms.
[15:18:47.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:14.098] INFO: ---> TrimStepCorr4 extremal thresholds: 0.193518 .. 255.000000
[15:19:14.169] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 20 dacrange: 0 .. 255 (-1/-1) hits flags = 16 (plus default)
[15:19:14.179] INFO: dacScan split into 1 runs with ntrig = 20
[15:19:14.179] INFO: run 1 of 1
[15:19:14.529] INFO: Expecting 21299200 events.
[15:19:39.127] INFO: 825960 events read in total (23798ms).
[15:20:02.885] INFO: 1652160 events read in total (47556ms).
[15:20:26.668] INFO: 2477860 events read in total (71339ms).
[15:20:50.433] INFO: 3304880 events read in total (95104ms).
[15:21:14.178] INFO: 4131200 events read in total (118849ms).
[15:21:37.914] INFO: 4957520 events read in total (142585ms).
[15:22:01.664] INFO: 5783380 events read in total (166335ms).
[15:22:25.418] INFO: 6609800 events read in total (190089ms).
[15:22:49.156] INFO: 7436800 events read in total (213827ms).
[15:23:12.944] INFO: 8263140 events read in total (237615ms).
[15:23:36.727] INFO: 9089620 events read in total (261398ms).
[15:24:00.491] INFO: 9916000 events read in total (285162ms).
[15:24:24.247] INFO: 10742740 events read in total (308918ms).
[15:24:47.979] INFO: 11568520 events read in total (332650ms).
[15:25:11.699] INFO: 12394420 events read in total (356370ms).
[15:25:35.441] INFO: 13219720 events read in total (380112ms).
[15:25:59.191] INFO: 14045560 events read in total (403862ms).
[15:26:22.945] INFO: 14870900 events read in total (427616ms).
[15:26:46.751] INFO: 15695900 events read in total (451422ms).
[15:27:10.454] INFO: 16520800 events read in total (475125ms).
[15:27:34.108] INFO: 17345500 events read in total (498779ms).
[15:27:57.746] INFO: 18169920 events read in total (522417ms).
[15:28:21.439] INFO: 18994280 events read in total (546110ms).
[15:28:45.139] INFO: 19818640 events read in total (569810ms).
[15:29:08.841] INFO: 20643000 events read in total (593512ms).
[15:29:27.845] INFO: 21299200 events read in total (612516ms).
[15:29:27.949] INFO: Test took 613771ms.
[15:29:28.263] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:56.870] INFO: ---> TrimStepCorr2 extremal thresholds: 15.837914 .. 47.263064
[15:29:56.939] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 20 dacrange: 5 .. 57 (-1/-1) hits flags = 16 (plus default)
[15:29:56.948] INFO: dacScan split into 1 runs with ntrig = 20
[15:29:56.948] INFO: run 1 of 1
[15:29:57.298] INFO: Expecting 4409600 events.
[15:30:24.922] INFO: 1140240 events read in total (26836ms).
[15:30:51.804] INFO: 2281260 events read in total (53718ms).
[15:31:18.703] INFO: 3420620 events read in total (80617ms).
[15:31:42.113] INFO: 4409600 events read in total (104027ms).
[15:31:42.134] INFO: Test took 105185ms.
[15:31:42.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:55.773] INFO: ---> TrimStepCorr1a extremal thresholds: 1.470248 .. 44.662464
[15:31:55.842] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 20 dacrange: 1 .. 54 (-1/-1) hits flags = 16 (plus default)
[15:31:55.852] INFO: dacScan split into 1 runs with ntrig = 20
[15:31:55.852] INFO: run 1 of 1
[15:31:56.202] INFO: Expecting 4492800 events.
[15:32:24.386] INFO: 1206140 events read in total (27406ms).
[15:32:51.798] INFO: 2412920 events read in total (54818ms).
[15:33:19.318] INFO: 3617860 events read in total (82338ms).
[15:33:39.407] INFO: 4492800 events read in total (102427ms).
[15:33:39.430] INFO: Test took 103578ms.
[15:33:39.468] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:52.443] INFO: ---> TrimStepCorr1b extremal thresholds: 1.470248 .. 44.662464
[15:33:52.512] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 20 dacrange: 1 .. 54 (-1/-1) hits flags = 16 (plus default)
[15:33:52.522] INFO: dacScan split into 1 runs with ntrig = 20
[15:33:52.522] INFO: run 1 of 1
[15:33:52.871] INFO: Expecting 4492800 events.
[15:34:21.127] INFO: 1207340 events read in total (27477ms).
[15:34:48.606] INFO: 2414800 events read in total (54956ms).
[15:35:16.105] INFO: 3621900 events read in total (82455ms).
[15:35:36.072] INFO: 4492800 events read in total (102422ms).
[15:35:36.096] INFO: Test took 103575ms.
[15:35:36.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:49.239] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[15:35:49.239] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 20 dacrange: 15 .. 55 (-1/-1) hits flags = 16 (plus default)
[15:35:49.253] INFO: dacScan split into 1 runs with ntrig = 20
[15:35:49.253] INFO: run 1 of 1
[15:35:49.605] INFO: Expecting 3411200 events.
[15:36:16.913] INFO: 1074900 events read in total (26529ms).
[15:36:43.444] INFO: 2149220 events read in total (53060ms).
[15:37:09.933] INFO: 3222520 events read in total (79550ms).
[15:37:14.982] INFO: 3411200 events read in total (84598ms).
[15:37:14.997] INFO: Test took 85744ms.
[15:37:15.040] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:28.073] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C0.dat
[15:37:28.073] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C1.dat
[15:37:28.074] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C2.dat
[15:37:28.074] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C3.dat
[15:37:28.074] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C4.dat
[15:37:28.074] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C5.dat
[15:37:28.074] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C6.dat
[15:37:28.075] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C7.dat
[15:37:28.075] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C8.dat
[15:37:28.075] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C9.dat
[15:37:28.075] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C10.dat
[15:37:28.075] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C11.dat
[15:37:28.076] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C12.dat
[15:37:28.076] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C13.dat
[15:37:28.076] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C14.dat
[15:37:28.076] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C15.dat
[15:37:28.076] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C0.dat
[15:37:28.086] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C1.dat
[15:37:28.094] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C2.dat
[15:37:28.100] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C3.dat
[15:37:28.106] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C4.dat
[15:37:28.112] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C5.dat
[15:37:28.118] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C6.dat
[15:37:28.123] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C7.dat
[15:37:28.129] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C8.dat
[15:37:28.135] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C9.dat
[15:37:28.141] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C10.dat
[15:37:28.147] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C11.dat
[15:37:28.153] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C12.dat
[15:37:28.159] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C13.dat
[15:37:28.165] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C14.dat
[15:37:28.171] INFO: write trim parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/trimParameters35_C15.dat
[15:37:28.177] INFO: PixTestTrim::trimTest() done
[15:37:28.177] INFO: vtrim: 80 82 108 83 84 86 92 93 82 90 91 88 84 116 102 97
[15:37:28.177] INFO: vthrcomp: 81 93 107 95 88 98 83 95 92 76 92 80 93 106 87 93
[15:37:28.177] INFO: vcal mean: 35.02 35.11 34.99 34.98 34.98 34.99 35.02 34.98 35.00 35.02 34.99 34.99 35.03 34.98 34.96 34.97
[15:37:28.177] INFO: vcal RMS: 0.66 0.78 0.79 0.71 0.63 0.88 0.77 0.76 0.67 0.67 0.75 0.74 0.72 0.84 0.75 0.84
[15:37:28.177] INFO: bits mean: 8.89 9.07 8.36 9.25 9.21 9.04 9.61 9.19 9.12 8.82 9.20 8.99 8.36 8.87 9.46 9.34
[15:37:28.177] INFO: bits RMS: 2.93 2.85 2.83 2.86 2.70 2.82 2.69 2.76 2.90 2.69 2.68 2.85 3.06 2.49 2.77 2.75
[15:37:28.185] INFO: ----------------------------------------------------------------------
[15:37:28.185] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[15:37:28.185] INFO: ----------------------------------------------------------------------
[15:37:28.188] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (-1/-1) hits flags = 16 (plus default)
[15:37:28.204] INFO: dacScan split into 1 runs with ntrig = 10
[15:37:28.204] INFO: run 1 of 1
[15:37:28.555] INFO: Expecting 8320000 events.
[15:37:59.610] INFO: 1153000 events read in total (30276ms).
[15:38:29.318] INFO: 2295760 events read in total (59984ms).
[15:38:59.479] INFO: 3433480 events read in total (90145ms).
[15:39:29.578] INFO: 4561180 events read in total (120244ms).
[15:39:59.559] INFO: 5677950 events read in total (150225ms).
[15:40:29.445] INFO: 6791890 events read in total (180111ms).
[15:40:59.204] INFO: 7905310 events read in total (209870ms).
[15:41:10.519] INFO: 8320000 events read in total (221185ms).
[15:41:10.571] INFO: Test took 222367ms.
[15:41:10.696] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:37.472] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 182 (-1/-1) hits flags = 16 (plus default)
[15:41:37.489] INFO: dacScan split into 1 runs with ntrig = 10
[15:41:37.489] INFO: run 1 of 1
[15:41:37.841] INFO: Expecting 7612800 events.
[15:42:08.991] INFO: 1150930 events read in total (30372ms).
[15:42:39.315] INFO: 2293070 events read in total (60696ms).
[15:43:09.489] INFO: 3428960 events read in total (90870ms).
[15:43:39.607] INFO: 4552400 events read in total (120988ms).
[15:44:09.472] INFO: 5664970 events read in total (150853ms).
[15:44:39.292] INFO: 6776380 events read in total (180673ms).
[15:45:01.709] INFO: 7612800 events read in total (203090ms).
[15:45:01.771] INFO: Test took 204282ms.
[15:45:01.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:27.309] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 169 (-1/-1) hits flags = 16 (plus default)
[15:45:27.319] INFO: dacScan split into 1 runs with ntrig = 10
[15:45:27.319] INFO: run 1 of 1
[15:45:27.669] INFO: Expecting 7072000 events.
[15:45:59.529] INFO: 1196760 events read in total (31081ms).
[15:46:30.475] INFO: 2383040 events read in total (62027ms).
[15:47:01.259] INFO: 3560170 events read in total (92811ms).
[15:47:31.830] INFO: 4717460 events read in total (123382ms).
[15:48:02.339] INFO: 5871080 events read in total (153892ms).
[15:48:32.701] INFO: 7026090 events read in total (184253ms).
[15:48:34.315] INFO: 7072000 events read in total (185867ms).
[15:48:34.361] INFO: Test took 187043ms.
[15:48:34.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:58.613] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 169 (-1/-1) hits flags = 16 (plus default)
[15:48:58.623] INFO: dacScan split into 1 runs with ntrig = 10
[15:48:58.623] INFO: run 1 of 1
[15:48:58.974] INFO: Expecting 7072000 events.
[15:49:30.660] INFO: 1195040 events read in total (30907ms).
[15:50:01.543] INFO: 2379830 events read in total (61790ms).
[15:50:32.293] INFO: 3555800 events read in total (92540ms).
[15:51:02.735] INFO: 4711560 events read in total (122982ms).
[15:51:33.154] INFO: 5863230 events read in total (153401ms).
[15:52:03.597] INFO: 7016940 events read in total (183844ms).
[15:52:05.455] INFO: 7072000 events read in total (185702ms).
[15:52:05.502] INFO: Test took 186879ms.
[15:52:05.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:29.910] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 167 (-1/-1) hits flags = 16 (plus default)
[15:52:29.920] INFO: dacScan split into 1 runs with ntrig = 10
[15:52:29.920] INFO: run 1 of 1
[15:52:30.270] INFO: Expecting 6988800 events.
[15:53:02.220] INFO: 1202500 events read in total (31172ms).
[15:53:33.370] INFO: 2393240 events read in total (62322ms).
[15:54:04.237] INFO: 3573520 events read in total (93190ms).
[15:54:34.829] INFO: 4735860 events read in total (123781ms).
[15:55:05.318] INFO: 5892420 events read in total (154270ms).
[15:55:34.108] INFO: 6988800 events read in total (183060ms).
[15:55:34.155] INFO: Test took 184235ms.
[15:55:34.252] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:58.414] INFO: PixTestTrim::trimBitTest() done
[15:55:58.415] INFO: PixTestTrim::doTest() done, duration: 3685 seconds
[15:55:59.081] INFO: ######################################################################
[15:55:59.081] INFO: PixTestPhOptimization::doTest() Ntrig = 16
[15:55:59.081] INFO: ######################################################################
[15:55:59.436] INFO: Expecting 41600 events.
[15:56:03.641] INFO: 41600 events read in total (3416ms).
[15:56:03.642] INFO: Test took 4559ms.
[15:56:03.648] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:04.417] INFO: Expecting 41600 events.
[15:56:08.655] INFO: 41600 events read in total (3459ms).
[15:56:08.656] INFO: Test took 4590ms.
[15:56:08.662] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:09.159] INFO: Expecting 41600 events.
[15:56:13.395] INFO: 41600 events read in total (3457ms).
[15:56:13.395] INFO: Test took 4623ms.
[15:56:13.402] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:13.409] INFO: The DUT currently contains the following objects:
[15:56:13.409] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:13.409] INFO: TBM Core alpha (0): 7 registers set
[15:56:13.409] INFO: TBM Core beta (1): 7 registers set
[15:56:13.409] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:13.409] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.409] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.409] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.409] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.410] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:13.896] INFO: Expecting 2560 events.
[15:56:14.924] INFO: 2560 events read in total (249ms).
[15:56:14.925] INFO: Test took 1515ms.
[15:56:14.925] INFO: The DUT currently contains the following objects:
[15:56:14.925] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:14.925] INFO: TBM Core alpha (0): 7 registers set
[15:56:14.925] INFO: TBM Core beta (1): 7 registers set
[15:56:14.925] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:14.925] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.925] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.925] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.925] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.925] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:14.926] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:15.496] INFO: Expecting 2560 events.
[15:56:16.524] INFO: 2560 events read in total (249ms).
[15:56:16.524] INFO: Test took 1598ms.
[15:56:16.525] INFO: The DUT currently contains the following objects:
[15:56:16.525] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:16.525] INFO: TBM Core alpha (0): 7 registers set
[15:56:16.525] INFO: TBM Core beta (1): 7 registers set
[15:56:16.525] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:16.525] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:16.525] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:17.096] INFO: Expecting 2560 events.
[15:56:18.123] INFO: 2560 events read in total (249ms).
[15:56:18.123] INFO: Test took 1598ms.
[15:56:18.124] INFO: The DUT currently contains the following objects:
[15:56:18.124] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:18.124] INFO: TBM Core alpha (0): 7 registers set
[15:56:18.124] INFO: TBM Core beta (1): 7 registers set
[15:56:18.124] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:18.124] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.124] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:18.695] INFO: Expecting 2560 events.
[15:56:19.723] INFO: 2560 events read in total (250ms).
[15:56:19.723] INFO: Test took 1599ms.
[15:56:19.723] INFO: The DUT currently contains the following objects:
[15:56:19.723] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:19.723] INFO: TBM Core alpha (0): 7 registers set
[15:56:19.723] INFO: TBM Core beta (1): 7 registers set
[15:56:19.723] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:19.723] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.723] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:19.724] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:20.295] INFO: Expecting 2560 events.
[15:56:21.323] INFO: 2560 events read in total (250ms).
[15:56:21.323] INFO: Test took 1599ms.
[15:56:21.323] INFO: The DUT currently contains the following objects:
[15:56:21.323] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:21.323] INFO: TBM Core alpha (0): 7 registers set
[15:56:21.323] INFO: TBM Core beta (1): 7 registers set
[15:56:21.323] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:21.323] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.323] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.323] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.323] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.324] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:21.894] INFO: Expecting 2560 events.
[15:56:22.921] INFO: 2560 events read in total (248ms).
[15:56:22.922] INFO: Test took 1598ms.
[15:56:22.922] INFO: The DUT currently contains the following objects:
[15:56:22.922] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:22.922] INFO: TBM Core alpha (0): 7 registers set
[15:56:22.922] INFO: TBM Core beta (1): 7 registers set
[15:56:22.922] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:22.922] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.922] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.923] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.923] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.923] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:22.923] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:23.494] INFO: Expecting 2560 events.
[15:56:24.521] INFO: 2560 events read in total (248ms).
[15:56:24.522] INFO: Test took 1599ms.
[15:56:24.522] INFO: The DUT currently contains the following objects:
[15:56:24.522] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:24.522] INFO: TBM Core alpha (0): 7 registers set
[15:56:24.522] INFO: TBM Core beta (1): 7 registers set
[15:56:24.522] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:24.522] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.522] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.522] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.522] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.522] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.522] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:24.523] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:25.094] INFO: Expecting 2560 events.
[15:56:26.121] INFO: 2560 events read in total (249ms).
[15:56:26.121] INFO: Test took 1598ms.
[15:56:26.122] INFO: The DUT currently contains the following objects:
[15:56:26.122] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:26.122] INFO: TBM Core alpha (0): 7 registers set
[15:56:26.122] INFO: TBM Core beta (1): 7 registers set
[15:56:26.122] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:26.122] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.122] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.122] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.122] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.122] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.122] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.122] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.123] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.123] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.123] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.123] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.123] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.123] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.123] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.123] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.123] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:26.694] INFO: Expecting 2560 events.
[15:56:27.722] INFO: 2560 events read in total (250ms).
[15:56:27.722] INFO: Test took 1599ms.
[15:56:27.722] INFO: The DUT currently contains the following objects:
[15:56:27.723] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:27.723] INFO: TBM Core alpha (0): 7 registers set
[15:56:27.723] INFO: TBM Core beta (1): 7 registers set
[15:56:27.723] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:27.723] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:27.723] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:28.294] INFO: Expecting 2560 events.
[15:56:29.322] INFO: 2560 events read in total (249ms).
[15:56:29.323] INFO: Test took 1600ms.
[15:56:29.323] INFO: The DUT currently contains the following objects:
[15:56:29.323] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:29.323] INFO: TBM Core alpha (0): 7 registers set
[15:56:29.323] INFO: TBM Core beta (1): 7 registers set
[15:56:29.323] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:29.323] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.323] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.323] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.323] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.323] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.323] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.323] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.323] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.324] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.324] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.324] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.324] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.324] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.324] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.324] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.324] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:29.895] INFO: Expecting 2560 events.
[15:56:30.923] INFO: 2560 events read in total (250ms).
[15:56:30.923] INFO: Test took 1599ms.
[15:56:30.924] INFO: The DUT currently contains the following objects:
[15:56:30.924] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:30.924] INFO: TBM Core alpha (0): 7 registers set
[15:56:30.924] INFO: TBM Core beta (1): 7 registers set
[15:56:30.924] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:30.924] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.924] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:30.925] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:31.495] INFO: Expecting 2560 events.
[15:56:32.524] INFO: 2560 events read in total (250ms).
[15:56:32.524] INFO: Test took 1599ms.
[15:56:32.525] INFO: The DUT currently contains the following objects:
[15:56:32.525] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:32.525] INFO: TBM Core alpha (0): 7 registers set
[15:56:32.525] INFO: TBM Core beta (1): 7 registers set
[15:56:32.525] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:32.525] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.525] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.526] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.526] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.526] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:32.526] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:33.096] INFO: Expecting 2560 events.
[15:56:34.125] INFO: 2560 events read in total (250ms).
[15:56:34.125] INFO: Test took 1599ms.
[15:56:34.125] INFO: The DUT currently contains the following objects:
[15:56:34.125] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:34.125] INFO: TBM Core alpha (0): 7 registers set
[15:56:34.125] INFO: TBM Core beta (1): 7 registers set
[15:56:34.125] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:34.126] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.126] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:34.697] INFO: Expecting 2560 events.
[15:56:35.725] INFO: 2560 events read in total (250ms).
[15:56:35.725] INFO: Test took 1599ms.
[15:56:35.726] INFO: The DUT currently contains the following objects:
[15:56:35.726] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:35.726] INFO: TBM Core alpha (0): 7 registers set
[15:56:35.726] INFO: TBM Core beta (1): 7 registers set
[15:56:35.726] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:35.726] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.726] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.727] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.727] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.727] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.727] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:35.727] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:36.297] INFO: Expecting 2560 events.
[15:56:37.325] INFO: 2560 events read in total (249ms).
[15:56:37.325] INFO: Test took 1598ms.
[15:56:37.326] INFO: The DUT currently contains the following objects:
[15:56:37.326] INFO: 2 TBM Cores tbm08c (2 ON)
[15:56:37.326] INFO: TBM Core alpha (0): 7 registers set
[15:56:37.326] INFO: TBM Core beta (1): 7 registers set
[15:56:37.326] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:56:37.326] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.326] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:56:37.897] INFO: Expecting 2560 events.
[15:56:38.925] INFO: 2560 events read in total (249ms).
[15:56:38.925] INFO: Test took 1599ms.
[15:56:38.929] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:39.499] INFO: Expecting 655360 events.
[15:56:52.914] INFO: 655360 events read in total (12636ms).
[15:56:52.925] INFO: Expecting 655360 events.
[15:57:06.177] INFO: 655360 events read in total (12671ms).
[15:57:06.191] INFO: Expecting 655360 events.
[15:57:19.412] INFO: 655360 events read in total (12642ms).
[15:57:19.431] INFO: Expecting 655360 events.
[15:57:32.680] INFO: 655360 events read in total (12675ms).
[15:57:32.702] INFO: Expecting 655360 events.
[15:57:45.915] INFO: 655360 events read in total (12645ms).
[15:57:45.942] INFO: Expecting 655360 events.
[15:57:59.172] INFO: 655360 events read in total (12673ms).
[15:57:59.206] INFO: Expecting 655360 events.
[15:58:12.413] INFO: 655360 events read in total (12650ms).
[15:58:12.453] INFO: Expecting 655360 events.
[15:58:25.636] INFO: 655360 events read in total (12637ms).
[15:58:25.676] INFO: Expecting 655360 events.
[15:58:38.922] INFO: 655360 events read in total (12696ms).
[15:58:38.967] INFO: Expecting 655360 events.
[15:58:52.192] INFO: 655360 events read in total (12682ms).
[15:58:52.240] INFO: Expecting 655360 events.
[15:59:05.444] INFO: 655360 events read in total (12662ms).
[15:59:05.495] INFO: Expecting 655360 events.
[15:59:18.722] INFO: 655360 events read in total (12685ms).
[15:59:18.780] INFO: Expecting 655360 events.
[15:59:31.974] INFO: 655360 events read in total (12667ms).
[15:59:32.040] INFO: Expecting 655360 events.
[15:59:45.269] INFO: 655360 events read in total (12702ms).
[15:59:45.334] INFO: Expecting 655360 events.
[15:59:58.503] INFO: 655360 events read in total (12642ms).
[15:59:58.572] INFO: Expecting 655360 events.
[16:00:11.790] INFO: 655360 events read in total (12691ms).
[16:00:11.862] INFO: Test took 212933ms.
[16:00:11.960] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:00:12.329] INFO: Expecting 655360 events.
[16:00:25.720] INFO: 655360 events read in total (12612ms).
[16:00:25.730] INFO: Expecting 655360 events.
[16:00:38.961] INFO: 655360 events read in total (12645ms).
[16:00:38.976] INFO: Expecting 655360 events.
[16:00:52.092] INFO: 655360 events read in total (12538ms).
[16:00:52.110] INFO: Expecting 655360 events.
[16:01:05.368] INFO: 655360 events read in total (12679ms).
[16:01:05.391] INFO: Expecting 655360 events.
[16:01:18.590] INFO: 655360 events read in total (12636ms).
[16:01:18.618] INFO: Expecting 655360 events.
[16:01:31.794] INFO: 655360 events read in total (12622ms).
[16:01:31.826] INFO: Expecting 655360 events.
[16:01:44.993] INFO: 655360 events read in total (12607ms).
[16:01:45.032] INFO: Expecting 655360 events.
[16:01:58.162] INFO: 655360 events read in total (12578ms).
[16:01:58.202] INFO: Expecting 655360 events.
[16:02:11.390] INFO: 655360 events read in total (12625ms).
[16:02:11.441] INFO: Expecting 655360 events.
[16:02:24.639] INFO: 655360 events read in total (12655ms).
[16:02:24.688] INFO: Expecting 655360 events.
[16:02:37.906] INFO: 655360 events read in total (12676ms).
[16:02:37.968] INFO: Expecting 655360 events.
[16:02:51.133] INFO: 655360 events read in total (12633ms).
[16:02:51.193] INFO: Expecting 655360 events.
[16:03:04.331] INFO: 655360 events read in total (12607ms).
[16:03:04.392] INFO: Expecting 655360 events.
[16:03:17.577] INFO: 655360 events read in total (12652ms).
[16:03:17.644] INFO: Expecting 655360 events.
[16:03:30.831] INFO: 655360 events read in total (12660ms).
[16:03:30.900] INFO: Expecting 655360 events.
[16:03:44.041] INFO: 655360 events read in total (12614ms).
[16:03:44.117] INFO: Test took 212157ms.
[16:03:44.314] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.320] INFO: safety margin for low PH: adding 1, margin is now 21
[16:03:44.326] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.333] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.339] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.346] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.353] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.359] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.365] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.372] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.378] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.385] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.393] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.401] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.410] INFO: safety margin for low PH: adding 1, margin is now 21
[16:03:44.418] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.425] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.431] INFO: safety margin for low PH: adding 0, margin is now 20
[16:03:44.438] INFO: safety margin for low PH: adding 1, margin is now 21
[16:03:44.484] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C0.dat
[16:03:44.484] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C1.dat
[16:03:44.484] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C2.dat
[16:03:44.484] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C3.dat
[16:03:44.484] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C4.dat
[16:03:44.485] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C5.dat
[16:03:44.485] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C6.dat
[16:03:44.485] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C7.dat
[16:03:44.485] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C8.dat
[16:03:44.485] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C9.dat
[16:03:44.486] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C10.dat
[16:03:44.486] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C11.dat
[16:03:44.486] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C12.dat
[16:03:44.486] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C13.dat
[16:03:44.486] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C14.dat
[16:03:44.487] INFO: write dac parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/dacParameters35_C15.dat
[16:03:44.848] INFO: Expecting 41600 events.
[16:03:49.084] INFO: 41600 events read in total (3458ms).
[16:03:49.085] INFO: Test took 4595ms.
[16:03:49.832] INFO: Expecting 41600 events.
[16:03:54.037] INFO: 41600 events read in total (3426ms).
[16:03:54.038] INFO: Test took 4562ms.
[16:03:54.782] INFO: Expecting 41600 events.
[16:03:59.021] INFO: 41600 events read in total (3460ms).
[16:03:59.022] INFO: Test took 4595ms.
[16:03:59.407] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:59.539] INFO: Expecting 2560 events.
[16:04:00.566] INFO: 2560 events read in total (248ms).
[16:04:00.566] INFO: Test took 1159ms.
[16:04:00.568] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:01.140] INFO: Expecting 2560 events.
[16:04:02.168] INFO: 2560 events read in total (250ms).
[16:04:02.168] INFO: Test took 1600ms.
[16:04:02.171] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:02.741] INFO: Expecting 2560 events.
[16:04:03.769] INFO: 2560 events read in total (249ms).
[16:04:03.769] INFO: Test took 1599ms.
[16:04:03.772] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:04.342] INFO: Expecting 2560 events.
[16:04:05.370] INFO: 2560 events read in total (249ms).
[16:04:05.371] INFO: Test took 1599ms.
[16:04:05.373] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:05.944] INFO: Expecting 2560 events.
[16:04:06.971] INFO: 2560 events read in total (249ms).
[16:04:06.972] INFO: Test took 1599ms.
[16:04:06.974] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:07.545] INFO: Expecting 2560 events.
[16:04:08.573] INFO: 2560 events read in total (250ms).
[16:04:08.573] INFO: Test took 1599ms.
[16:04:08.576] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:09.146] INFO: Expecting 2560 events.
[16:04:10.174] INFO: 2560 events read in total (249ms).
[16:04:10.175] INFO: Test took 1599ms.
[16:04:10.177] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:10.748] INFO: Expecting 2560 events.
[16:04:11.775] INFO: 2560 events read in total (249ms).
[16:04:11.776] INFO: Test took 1599ms.
[16:04:11.778] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:12.348] INFO: Expecting 2560 events.
[16:04:13.376] INFO: 2560 events read in total (249ms).
[16:04:13.376] INFO: Test took 1598ms.
[16:04:13.379] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:13.949] INFO: Expecting 2560 events.
[16:04:14.977] INFO: 2560 events read in total (249ms).
[16:04:14.977] INFO: Test took 1598ms.
[16:04:14.980] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:15.550] INFO: Expecting 2560 events.
[16:04:16.578] INFO: 2560 events read in total (249ms).
[16:04:16.578] INFO: Test took 1598ms.
[16:04:16.581] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:17.151] INFO: Expecting 2560 events.
[16:04:18.179] INFO: 2560 events read in total (249ms).
[16:04:18.179] INFO: Test took 1599ms.
[16:04:18.182] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:18.752] INFO: Expecting 2560 events.
[16:04:19.780] INFO: 2560 events read in total (250ms).
[16:04:19.780] INFO: Test took 1599ms.
[16:04:19.782] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:20.353] INFO: Expecting 2560 events.
[16:04:21.380] INFO: 2560 events read in total (249ms).
[16:04:21.381] INFO: Test took 1599ms.
[16:04:21.383] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:21.954] INFO: Expecting 2560 events.
[16:04:22.981] INFO: 2560 events read in total (249ms).
[16:04:22.982] INFO: Test took 1599ms.
[16:04:22.984] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:23.555] INFO: Expecting 2560 events.
[16:04:24.582] INFO: 2560 events read in total (249ms).
[16:04:24.583] INFO: Test took 1599ms.
[16:04:24.585] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:25.155] INFO: Expecting 2560 events.
[16:04:26.183] INFO: 2560 events read in total (249ms).
[16:04:26.184] INFO: Test took 1599ms.
[16:04:26.186] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:26.757] INFO: Expecting 2560 events.
[16:04:27.785] INFO: 2560 events read in total (250ms).
[16:04:27.785] INFO: Test took 1599ms.
[16:04:27.788] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:28.358] INFO: Expecting 2560 events.
[16:04:29.386] INFO: 2560 events read in total (249ms).
[16:04:29.387] INFO: Test took 1599ms.
[16:04:29.390] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:29.960] INFO: Expecting 2560 events.
[16:04:30.988] INFO: 2560 events read in total (250ms).
[16:04:30.989] INFO: Test took 1600ms.
[16:04:30.991] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:31.562] INFO: Expecting 2560 events.
[16:04:32.590] INFO: 2560 events read in total (250ms).
[16:04:32.591] INFO: Test took 1600ms.
[16:04:32.594] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:33.164] INFO: Expecting 2560 events.
[16:04:34.192] INFO: 2560 events read in total (250ms).
[16:04:34.192] INFO: Test took 1599ms.
[16:04:34.195] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:34.765] INFO: Expecting 2560 events.
[16:04:35.794] INFO: 2560 events read in total (250ms).
[16:04:35.794] INFO: Test took 1599ms.
[16:04:35.797] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:36.368] INFO: Expecting 2560 events.
[16:04:37.396] INFO: 2560 events read in total (250ms).
[16:04:37.396] INFO: Test took 1599ms.
[16:04:37.399] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:37.969] INFO: Expecting 2560 events.
[16:04:38.998] INFO: 2560 events read in total (250ms).
[16:04:38.998] INFO: Test took 1599ms.
[16:04:38.001] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:39.571] INFO: Expecting 2560 events.
[16:04:40.600] INFO: 2560 events read in total (250ms).
[16:04:40.600] INFO: Test took 1599ms.
[16:04:40.603] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:41.173] INFO: Expecting 2560 events.
[16:04:42.202] INFO: 2560 events read in total (250ms).
[16:04:42.202] INFO: Test took 1600ms.
[16:04:42.205] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:42.775] INFO: Expecting 2560 events.
[16:04:43.803] INFO: 2560 events read in total (249ms).
[16:04:43.804] INFO: Test took 1600ms.
[16:04:43.806] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:44.377] INFO: Expecting 2560 events.
[16:04:45.404] INFO: 2560 events read in total (249ms).
[16:04:45.405] INFO: Test took 1599ms.
[16:04:45.407] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:45.977] INFO: Expecting 2560 events.
[16:04:46.005] INFO: 2560 events read in total (249ms).
[16:04:46.005] INFO: Test took 1599ms.
[16:04:47.008] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:47.578] INFO: Expecting 2560 events.
[16:04:48.606] INFO: 2560 events read in total (249ms).
[16:04:48.607] INFO: Test took 1599ms.
[16:04:48.609] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:04:49.179] INFO: Expecting 2560 events.
[16:04:50.207] INFO: 2560 events read in total (249ms).
[16:04:50.208] INFO: Test took 1599ms.
[16:04:50.984] INFO: PixTestPhOptimization::doTest() done, duration: 531 seconds
[16:04:50.984] INFO: PH scale (per ROC): 80 79 83 77 85 79 89 75 84 91 86 80 82 78 89 80
[16:04:50.985] INFO: PH offset (per ROC): 146 164 159 155 132 146 148 145 158 154 157 141 144 172 164 161
[16:04:51.160] INFO: ######################################################################
[16:04:51.160] INFO: PixTestGainPedestal::fullTest() ntrig = 1
[16:04:51.160] INFO: ######################################################################
[16:04:51.172] INFO: scanning low vcal = 10
[16:04:51.525] INFO: Expecting 4160 events.
[16:04:54.401] INFO: 4160 events read in total (2097ms).
[16:04:54.401] INFO: Test took 3229ms.
[16:04:54.403] INFO: scanning low vcal = 20
[16:04:54.975] INFO: Expecting 4160 events.
[16:04:57.850] INFO: 4160 events read in total (2097ms).
[16:04:57.850] INFO: Test took 3446ms.
[16:04:57.852] INFO: scanning low vcal = 30
[16:04:58.424] INFO: Expecting 4160 events.
[16:05:01.305] INFO: 4160 events read in total (2102ms).
[16:05:01.305] INFO: Test took 3452ms.
[16:05:01.308] INFO: scanning low vcal = 40
[16:05:01.876] INFO: Expecting 4160 events.
[16:05:04.822] INFO: 4160 events read in total (2167ms).
[16:05:04.823] INFO: Test took 3515ms.
[16:05:04.827] INFO: scanning low vcal = 50
[16:05:05.370] INFO: Expecting 4160 events.
[16:05:08.321] INFO: 4160 events read in total (2172ms).
[16:05:08.322] INFO: Test took 3495ms.
[16:05:08.325] INFO: scanning low vcal = 60
[16:05:08.869] INFO: Expecting 4160 events.
[16:05:11.822] INFO: 4160 events read in total (2174ms).
[16:05:11.823] INFO: Test took 3498ms.
[16:05:11.825] INFO: scanning low vcal = 70
[16:05:12.367] INFO: Expecting 4160 events.
[16:05:15.327] INFO: 4160 events read in total (2181ms).
[16:05:15.327] INFO: Test took 3502ms.
[16:05:15.330] INFO: scanning low vcal = 80
[16:05:15.872] INFO: Expecting 4160 events.
[16:05:18.826] INFO: 4160 events read in total (2175ms).
[16:05:18.827] INFO: Test took 3497ms.
[16:05:18.830] INFO: scanning low vcal = 90
[16:05:19.376] INFO: Expecting 4160 events.
[16:05:22.408] INFO: 4160 events read in total (2253ms).
[16:05:22.408] INFO: Test took 3578ms.
[16:05:22.412] INFO: scanning low vcal = 100
[16:05:22.954] INFO: Expecting 4160 events.
[16:05:25.906] INFO: 4160 events read in total (2173ms).
[16:05:25.907] INFO: Test took 3495ms.
[16:05:25.910] INFO: scanning low vcal = 110
[16:05:26.452] INFO: Expecting 4160 events.
[16:05:29.404] INFO: 4160 events read in total (2173ms).
[16:05:29.404] INFO: Test took 3494ms.
[16:05:29.408] INFO: scanning low vcal = 120
[16:05:29.951] INFO: Expecting 4160 events.
[16:05:32.899] INFO: 4160 events read in total (2169ms).
[16:05:32.899] INFO: Test took 3491ms.
[16:05:32.902] INFO: scanning low vcal = 130
[16:05:33.450] INFO: Expecting 4160 events.
[16:05:36.401] INFO: 4160 events read in total (2172ms).
[16:05:36.402] INFO: Test took 3500ms.
[16:05:36.406] INFO: scanning low vcal = 140
[16:05:36.950] INFO: Expecting 4160 events.
[16:05:39.903] INFO: 4160 events read in total (2174ms).
[16:05:39.903] INFO: Test took 3497ms.
[16:05:39.907] INFO: scanning low vcal = 150
[16:05:40.449] INFO: Expecting 4160 events.
[16:05:43.403] INFO: 4160 events read in total (2176ms).
[16:05:43.403] INFO: Test took 3496ms.
[16:05:43.406] INFO: scanning low vcal = 160
[16:05:43.946] INFO: Expecting 4160 events.
[16:05:46.896] INFO: 4160 events read in total (2171ms).
[16:05:46.897] INFO: Test took 3491ms.
[16:05:46.900] INFO: scanning low vcal = 170
[16:05:47.443] INFO: Expecting 4160 events.
[16:05:50.393] INFO: 4160 events read in total (2171ms).
[16:05:50.393] INFO: Test took 3493ms.
[16:05:50.398] INFO: scanning low vcal = 180
[16:05:50.940] INFO: Expecting 4160 events.
[16:05:53.894] INFO: 4160 events read in total (2176ms).
[16:05:53.895] INFO: Test took 3497ms.
[16:05:53.899] INFO: scanning low vcal = 190
[16:05:54.438] INFO: Expecting 4160 events.
[16:05:57.389] INFO: 4160 events read in total (2172ms).
[16:05:57.390] INFO: Test took 3491ms.
[16:05:57.392] INFO: scanning low vcal = 200
[16:05:57.937] INFO: Expecting 4160 events.
[16:06:00.891] INFO: 4160 events read in total (2175ms).
[16:06:00.891] INFO: Test took 3499ms.
[16:06:00.894] INFO: scanning low vcal = 210
[16:06:01.437] INFO: Expecting 4160 events.
[16:06:04.386] INFO: 4160 events read in total (2171ms).
[16:06:04.387] INFO: Test took 3493ms.
[16:06:04.390] INFO: scanning low vcal = 220
[16:06:04.937] INFO: Expecting 4160 events.
[16:06:07.889] INFO: 4160 events read in total (2174ms).
[16:06:07.889] INFO: Test took 3499ms.
[16:06:07.892] INFO: scanning low vcal = 230
[16:06:08.436] INFO: Expecting 4160 events.
[16:06:11.389] INFO: 4160 events read in total (2174ms).
[16:06:11.390] INFO: Test took 3498ms.
[16:06:11.392] INFO: scanning low vcal = 240
[16:06:11.934] INFO: Expecting 4160 events.
[16:06:14.891] INFO: 4160 events read in total (2178ms).
[16:06:14.891] INFO: Test took 3499ms.
[16:06:14.894] INFO: scanning low vcal = 250
[16:06:15.432] INFO: Expecting 4160 events.
[16:06:18.386] INFO: 4160 events read in total (2175ms).
[16:06:18.386] INFO: Test took 3492ms.
[16:06:18.391] INFO: scanning high vcal = 30 (= 210 in low range)
[16:06:18.931] INFO: Expecting 4160 events.
[16:06:21.881] INFO: 4160 events read in total (2171ms).
[16:06:21.881] INFO: Test took 3490ms.
[16:06:21.884] INFO: scanning high vcal = 50 (= 350 in low range)
[16:06:22.429] INFO: Expecting 4160 events.
[16:06:25.375] INFO: 4160 events read in total (2168ms).
[16:06:25.375] INFO: Test took 3491ms.
[16:06:25.379] INFO: scanning high vcal = 70 (= 490 in low range)
[16:06:25.926] INFO: Expecting 4160 events.
[16:06:28.886] INFO: 4160 events read in total (2182ms).
[16:06:28.887] INFO: Test took 3508ms.
[16:06:28.890] INFO: scanning high vcal = 90 (= 630 in low range)
[16:06:29.432] INFO: Expecting 4160 events.
[16:06:32.463] INFO: 4160 events read in total (2252ms).
[16:06:32.464] INFO: Test took 3574ms.
[16:06:32.467] INFO: scanning high vcal = 200 (= 1400 in low range)
[16:06:33.011] INFO: Expecting 4160 events.
[16:06:35.959] INFO: 4160 events read in total (2169ms).
[16:06:35.960] INFO: Test took 3493ms.
[16:06:36.457] INFO: PixTestGainPedestal::measure() done
[16:07:10.554] INFO: PixTestGainPedestal::fit() done
[16:07:10.554] INFO: non-linearity mean: 0.957 0.961 0.957 0.952 0.953 0.960 0.955 0.951 0.953 0.949 0.960 0.961 0.956 0.959 0.948 0.959
[16:07:10.554] INFO: non-linearity RMS: 0.005 0.007 0.006 0.006 0.006 0.005 0.006 0.007 0.006 0.006 0.005 0.005 0.005 0.005 0.007 0.005
[16:07:10.554] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C0.dat
[16:07:10.576] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C1.dat
[16:07:10.596] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C2.dat
[16:07:10.615] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C3.dat
[16:07:10.634] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C4.dat
[16:07:10.654] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C5.dat
[16:07:10.673] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C6.dat
[16:07:10.692] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C7.dat
[16:07:10.712] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C8.dat
[16:07:10.731] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C9.dat
[16:07:10.750] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C10.dat
[16:07:10.770] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C11.dat
[16:07:10.789] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C12.dat
[16:07:10.808] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C13.dat
[16:07:10.827] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C14.dat
[16:07:10.847] INFO: write gain/ped parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/phCalibrationFitErr35_C15.dat
[16:07:10.866] INFO: PixTestGainPedestal::doTest() done, duration: 139 seconds
[16:07:10.872] INFO: readReadbackCal: M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C0.dat .. M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C15.dat
[16:07:10.893] INFO: PixTestReadback::doTest() start.
[16:07:10.894] INFO: PixTestReadback::RES sent once
[16:07:23.454] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C0.dat
[16:07:23.454] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C1.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C2.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C3.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C4.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C5.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C6.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C7.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C8.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C9.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C10.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C11.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C12.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C13.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C14.dat
[16:07:23.455] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C15.dat
[16:07:23.493] INFO: PixTestPattern:: pg_setup set to default.
[16:07:23.494] INFO: PixTestReadback::RES sent once
[16:07:36.027] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C0.dat
[16:07:36.027] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C1.dat
[16:07:36.027] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C2.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C3.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C4.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C5.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C6.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C7.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C8.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C9.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C10.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C11.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C12.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C13.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C14.dat
[16:07:36.028] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C15.dat
[16:07:36.065] INFO: PixTestPattern:: pg_setup set to default.
[16:07:36.066] INFO: PixTestReadback::RES sent once
[16:07:45.735] INFO: PixTestPattern:: pg_setup set to default.
[16:07:45.735] INFO: Vbg will be calibrated using Vd calibration
[16:07:45.736] INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 146calibrated Vbg = 1.22962 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 148.8calibrated Vbg = 1.23464 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 157.2calibrated Vbg = 1.23327 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 150calibrated Vbg = 1.24037 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 136.7calibrated Vbg = 1.24038 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 156.9calibrated Vbg = 1.24424 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 157.2calibrated Vbg = 1.2547 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 149calibrated Vbg = 1.25656 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 144.9calibrated Vbg = 1.2529 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 157.6calibrated Vbg = 1.25516 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 151.5calibrated Vbg = 1.23834 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 157.9calibrated Vbg = 1.24137 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 148.6calibrated Vbg = 1.22746 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 154.1calibrated Vbg = 1.24094 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 159.4calibrated Vbg = 1.238 :::*/*/*/*/
[16:07:45.736] INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 1.4822e-323calibrated Vbg = inf :::*/*/*/*/
[16:07:45.739] INFO: PixTestReadback::RES sent once
[16:10:55.640] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C0.dat
[16:10:55.640] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C1.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C2.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C3.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C4.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C5.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C6.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C7.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C8.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C9.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C10.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C11.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C12.dat
[16:10:55.641] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C13.dat
[16:10:55.642] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C14.dat
[16:10:55.642] INFO: write readback calibration parameters into M4087_FullQualification_2015-09-14_09h46m_1442216818/003_Fulltest_m20/readbackCal_C15.dat
[16:10:55.677] INFO: PixTestPattern:: pg_setup set to default.
[16:10:55.679] INFO: PixTestReadback::doTest() done
[16:10:55.698] INFO: enter test to run
[16:10:55.698] INFO: test: BB2 no parameter change
[16:10:55.698] INFO: running: bb2
[16:10:55.700] INFO: ######################################################################
[16:10:55.700] INFO: PixTestBB2Map::doTest() Ntrig = 16, VcalS = 255, PlWidth = 35
[16:10:55.700] INFO: ######################################################################
[16:10:55.701] INFO: ----------------------------------------------------------------------
[16:10:55.701] INFO: PixTestBB2Map::setVana() target Ia = 30 mA/ROC
[16:10:55.701] INFO: ----------------------------------------------------------------------
[16:11:15.278] INFO: PixTestBB2Map::setVana() done, Module Ia 479.9 mA = 29.9937 mA/ROC
[16:11:15.279] INFO: ----------------------------------------------------------------------
[16:11:15.279] INFO: PixTestBB2Map::setVthrCompCalDel()
[16:11:15.279] INFO: ----------------------------------------------------------------------
[16:11:15.420] INFO: Expecting 1048576 events.
[16:11:26.629] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (1) != Token Chain Length (8)
[16:11:26.631] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (21) != TBM ID (130)
[16:11:36.895] INFO: 1048576 events read in total (20696ms).
[16:11:36.901] INFO: Test took 21617ms.
[16:11:37.334] INFO: PixTestBB2Map::setVthrCompCalDel() done
[16:11:37.334] INFO: CalDel: 164 165 140 128 138 133 132 154 143 147 134 147 137 146 127 142
[16:11:37.334] INFO: VthrComp: 100 117 129 113 110 115 102 112 110 107 112 100 116 124 108 119
[16:11:37.703] INFO: Expecting 8519680 events.
[16:12:07.996] INFO: 1337744 events read in total (29514ms).
[16:12:37.483] INFO: 2665248 events read in total (59001ms).
[16:13:06.898] INFO: 3984384 events read in total (88417ms).
[16:13:36.245] INFO: 5303120 events read in total (117763ms).
[16:14:05.613] INFO: 6628224 events read in total (147131ms).
[16:14:35.024] INFO: 7963728 events read in total (176542ms).
[16:14:47.478] INFO: 8519680 events read in total (188996ms).
[16:14:47.510] INFO: Test took 190157ms.
[16:14:48.144] INFO: Missing Bumps: 1 0 0 0 0 2 0 1 0 1 0 0 0 1 0 1
[16:14:48.144] INFO: Separation Cut: 37.78 26.12 45.00 42.92 34.89 41.60 34.16 41.17 39.06 45.00 37.03 35.98 38.73 34.43 26.56 25.99
[16:14:48.145] INFO: PixTestBB2Map::doTest() done,232 seconds
[16:14:48.462] INFO: enter test to run
[16:14:48.462] INFO: test: q no parameter change
[16:14:49.147] QUIET: Connection to board 85 closed.
[16:14:49.157] INFO: pXar: this is the end, my friend