[15:31:01.198] INFO: === Welcome to pxar ===
[15:31:01.198] INFO: === Today: 2015/09/11
[15:31:01.198] INFO: readRocDacs: M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C0.dat .. M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C15.dat
[15:31:01.199] INFO: readTbmDacs: M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/tbmParameters_C0a.dat .. M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/tbmParameters_C0b.dat
[15:31:01.199] INFO: readMaskFile: M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/defaultMaskFile.dat
[15:31:01.199] INFO: readTrimFile: M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters_C0.dat .. M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters_C15.dat
[15:31:01.269] INFO: clk: 4
[15:31:01.269] INFO: ctr: 4
[15:31:01.269] INFO: sda: 19
[15:31:01.269] INFO: tin: 9
[15:31:01.269] INFO: level: 15
[15:31:01.269] INFO: triggerdelay: 0
[15:31:01.269] QUIET: Instanciating API for pxar prod-10+20~g6580e80
[15:31:01.269] INFO: Log level: INFO
[15:31:01.279] INFO: Found DTB DTB_WS6C22
[15:31:01.295] QUIET: Connection to board DTB_WS6C22 opened.
[15:31:01.299] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 74
HW version: DTB1.2
FW version: 4.2
SW version: 4.4
USB id: DTB_WS6C22
MAC address: 40D85511804A
Hostname: pixelDTB074
Comment:
------------------------------------------------------
[15:31:01.302] INFO: RPC call hashes of host and DTB match: 397073690
[15:31:02.909] INFO: DUT info:
[15:31:02.909] INFO: The DUT currently contains the following objects:
[15:31:02.909] INFO: 2 TBM Cores tbm08c (2 ON)
[15:31:02.909] INFO: TBM Core alpha (0): 7 registers set
[15:31:02.909] INFO: TBM Core beta (1): 7 registers set
[15:31:02.909] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:31:02.910] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:02.910] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:31:03.311] INFO: enter 'restricted' command line mode
[15:31:03.311] INFO: enter test to run
[15:31:03.311] INFO: test: Pretest no parameter change
[15:31:03.311] INFO: running: pretest
[15:31:03.318] INFO: ######################################################################
[15:31:03.318] INFO: PixTestPretest::doTest()
[15:31:03.318] INFO: ######################################################################
[15:31:03.320] INFO: ----------------------------------------------------------------------
[15:31:03.320] INFO: PixTestPretest::programROC()
[15:31:03.320] INFO: ----------------------------------------------------------------------
[15:31:21.344] INFO: PixTestPretest::programROC() done: ROCs are all programmable
[15:31:21.344] INFO: IA differences per ROC: 16.1 20.1 17.7 17.7 20.1 19.3 19.3 17.7 19.3 19.3 18.5 17.7 17.7 18.5 19.3 16.9
[15:31:21.424] INFO: ----------------------------------------------------------------------
[15:31:21.424] INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[15:31:21.424] INFO: ----------------------------------------------------------------------
[15:31:25.216] INFO: PixTestPretest::setVana() done, Module Ia 383.5 mA = 23.9688 mA/ROC
[15:31:25.217] INFO: ----------------------------------------------------------------------
[15:31:25.217] INFO: PixTestPretest::findTiming()
[15:31:25.217] INFO: ----------------------------------------------------------------------
[15:31:25.218] INFO: PixTestCmd::init()
[15:31:25.850] WARNING: Not unmasking DUT, not setting Calibrate bits!
[15:33:03.773] INFO: TBM phases: 160MHz: 7, 400MHz: 2, TBM delays: ROC(0/1):4, header/trailer: 1, token: 1
[15:33:03.773] INFO: (success/tries = 100/100), width = 3
[15:33:03.775] INFO: ----------------------------------------------------------------------
[15:33:03.775] INFO: PixTestPretest::findWorkingPixel()
[15:33:03.775] INFO: ----------------------------------------------------------------------
[15:33:03.919] INFO: Expecting 231680 events.
[15:33:09.108] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (1) != Token Chain Length (8)
[15:33:09.111] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (21) != TBM ID (2)
[15:33:11.806] INFO: 231680 events read in total (7108ms).
[15:33:11.811] INFO: Test took 8031ms.
[15:33:12.289] INFO: Found working pixel in all ROCs: col/row = 12/22
[15:33:12.339] INFO: ----------------------------------------------------------------------
[15:33:12.339] INFO: PixTestPretest::setVthrCompCalDel()
[15:33:12.339] INFO: ----------------------------------------------------------------------
[15:33:12.479] INFO: Expecting 231680 events.
[15:33:20.346] INFO: 231680 events read in total (7088ms).
[15:33:20.350] INFO: Test took 8005ms.
[15:33:20.850] INFO: PixTestPretest::setVthrCompCalDel() done
[15:33:20.850] INFO: CalDel: 143 138 129 133 152 142 144 141 131 130 139 126 125 158 123 125
[15:33:20.850] INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[15:33:20.854] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C0.dat
[15:33:20.854] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C1.dat
[15:33:20.855] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C2.dat
[15:33:20.855] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C3.dat
[15:33:20.855] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C4.dat
[15:33:20.855] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C5.dat
[15:33:20.855] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C6.dat
[15:33:20.856] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C7.dat
[15:33:20.856] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C8.dat
[15:33:20.856] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C9.dat
[15:33:20.856] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C10.dat
[15:33:20.856] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C11.dat
[15:33:20.856] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C12.dat
[15:33:20.857] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C13.dat
[15:33:20.857] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C14.dat
[15:33:20.857] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters_C15.dat
[15:33:20.857] INFO: write tbm parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/tbmParameters_C0a.dat
[15:33:20.857] INFO: write tbm parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/tbmParameters_C0b.dat
[15:33:20.857] INFO: PixTestPretest::doTest() done, duration: 137 seconds
[15:33:20.919] INFO: enter test to run
[15:33:20.919] INFO: test: FullTest no parameter change
[15:33:20.919] INFO: running: fulltest
[15:33:20.919] INFO: ######################################################################
[15:33:20.919] INFO: PixTestFullTest::doTest()
[15:33:20.919] INFO: ######################################################################
[15:33:20.921] INFO: ######################################################################
[15:33:20.921] INFO: PixTestAlive::doTest()
[15:33:20.921] INFO: ######################################################################
[15:33:20.923] INFO: ----------------------------------------------------------------------
[15:33:20.923] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:33:20.923] INFO: ----------------------------------------------------------------------
[15:33:21.280] INFO: Expecting 41600 events.
[15:33:25.417] INFO: 41600 events read in total (3358ms).
[15:33:25.417] INFO: Test took 4492ms.
[15:33:25.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:25.879] INFO: PixTestAlive::aliveTest() done
[15:33:25.879] INFO: number of dead pixels per ROC: 0 0 0 2 0 0 0 1 0 0 0 0 0 0 0 0
[15:33:25.881] INFO: ----------------------------------------------------------------------
[15:33:25.881] INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:33:25.881] INFO: ----------------------------------------------------------------------
[15:33:26.236] INFO: Expecting 41600 events.
[15:33:29.184] INFO: 41600 events read in total (2169ms).
[15:33:29.184] INFO: Test took 3301ms.
[15:33:29.184] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:29.185] INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[15:33:29.669] INFO: PixTestAlive::maskTest() done
[15:33:29.669] INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:33:29.671] INFO: ----------------------------------------------------------------------
[15:33:29.671] INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:33:29.671] INFO: ----------------------------------------------------------------------
[15:33:30.032] INFO: Expecting 41600 events.
[15:33:34.189] INFO: 41600 events read in total (3378ms).
[15:33:34.189] INFO: Test took 4515ms.
[15:33:34.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:34.650] INFO: PixTestAlive::addressDecodingTest() done
[15:33:34.650] INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:33:34.650] INFO: PixTestAlive::doTest() done, duration: 13 seconds
[15:33:34.660] INFO: ######################################################################
[15:33:34.660] INFO: PixTestBBMap::doTest() Ntrig = 16, VcalS = 250 (high range)
[15:33:34.660] INFO: ######################################################################
[15:33:34.665] INFO: ---> dac: VthrComp name: calSMap ntrig: 16 dacrange: 0 .. 149 (-1/-1) hits flags = 2 (plus default)
[15:33:34.693] INFO: dacScan split into 1 runs with ntrig = 16
[15:33:34.693] INFO: run 1 of 1
[15:33:35.046] INFO: Expecting 9984000 events.
[15:34:03.563] INFO: 1230496 events read in total (27738ms).
[15:34:31.254] INFO: 2449616 events read in total (55429ms).
[15:34:58.921] INFO: 3659824 events read in total (83097ms).
[15:35:26.569] INFO: 4866144 events read in total (110744ms).
[15:35:54.272] INFO: 6080608 events read in total (138447ms).
[15:36:22.009] INFO: 7302928 events read in total (166184ms).
[15:36:49.751] INFO: 8530576 events read in total (193926ms).
[15:37:16.869] INFO: 9769216 events read in total (221044ms).
[15:37:21.848] INFO: 9984000 events read in total (226023ms).
[15:37:21.890] INFO: Test took 227198ms.
[15:37:21.982] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:42.381] INFO: PixTestBBMap::doTest() done, duration: 247 seconds
[15:37:42.381] INFO: number of dead bumps (per ROC): 0 1 1 0 1 1 0 1 0 0 1 0 2 1 0 0
[15:37:42.381] INFO: separation cut (per ROC): 111 129 135 124 114 113 110 125 113 125 106 106 103 105 118 104
[15:37:42.450] INFO: ######################################################################
[15:37:42.450] INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[15:37:42.450] INFO: ######################################################################
[15:37:42.450] INFO: ----------------------------------------------------------------------
[15:37:42.450] INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[15:37:42.450] INFO: ----------------------------------------------------------------------
[15:37:42.451] INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (-1/-1) hits flags = 16 (plus default)
[15:37:42.466] INFO: dacScan split into 1 runs with ntrig = 50
[15:37:42.467] INFO: run 1 of 1
[15:37:42.819] INFO: Expecting 31200000 events.
[15:38:08.228] INFO: 1265200 events read in total (24625ms).
[15:38:31.793] INFO: 2504800 events read in total (48190ms).
[15:38:56.233] INFO: 3742950 events read in total (72630ms).
[15:39:20.589] INFO: 4976900 events read in total (96986ms).
[15:39:44.977] INFO: 6206150 events read in total (121374ms).
[15:40:09.297] INFO: 7431850 events read in total (145694ms).
[15:40:33.592] INFO: 8654700 events read in total (169989ms).
[15:40:57.842] INFO: 9875850 events read in total (194239ms).
[15:41:22.108] INFO: 11096950 events read in total (218505ms).
[15:41:46.321] INFO: 12311750 events read in total (242718ms).
[15:42:10.456] INFO: 13523950 events read in total (266853ms).
[15:42:34.542] INFO: 14735600 events read in total (290939ms).
[15:42:58.551] INFO: 15936550 events read in total (314948ms).
[15:43:22.539] INFO: 17128800 events read in total (338936ms).
[15:43:46.487] INFO: 18317400 events read in total (362884ms).
[15:44:10.390] INFO: 19499950 events read in total (386787ms).
[15:44:34.221] INFO: 20682950 events read in total (410618ms).
[15:44:57.988] INFO: 21862350 events read in total (434385ms).
[15:45:21.681] INFO: 23038600 events read in total (458078ms).
[15:45:45.463] INFO: 24214900 events read in total (481860ms).
[15:46:09.189] INFO: 25388700 events read in total (505586ms).
[15:46:32.828] INFO: 26560450 events read in total (529225ms).
[15:46:56.518] INFO: 27732600 events read in total (552915ms).
[15:47:20.211] INFO: 28904700 events read in total (576608ms).
[15:47:43.849] INFO: 30078500 events read in total (600246ms).
[15:48:05.758] INFO: 31200000 events read in total (622155ms).
[15:48:05.803] INFO: Test took 623336ms.
[15:48:05.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:06.102] INFO: dumping ASCII scurve output file: SCurveData
[15:48:07.696] INFO: dumping ASCII scurve output file: SCurveData
[15:48:09.210] INFO: dumping ASCII scurve output file: SCurveData
[15:48:10.592] INFO: dumping ASCII scurve output file: SCurveData
[15:48:12.016] INFO: dumping ASCII scurve output file: SCurveData
[15:48:13.485] INFO: dumping ASCII scurve output file: SCurveData
[15:48:14.952] INFO: dumping ASCII scurve output file: SCurveData
[15:48:16.424] INFO: dumping ASCII scurve output file: SCurveData
[15:48:17.874] INFO: dumping ASCII scurve output file: SCurveData
[15:48:19.341] INFO: dumping ASCII scurve output file: SCurveData
[15:48:20.771] INFO: dumping ASCII scurve output file: SCurveData
[15:48:22.238] INFO: dumping ASCII scurve output file: SCurveData
[15:48:23.701] INFO: dumping ASCII scurve output file: SCurveData
[15:48:25.192] INFO: dumping ASCII scurve output file: SCurveData
[15:48:26.695] INFO: dumping ASCII scurve output file: SCurveData
[15:48:28.181] INFO: dumping ASCII scurve output file: SCurveData
[15:48:29.671] INFO: PixTestScurves::scurves() done
[15:48:29.671] INFO: Vcal mean: 84.30 98.31 117.84 110.47 94.70 95.21 94.83 98.24 94.49 107.30 95.32 94.75 82.80 89.17 102.74 100.59
[15:48:29.671] INFO: Vcal RMS: 4.70 4.64 5.52 5.33 4.88 5.35 5.54 6.05 5.09 6.00 5.57 6.15 5.52 5.50 8.80 5.97
[15:48:29.671] INFO: PixTestScurves::fullTest() done, duration: 647 seconds
[15:48:29.744] INFO: ######################################################################
[15:48:29.744] INFO: PixTestTrim::doTest()
[15:48:29.744] INFO: ######################################################################
[15:48:29.746] INFO: ----------------------------------------------------------------------
[15:48:29.746] INFO: PixTestTrim::trimTest() ntrig = 20, vcal = 35
[15:48:29.746] INFO: ----------------------------------------------------------------------
[15:48:29.822] INFO: ---> VthrComp thr map (minimal VthrComp)
[15:48:29.822] INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 20 dacrange: 0 .. 159 (-1/-1) hits flags = 16 (plus default)
[15:48:29.832] INFO: dacScan split into 1 runs with ntrig = 20
[15:48:29.832] INFO: run 1 of 1
[15:48:30.182] INFO: Expecting 13312000 events.
[15:48:59.933] INFO: 1472340 events read in total (28962ms).
[15:49:28.890] INFO: 2937500 events read in total (57919ms).
[15:49:57.824] INFO: 4396340 events read in total (86854ms).
[15:50:26.658] INFO: 5846960 events read in total (115687ms).
[15:50:55.483] INFO: 7296420 events read in total (144512ms).
[15:51:24.521] INFO: 8756520 events read in total (173550ms).
[15:51:53.608] INFO: 10220480 events read in total (202637ms).
[15:52:22.689] INFO: 11685560 events read in total (231718ms).
[15:52:50.529] INFO: 13154200 events read in total (259558ms).
[15:52:53.791] INFO: 13312000 events read in total (262820ms).
[15:52:53.822] INFO: Test took 263990ms.
[15:52:53.877] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:12.674] INFO: ROC 0 VthrComp = 83
[15:53:12.675] INFO: ROC 1 VthrComp = 101
[15:53:12.675] INFO: ROC 2 VthrComp = 109
[15:53:12.675] INFO: ROC 3 VthrComp = 103
[15:53:12.675] INFO: ROC 4 VthrComp = 93
[15:53:12.676] INFO: ROC 5 VthrComp = 91
[15:53:12.676] INFO: ROC 6 VthrComp = 91
[15:53:12.676] INFO: ROC 7 VthrComp = 97
[15:53:12.676] INFO: ROC 8 VthrComp = 93
[15:53:12.676] INFO: ROC 9 VthrComp = 103
[15:53:12.676] INFO: ROC 10 VthrComp = 94
[15:53:12.676] INFO: ROC 11 VthrComp = 93
[15:53:12.677] INFO: ROC 12 VthrComp = 86
[15:53:12.677] INFO: ROC 13 VthrComp = 89
[15:53:12.677] INFO: ROC 14 VthrComp = 93
[15:53:12.677] INFO: ROC 15 VthrComp = 95
[15:53:12.677] INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[15:53:12.677] INFO: ---> dac: vcal name: TrimThr1 ntrig: 20 dacrange: 0 .. 159 (-1/-1) hits flags = 16 (plus default)
[15:53:12.691] INFO: dacScan split into 1 runs with ntrig = 20
[15:53:12.691] INFO: run 1 of 1
[15:53:13.044] INFO: Expecting 13312000 events.
[15:53:37.767] INFO: 921900 events read in total (23942ms).
[15:54:01.753] INFO: 1841740 events read in total (47928ms).
[15:54:25.684] INFO: 2759140 events read in total (71859ms).
[15:54:49.645] INFO: 3678100 events read in total (95820ms).
[15:55:13.635] INFO: 4596980 events read in total (119810ms).
[15:55:37.613] INFO: 5516180 events read in total (143788ms).
[15:56:01.644] INFO: 6436980 events read in total (167819ms).
[15:56:25.557] INFO: 7349280 events read in total (191732ms).
[15:56:49.347] INFO: 8258480 events read in total (215522ms).
[15:57:13.147] INFO: 9164240 events read in total (239322ms).
[15:57:36.934] INFO: 10068200 events read in total (263109ms).
[15:58:00.706] INFO: 10969740 events read in total (286881ms).
[15:58:24.537] INFO: 11870360 events read in total (310712ms).
[15:58:47.869] INFO: 12770360 events read in total (334044ms).
[15:59:00.971] INFO: 13312000 events read in total (347146ms).
[15:59:01.025] INFO: Test took 348334ms.
[15:59:01.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:26.127] INFO: roc 0 with ID = 0 has maximal Vcal 56.9947 for pixel 2/52 mean/min/max = 44.5337/31.8532/57.2143
[15:59:26.128] INFO: roc 1 with ID = 1 has maximal Vcal 55.1478 for pixel 47/1 mean/min/max = 43.1816/31.2143/55.1489
[15:59:26.128] INFO: roc 2 with ID = 2 has maximal Vcal 64.1979 for pixel 21/38 mean/min/max = 49.5891/34.9454/64.2327
[15:59:26.128] INFO: roc 3 with ID = 3 has maximal Vcal 60.9467 for pixel 51/69 mean/min/max = 46.9003/32.8332/60.9674
[15:59:26.128] INFO: roc 4 with ID = 4 has maximal Vcal 58.3369 for pixel 35/0 mean/min/max = 45.9227/33.42/58.4254
[15:59:26.129] INFO: roc 5 with ID = 5 has maximal Vcal 59.3249 for pixel 4/43 mean/min/max = 46.6223/33.6506/59.594
[15:59:26.129] INFO: roc 6 with ID = 6 has maximal Vcal 59.5775 for pixel 0/63 mean/min/max = 46.6755/33.658/59.693
[15:59:26.129] INFO: roc 7 with ID = 7 has maximal Vcal 61.3897 for pixel 15/79 mean/min/max = 46.3631/31.213/61.5131
[15:59:26.130] INFO: roc 8 with ID = 8 has maximal Vcal 57.5101 for pixel 20/5 mean/min/max = 45.6365/33.6069/57.6661
[15:59:26.130] INFO: roc 9 with ID = 9 has maximal Vcal 60.7518 for pixel 11/79 mean/min/max = 46.3503/31.223/61.4777
[15:59:26.130] INFO: roc 10 with ID = 10 has maximal Vcal 57.3296 for pixel 0/53 mean/min/max = 45.549/33.5262/57.5719
[15:59:26.130] INFO: roc 11 with ID = 11 has maximal Vcal 60.7198 for pixel 8/2 mean/min/max = 46.6208/32.4113/60.8303
[15:59:26.131] INFO: roc 12 with ID = 12 has maximal Vcal 58.4906 for pixel 0/70 mean/min/max = 45.0947/31.6029/58.5865
[15:59:26.131] INFO: roc 13 with ID = 13 has maximal Vcal 58.3793 for pixel 27/77 mean/min/max = 46.1067/33.4949/58.7185
[15:59:26.131] INFO: roc 14 with ID = 14 has maximal Vcal 69.6267 for pixel 3/70 mean/min/max = 49.9435/29.7378/70.1493
[15:59:26.132] INFO: roc 15 with ID = 15 has maximal Vcal 61.5969 for pixel 3/9 mean/min/max = 46.9523/32.244/61.6605
[15:59:26.132] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:59:26.266] INFO: Expecting 1029120 events.
[15:59:45.041] INFO: 1029120 events read in total (17996ms).
[15:59:45.047] INFO: Expecting 1029120 events.
[16:00:03.710] INFO: 1029120 events read in total (18038ms).
[16:00:03.720] INFO: Expecting 1029120 events.
[16:00:22.376] INFO: 1029120 events read in total (18044ms).
[16:00:22.385] INFO: Expecting 1029120 events.
[16:00:40.965] INFO: 1029120 events read in total (17956ms).
[16:00:40.976] INFO: Expecting 1029120 events.
[16:00:59.619] INFO: 1029120 events read in total (18012ms).
[16:00:59.632] INFO: Expecting 1029120 events.
[16:01:18.256] INFO: 1029120 events read in total (18005ms).
[16:01:18.272] INFO: Expecting 1029120 events.
[16:01:36.885] INFO: 1029120 events read in total (17991ms).
[16:01:36.903] INFO: Expecting 1029120 events.
[16:01:55.621] INFO: 1029120 events read in total (18097ms).
[16:01:55.643] INFO: Expecting 1029120 events.
[16:02:14.396] INFO: 1029120 events read in total (18144ms).
[16:02:14.425] INFO: Expecting 1029120 events.
[16:02:33.138] INFO: 1029120 events read in total (18108ms).
[16:02:33.167] INFO: Expecting 1029120 events.
[16:02:51.755] INFO: 1029120 events read in total (17982ms).
[16:02:51.782] INFO: Expecting 1029120 events.
[16:03:10.572] INFO: 1029120 events read in total (18174ms).
[16:03:10.605] INFO: Expecting 1029120 events.
[16:03:29.274] INFO: 1029120 events read in total (18069ms).
[16:03:29.307] INFO: Expecting 1029120 events.
[16:03:48.009] INFO: 1029120 events read in total (18095ms).
[16:03:48.042] INFO: Expecting 1029120 events.
[16:04:06.584] INFO: 1029120 events read in total (17939ms).
[16:04:06.623] INFO: Expecting 1029120 events.
[16:04:25.345] INFO: 1029120 events read in total (18118ms).
[16:04:25.388] INFO: Test took 299256ms.
[16:04:26.361] INFO: ---> dac: vcal name: TrimThr2 ntrig: 20 dacrange: 0 .. 199 (-1/-1) hits flags = 16 (plus default)
[16:04:26.371] INFO: dacScan split into 1 runs with ntrig = 20
[16:04:26.371] INFO: run 1 of 1
[16:04:26.721] INFO: Expecting 16640000 events.
[16:04:50.710] INFO: 846020 events read in total (23210ms).
[16:05:13.975] INFO: 1690200 events read in total (46475ms).
[16:05:37.291] INFO: 2533480 events read in total (69791ms).
[16:06:00.605] INFO: 3376000 events read in total (93105ms).
[16:06:23.885] INFO: 4219240 events read in total (116385ms).
[16:06:47.195] INFO: 5061340 events read in total (139695ms).
[16:07:10.526] INFO: 5904700 events read in total (163026ms).
[16:07:33.835] INFO: 6746780 events read in total (186335ms).
[16:07:57.080] INFO: 7588720 events read in total (209580ms).
[16:08:19.951] INFO: 8429180 events read in total (232451ms).
[16:08:43.173] INFO: 9263540 events read in total (255673ms).
[16:09:06.385] INFO: 10097200 events read in total (278885ms).
[16:09:29.614] INFO: 10930000 events read in total (302114ms).
[16:09:52.875] INFO: 11762220 events read in total (325375ms).
[16:10:16.160] INFO: 12593640 events read in total (348660ms).
[16:10:39.402] INFO: 13422700 events read in total (371902ms).
[16:11:02.685] INFO: 14252940 events read in total (395185ms).
[16:11:25.620] INFO: 15083160 events read in total (418120ms).
[16:11:48.396] INFO: 15914340 events read in total (440896ms).
[16:12:07.409] INFO: 16640000 events read in total (459909ms).
[16:12:07.488] INFO: Test took 461116ms.
[16:12:07.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:12:35.635] INFO: ---> TrimStepCorr4 extremal thresholds: 0.130851 .. 255.000000
[16:12:35.708] INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 20 dacrange: 0 .. 255 (-1/-1) hits flags = 16 (plus default)
[16:12:35.718] INFO: dacScan split into 1 runs with ntrig = 20
[16:12:35.718] INFO: run 1 of 1
[16:12:36.071] INFO: Expecting 21299200 events.
[16:12:59.901] INFO: 825820 events read in total (23051ms).
[16:13:22.924] INFO: 1651720 events read in total (46074ms).
[16:13:45.769] INFO: 2477840 events read in total (68919ms).
[16:14:07.010] INFO: 3304500 events read in total (90160ms).
[16:14:29.969] INFO: 4130620 events read in total (113119ms).
[16:14:52.992] INFO: 4956840 events read in total (136142ms).
[16:15:16.031] INFO: 5782580 events read in total (159181ms).
[16:15:38.934] INFO: 6608900 events read in total (182084ms).
[16:16:00.721] INFO: 7435200 events read in total (203871ms).
[16:16:23.336] INFO: 8261420 events read in total (226486ms).
[16:16:46.370] INFO: 9087620 events read in total (249520ms).
[16:17:09.456] INFO: 9913980 events read in total (272606ms).
[16:17:30.742] INFO: 10740380 events read in total (293892ms).
[16:17:52.670] INFO: 11566960 events read in total (315820ms).
[16:18:15.687] INFO: 12393400 events read in total (338837ms).
[16:18:38.639] INFO: 13219540 events read in total (361789ms).
[16:18:59.859] INFO: 14045740 events read in total (383009ms).
[16:19:22.895] INFO: 14871660 events read in total (406045ms).
[16:19:43.862] INFO: 15696620 events read in total (427012ms).
[16:20:06.797] INFO: 16521300 events read in total (449947ms).
[16:20:28.856] INFO: 17346040 events read in total (472006ms).
[16:20:51.845] INFO: 18169780 events read in total (494995ms).
[16:21:12.985] INFO: 18993540 events read in total (516135ms).
[16:21:33.822] INFO: 19817740 events read in total (536972ms).
[16:21:55.381] INFO: 20640980 events read in total (558531ms).
[16:22:13.972] INFO: 21299200 events read in total (577122ms).
[16:22:14.081] INFO: Test took 578364ms.
[16:22:14.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:44.410] INFO: ---> TrimStepCorr2 extremal thresholds: 0.172677 .. 53.274825
[16:22:44.479] INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 20 dacrange: 0 .. 63 (-1/-1) hits flags = 16 (plus default)
[16:22:44.489] INFO: dacScan split into 1 runs with ntrig = 20
[16:22:44.489] INFO: run 1 of 1
[16:22:44.838] INFO: Expecting 5324800 events.
[16:23:11.619] INFO: 1120660 events read in total (25997ms).
[16:23:35.525] INFO: 2241140 events read in total (49904ms).
[16:24:01.711] INFO: 3361660 events read in total (76089ms).
[16:24:25.822] INFO: 4479940 events read in total (100200ms).
[16:24:43.781] INFO: 5324800 events read in total (118159ms).
[16:24:43.809] INFO: Test took 119321ms.
[16:24:43.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:58.153] INFO: ---> TrimStepCorr1a extremal thresholds: 9.297120 .. 48.325363
[16:24:58.223] INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 20 dacrange: 9 .. 58 (-1/-1) hits flags = 16 (plus default)
[16:24:58.233] INFO: dacScan split into 1 runs with ntrig = 20
[16:24:58.233] INFO: run 1 of 1
[16:24:58.587] INFO: Expecting 4160000 events.
[16:25:23.777] INFO: 1100300 events read in total (24412ms).
[16:25:49.865] INFO: 2200100 events read in total (50500ms).
[16:26:15.903] INFO: 3298640 events read in total (76538ms).
[16:26:36.271] INFO: 4160000 events read in total (96906ms).
[16:26:36.295] INFO: Test took 98062ms.
[16:26:36.342] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:26:50.052] INFO: ---> TrimStepCorr1b extremal thresholds: 6.956914 .. 48.033927
[16:26:50.125] INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 20 dacrange: 6 .. 58 (-1/-1) hits flags = 16 (plus default)
[16:26:50.135] INFO: dacScan split into 1 runs with ntrig = 20
[16:26:50.135] INFO: run 1 of 1
[16:26:50.484] INFO: Expecting 4409600 events.
[16:27:16.550] INFO: 1125240 events read in total (25287ms).
[16:27:40.603] INFO: 2250360 events read in total (49340ms).
[16:28:05.763] INFO: 3374920 events read in total (74501ms).
[16:28:28.147] INFO: 4409600 events read in total (96885ms).
[16:28:28.171] INFO: Test took 98037ms.
[16:28:28.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:28:41.632] INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[16:28:41.632] INFO: ---> dac: vcal name: TrimThrFinal ntrig: 20 dacrange: 15 .. 55 (-1/-1) hits flags = 16 (plus default)
[16:28:41.645] INFO: dacScan split into 1 runs with ntrig = 20
[16:28:41.645] INFO: run 1 of 1
[16:28:41.995] INFO: Expecting 3411200 events.
[16:29:08.581] INFO: 1075020 events read in total (25807ms).
[16:29:34.491] INFO: 2149700 events read in total (51717ms).
[16:30:00.580] INFO: 3223220 events read in total (77806ms).
[16:30:05.437] INFO: 3411200 events read in total (82663ms).
[16:30:05.454] INFO: Test took 83810ms.
[16:30:05.495] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:30:18.572] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C0.dat
[16:30:18.572] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C1.dat
[16:30:18.572] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C2.dat
[16:30:18.573] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C3.dat
[16:30:18.573] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C4.dat
[16:30:18.573] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C5.dat
[16:30:18.573] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C6.dat
[16:30:18.573] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C7.dat
[16:30:18.573] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C8.dat
[16:30:18.574] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C9.dat
[16:30:18.574] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C10.dat
[16:30:18.574] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C11.dat
[16:30:18.574] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C12.dat
[16:30:18.574] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C13.dat
[16:30:18.574] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C14.dat
[16:30:18.574] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C15.dat
[16:30:18.575] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C0.dat
[16:30:18.585] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C1.dat
[16:30:18.592] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C2.dat
[16:30:18.598] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C3.dat
[16:30:18.604] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C4.dat
[16:30:18.610] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C5.dat
[16:30:18.616] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C6.dat
[16:30:18.622] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C7.dat
[16:30:18.628] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C8.dat
[16:30:18.634] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C9.dat
[16:30:18.640] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C10.dat
[16:30:18.646] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C11.dat
[16:30:18.652] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C12.dat
[16:30:18.658] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C13.dat
[16:30:18.664] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C14.dat
[16:30:18.670] INFO: write trim parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/trimParameters35_C15.dat
[16:30:18.676] INFO: PixTestTrim::trimTest() done
[16:30:18.676] INFO: vtrim: 84 86 106 84 84 92 90 103 84 97 82 101 85 92 111 99
[16:30:18.676] INFO: vthrcomp: 83 101 109 103 93 91 91 97 93 103 94 93 86 89 93 95
[16:30:18.676] INFO: vcal mean: 34.97 34.94 34.93 34.94 35.02 35.04 34.97 34.94 34.96 34.93 34.98 34.95 34.96 34.99 34.99 34.92
[16:30:18.676] INFO: vcal RMS: 0.75 0.73 0.92 1.09 0.69 0.78 0.76 0.97 0.68 0.78 0.71 0.78 0.73 0.74 1.01 0.78
[16:30:18.676] INFO: bits mean: 9.16 10.04 7.81 8.46 8.70 8.15 8.37 9.21 9.04 8.97 8.60 9.55 9.36 8.89 8.87 9.14
[16:30:18.676] INFO: bits RMS: 2.99 2.72 2.67 2.94 2.87 2.97 2.93 2.87 2.70 2.94 2.86 2.53 2.91 2.71 2.86 2.67
[16:30:18.685] INFO: ----------------------------------------------------------------------
[16:30:18.685] INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[16:30:18.685] INFO: ----------------------------------------------------------------------
[16:30:18.691] INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (-1/-1) hits flags = 16 (plus default)
[16:30:18.704] INFO: dacScan split into 1 runs with ntrig = 10
[16:30:18.704] INFO: run 1 of 1
[16:30:19.059] INFO: Expecting 8320000 events.
[16:30:48.485] INFO: 1222300 events read in total (28633ms).
[16:31:18.883] INFO: 2428050 events read in total (59031ms).
[16:31:46.630] INFO: 3621990 events read in total (86778ms).
[16:32:14.219] INFO: 4801660 events read in total (114367ms).
[16:32:44.021] INFO: 5967560 events read in total (144169ms).
[16:33:13.640] INFO: 7127290 events read in total (173788ms).
[16:33:43.419] INFO: 8292100 events read in total (203567ms).
[16:33:44.511] INFO: 8320000 events read in total (204659ms).
[16:33:44.561] INFO: Test took 205857ms.
[16:33:44.673] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:34:11.389] INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 195 (-1/-1) hits flags = 16 (plus default)
[16:34:11.403] INFO: dacScan split into 1 runs with ntrig = 10
[16:34:11.403] INFO: run 1 of 1
[16:34:11.754] INFO: Expecting 8153600 events.
[16:34:42.683] INFO: 1175140 events read in total (30150ms).
[16:35:10.510] INFO: 2335160 events read in total (57977ms).
[16:35:38.288] INFO: 3485230 events read in total (85755ms).
[16:36:07.697] INFO: 4621960 events read in total (115164ms).
[16:36:37.057] INFO: 5747880 events read in total (144524ms).
[16:37:03.987] INFO: 6868070 events read in total (171454ms).
[16:37:33.125] INFO: 7987800 events read in total (200592ms).
[16:37:37.720] INFO: 8153600 events read in total (205187ms).
[16:37:37.782] INFO: Test took 206379ms.
[16:37:37.907] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:38:04.388] INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 182 (-1/-1) hits flags = 16 (plus default)
[16:38:04.398] INFO: dacScan split into 1 runs with ntrig = 10
[16:38:04.398] INFO: run 1 of 1
[16:38:04.747] INFO: Expecting 7612800 events.
[16:38:34.800] INFO: 1221230 events read in total (29274ms).
[16:39:04.062] INFO: 2423550 events read in total (58536ms).
[16:39:34.079] INFO: 3614290 events read in total (88553ms).
[16:40:03.003] INFO: 4785720 events read in total (118477ms).
[16:40:33.798] INFO: 5948290 events read in total (148272ms).
[16:41:03.402] INFO: 7106670 events read in total (177876ms).
[16:41:16.594] INFO: 7612800 events read in total (191068ms).
[16:41:16.638] INFO: Test took 192240ms.
[16:41:16.738] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:41:42.029] INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 181 (-1/-1) hits flags = 16 (plus default)
[16:41:42.038] INFO: dacScan split into 1 runs with ntrig = 10
[16:41:42.039] INFO: run 1 of 1
[16:41:42.390] INFO: Expecting 7571200 events.
[16:42:11.727] INFO: 1224170 events read in total (28558ms).
[16:42:42.219] INFO: 2429290 events read in total (59050ms).
[16:43:12.486] INFO: 3623020 events read in total (89317ms).
[16:43:42.365] INFO: 4796270 events read in total (119197ms).
[16:44:12.263] INFO: 5960960 events read in total (149094ms).
[16:44:42.008] INFO: 7121500 events read in total (178839ms).
[16:44:53.675] INFO: 7571200 events read in total (190506ms).
[16:44:53.716] INFO: Test took 191677ms.
[16:44:53.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:18.865] INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 181 (-1/-1) hits flags = 16 (plus default)
[16:45:18.875] INFO: dacScan split into 1 runs with ntrig = 10
[16:45:18.875] INFO: run 1 of 1
[16:45:19.224] INFO: Expecting 7571200 events.
[16:45:50.627] INFO: 1222890 events read in total (30624ms).
[16:46:20.938] INFO: 2427170 events read in total (60935ms).
[16:46:51.045] INFO: 3619500 events read in total (91042ms).
[16:47:20.582] INFO: 4791730 events read in total (120579ms).
[16:47:48.086] INFO: 5955440 events read in total (148083ms).
[16:48:17.680] INFO: 7115420 events read in total (177677ms).
[16:48:29.552] INFO: 7571200 events read in total (189549ms).
[16:48:29.592] INFO: Test took 190717ms.
[16:48:29.693] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:48:54.884] INFO: PixTestTrim::trimBitTest() done
[16:48:54.886] INFO: PixTestTrim::doTest() done, duration: 3625 seconds
[16:48:55.558] INFO: ######################################################################
[16:48:55.558] INFO: PixTestPhOptimization::doTest() Ntrig = 16
[16:48:55.558] INFO: ######################################################################
[16:48:55.910] INFO: Expecting 41600 events.
[16:48:59.965] INFO: 41600 events read in total (3271ms).
[16:48:59.966] INFO: Test took 4407ms.
[16:48:59.973] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:49:00.745] INFO: Expecting 41600 events.
[16:49:04.829] INFO: 41600 events read in total (3305ms).
[16:49:04.830] INFO: Test took 4437ms.
[16:49:04.836] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:49:05.342] INFO: Expecting 41600 events.
[16:49:09.571] INFO: 41600 events read in total (3450ms).
[16:49:09.572] INFO: Test took 4619ms.
[16:49:09.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:49:09.586] INFO: The DUT currently contains the following objects:
[16:49:09.586] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:09.586] INFO: TBM Core alpha (0): 7 registers set
[16:49:09.586] INFO: TBM Core beta (1): 7 registers set
[16:49:09.586] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:09.586] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:09.586] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:10.072] INFO: Expecting 2560 events.
[16:49:11.101] INFO: 2560 events read in total (250ms).
[16:49:11.101] INFO: Test took 1515ms.
[16:49:11.102] INFO: The DUT currently contains the following objects:
[16:49:11.102] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:11.102] INFO: TBM Core alpha (0): 7 registers set
[16:49:11.102] INFO: TBM Core beta (1): 7 registers set
[16:49:11.102] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:11.102] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.102] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:11.674] INFO: Expecting 2560 events.
[16:49:12.702] INFO: 2560 events read in total (248ms).
[16:49:12.703] INFO: Test took 1601ms.
[16:49:12.703] INFO: The DUT currently contains the following objects:
[16:49:12.703] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:12.703] INFO: TBM Core alpha (0): 7 registers set
[16:49:12.703] INFO: TBM Core beta (1): 7 registers set
[16:49:12.703] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:12.703] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:12.703] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:13.276] INFO: Expecting 2560 events.
[16:49:14.301] INFO: 2560 events read in total (246ms).
[16:49:14.302] INFO: Test took 1599ms.
[16:49:14.302] INFO: The DUT currently contains the following objects:
[16:49:14.302] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:14.302] INFO: TBM Core alpha (0): 7 registers set
[16:49:14.302] INFO: TBM Core beta (1): 7 registers set
[16:49:14.302] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:14.302] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.302] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.302] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.302] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.302] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.303] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:14.876] INFO: Expecting 2560 events.
[16:49:15.904] INFO: 2560 events read in total (249ms).
[16:49:15.904] INFO: Test took 1601ms.
[16:49:15.905] INFO: The DUT currently contains the following objects:
[16:49:15.905] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:15.905] INFO: TBM Core alpha (0): 7 registers set
[16:49:15.905] INFO: TBM Core beta (1): 7 registers set
[16:49:15.905] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:15.905] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.905] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.905] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.905] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.905] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.905] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.905] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.905] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.905] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.906] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.906] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.906] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.906] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.906] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.906] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:15.906] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:16.478] INFO: Expecting 2560 events.
[16:49:17.506] INFO: 2560 events read in total (249ms).
[16:49:17.507] INFO: Test took 1601ms.
[16:49:17.507] INFO: The DUT currently contains the following objects:
[16:49:17.507] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:17.507] INFO: TBM Core alpha (0): 7 registers set
[16:49:17.507] INFO: TBM Core beta (1): 7 registers set
[16:49:17.507] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:17.507] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.507] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.507] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:17.508] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:18.081] INFO: Expecting 2560 events.
[16:49:19.108] INFO: 2560 events read in total (249ms).
[16:49:19.108] INFO: Test took 1600ms.
[16:49:19.109] INFO: The DUT currently contains the following objects:
[16:49:19.109] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:19.109] INFO: TBM Core alpha (0): 7 registers set
[16:49:19.109] INFO: TBM Core beta (1): 7 registers set
[16:49:19.109] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:19.109] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.109] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.109] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.109] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.109] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.109] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.109] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.109] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.109] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.109] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.110] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.110] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.110] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.110] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.110] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.110] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:19.682] INFO: Expecting 2560 events.
[16:49:20.710] INFO: 2560 events read in total (249ms).
[16:49:20.711] INFO: Test took 1601ms.
[16:49:20.711] INFO: The DUT currently contains the following objects:
[16:49:20.711] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:20.711] INFO: TBM Core alpha (0): 7 registers set
[16:49:20.711] INFO: TBM Core beta (1): 7 registers set
[16:49:20.711] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:20.711] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.711] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.712] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.712] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.712] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:20.712] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:21.284] INFO: Expecting 2560 events.
[16:49:22.311] INFO: 2560 events read in total (248ms).
[16:49:22.311] INFO: Test took 1599ms.
[16:49:22.312] INFO: The DUT currently contains the following objects:
[16:49:22.312] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:22.312] INFO: TBM Core alpha (0): 7 registers set
[16:49:22.312] INFO: TBM Core beta (1): 7 registers set
[16:49:22.312] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:22.312] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.312] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:22.885] INFO: Expecting 2560 events.
[16:49:23.912] INFO: 2560 events read in total (248ms).
[16:49:23.913] INFO: Test took 1601ms.
[16:49:23.913] INFO: The DUT currently contains the following objects:
[16:49:23.913] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:23.913] INFO: TBM Core alpha (0): 7 registers set
[16:49:23.913] INFO: TBM Core beta (1): 7 registers set
[16:49:23.913] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:23.913] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.913] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.914] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:23.914] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:24.486] INFO: Expecting 2560 events.
[16:49:25.513] INFO: 2560 events read in total (248ms).
[16:49:25.514] INFO: Test took 1600ms.
[16:49:25.514] INFO: The DUT currently contains the following objects:
[16:49:25.514] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:25.514] INFO: TBM Core alpha (0): 7 registers set
[16:49:25.514] INFO: TBM Core beta (1): 7 registers set
[16:49:25.514] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:25.514] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.514] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.514] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.514] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.514] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.514] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.514] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.514] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.514] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.514] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.515] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.515] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.515] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.515] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.515] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:25.515] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:26.087] INFO: Expecting 2560 events.
[16:49:27.114] INFO: 2560 events read in total (248ms).
[16:49:27.115] INFO: Test took 1600ms.
[16:49:27.115] INFO: The DUT currently contains the following objects:
[16:49:27.115] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:27.115] INFO: TBM Core alpha (0): 7 registers set
[16:49:27.115] INFO: TBM Core beta (1): 7 registers set
[16:49:27.115] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:27.115] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.115] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.115] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.115] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.116] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:27.688] INFO: Expecting 2560 events.
[16:49:28.716] INFO: 2560 events read in total (249ms).
[16:49:28.716] INFO: Test took 1600ms.
[16:49:28.717] INFO: The DUT currently contains the following objects:
[16:49:28.717] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:28.717] INFO: TBM Core alpha (0): 7 registers set
[16:49:28.717] INFO: TBM Core beta (1): 7 registers set
[16:49:28.717] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:28.717] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.717] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.717] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.717] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.717] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.717] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.717] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.717] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.718] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.718] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.718] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.718] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.718] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.718] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.718] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:28.718] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:29.290] INFO: Expecting 2560 events.
[16:49:30.319] INFO: 2560 events read in total (250ms).
[16:49:30.319] INFO: Test took 1601ms.
[16:49:30.320] INFO: The DUT currently contains the following objects:
[16:49:30.320] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:30.320] INFO: TBM Core alpha (0): 7 registers set
[16:49:30.320] INFO: TBM Core beta (1): 7 registers set
[16:49:30.320] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:30.320] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.320] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:30.893] INFO: Expecting 2560 events.
[16:49:31.922] INFO: 2560 events read in total (250ms).
[16:49:31.922] INFO: Test took 1602ms.
[16:49:31.923] INFO: The DUT currently contains the following objects:
[16:49:31.923] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:31.923] INFO: TBM Core alpha (0): 7 registers set
[16:49:31.923] INFO: TBM Core beta (1): 7 registers set
[16:49:31.923] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:31.923] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:31.923] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:32.496] INFO: Expecting 2560 events.
[16:49:33.525] INFO: 2560 events read in total (250ms).
[16:49:33.525] INFO: Test took 1602ms.
[16:49:33.526] INFO: The DUT currently contains the following objects:
[16:49:33.526] INFO: 2 TBM Cores tbm08c (2 ON)
[16:49:33.526] INFO: TBM Core alpha (0): 7 registers set
[16:49:33.526] INFO: TBM Core beta (1): 7 registers set
[16:49:33.526] INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:49:33.526] INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:33.526] INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:49:34.099] INFO: Expecting 2560 events.
[16:49:35.124] INFO: 2560 events read in total (246ms).
[16:49:35.124] INFO: Test took 1598ms.
[16:49:35.129] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:49:35.699] INFO: Expecting 655360 events.
[16:49:49.128] INFO: 655360 events read in total (12650ms).
[16:49:49.142] INFO: Expecting 655360 events.
[16:50:02.296] INFO: 655360 events read in total (12586ms).
[16:50:02.311] INFO: Expecting 655360 events.
[16:50:15.519] INFO: 655360 events read in total (12630ms).
[16:50:15.544] INFO: Expecting 655360 events.
[16:50:28.724] INFO: 655360 events read in total (12617ms).
[16:50:28.751] INFO: Expecting 655360 events.
[16:50:41.931] INFO: 655360 events read in total (12620ms).
[16:50:41.963] INFO: Expecting 655360 events.
[16:50:55.156] INFO: 655360 events read in total (12634ms).
[16:50:55.202] INFO: Expecting 655360 events.
[16:51:08.320] INFO: 655360 events read in total (12577ms).
[16:51:08.358] INFO: Expecting 655360 events.
[16:51:21.557] INFO: 655360 events read in total (12644ms).
[16:51:21.596] INFO: Expecting 655360 events.
[16:51:34.864] INFO: 655360 events read in total (12718ms).
[16:51:34.911] INFO: Expecting 655360 events.
[16:51:48.136] INFO: 655360 events read in total (12685ms).
[16:51:48.192] INFO: Expecting 655360 events.
[16:52:01.383] INFO: 655360 events read in total (12664ms).
[16:52:01.436] INFO: Expecting 655360 events.
[16:52:14.611] INFO: 655360 events read in total (12638ms).
[16:52:14.668] INFO: Expecting 655360 events.
[16:52:27.755] INFO: 655360 events read in total (12560ms).
[16:52:27.826] INFO: Expecting 655360 events.
[16:52:40.903] INFO: 655360 events read in total (12550ms).
[16:52:40.974] INFO: Expecting 655360 events.
[16:52:54.014] INFO: 655360 events read in total (12512ms).
[16:52:54.086] INFO: Expecting 655360 events.
[16:53:07.061] INFO: 655360 events read in total (12448ms).
[16:53:07.136] INFO: Test took 212008ms.
[16:53:07.239] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:53:07.605] INFO: Expecting 655360 events.
[16:53:20.765] INFO: 655360 events read in total (12381ms).
[16:53:20.777] INFO: Expecting 655360 events.
[16:53:33.727] INFO: 655360 events read in total (12370ms).
[16:53:33.742] INFO: Expecting 655360 events.
[16:53:46.747] INFO: 655360 events read in total (12423ms).
[16:53:46.767] INFO: Expecting 655360 events.
[16:53:59.607] INFO: 655360 events read in total (12267ms).
[16:53:59.635] INFO: Expecting 655360 events.
[16:54:12.510] INFO: 655360 events read in total (12311ms).
[16:54:12.538] INFO: Expecting 655360 events.
[16:54:25.456] INFO: 655360 events read in total (12352ms).
[16:54:25.491] INFO: Expecting 655360 events.
[16:54:38.420] INFO: 655360 events read in total (12380ms).
[16:54:38.457] INFO: Expecting 655360 events.
[16:54:51.388] INFO: 655360 events read in total (12367ms).
[16:54:51.432] INFO: Expecting 655360 events.
[16:55:04.356] INFO: 655360 events read in total (12376ms).
[16:55:04.400] INFO: Expecting 655360 events.
[16:55:17.252] INFO: 655360 events read in total (12297ms).
[16:55:17.302] INFO: Expecting 655360 events.
[16:55:29.978] INFO: 655360 events read in total (12127ms).
[16:55:30.031] INFO: Expecting 655360 events.
[16:55:42.198] INFO: 655360 events read in total (11631ms).
[16:55:42.254] INFO: Expecting 655360 events.
[16:55:54.653] INFO: 655360 events read in total (11856ms).
[16:55:54.714] INFO: Expecting 655360 events.
[16:56:07.225] INFO: 655360 events read in total (11974ms).
[16:56:07.294] INFO: Expecting 655360 events.
[16:56:20.041] INFO: 655360 events read in total (12214ms).
[16:56:20.109] INFO: Expecting 655360 events.
[16:56:33.490] INFO: 655360 events read in total (12793ms).
[16:56:33.566] INFO: Test took 206327ms.
[16:56:33.760] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.767] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.773] INFO: safety margin for low PH: adding 1, margin is now 21
[16:56:33.779] INFO: safety margin for low PH: adding 2, margin is now 22
[16:56:33.785] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.792] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.798] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.804] INFO: safety margin for low PH: adding 1, margin is now 21
[16:56:33.810] INFO: safety margin for low PH: adding 2, margin is now 22
[16:56:33.817] INFO: safety margin for low PH: adding 3, margin is now 23
[16:56:33.823] INFO: safety margin for low PH: adding 4, margin is now 24
[16:56:33.830] INFO: safety margin for low PH: adding 5, margin is now 25
[16:56:33.836] INFO: safety margin for low PH: adding 6, margin is now 26
[16:56:33.842] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.849] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.856] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.862] INFO: safety margin for low PH: adding 1, margin is now 21
[16:56:33.868] INFO: safety margin for low PH: adding 2, margin is now 22
[16:56:33.875] INFO: safety margin for low PH: adding 3, margin is now 23
[16:56:33.881] INFO: safety margin for low PH: adding 4, margin is now 24
[16:56:33.888] INFO: safety margin for low PH: adding 5, margin is now 25
[16:56:33.894] INFO: safety margin for low PH: adding 6, margin is now 26
[16:56:33.900] INFO: safety margin for low PH: adding 7, margin is now 27
[16:56:33.906] INFO: safety margin for low PH: adding 8, margin is now 28
[16:56:33.913] INFO: safety margin for low PH: adding 9, margin is now 29
[16:56:33.920] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.926] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.932] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.939] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.945] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.952] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.959] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:33.965] INFO: safety margin for low PH: adding 0, margin is now 20
[16:56:34.022] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C0.dat
[16:56:34.022] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C1.dat
[16:56:34.022] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C2.dat
[16:56:34.022] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C3.dat
[16:56:34.022] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C4.dat
[16:56:34.022] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C5.dat
[16:56:34.023] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C6.dat
[16:56:34.023] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C7.dat
[16:56:34.023] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C8.dat
[16:56:34.023] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C9.dat
[16:56:34.023] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C10.dat
[16:56:34.023] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C11.dat
[16:56:34.024] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C12.dat
[16:56:34.024] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C13.dat
[16:56:34.024] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C14.dat
[16:56:34.024] INFO: write dac parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/dacParameters35_C15.dat
[16:56:34.385] INFO: Expecting 41600 events.
[16:56:38.650] INFO: 41600 events read in total (3486ms).
[16:56:38.651] INFO: Test took 4622ms.
[16:56:39.401] INFO: Expecting 41600 events.
[16:56:43.597] INFO: 41600 events read in total (3416ms).
[16:56:43.598] INFO: Test took 4553ms.
[16:56:44.348] INFO: Expecting 41600 events.
[16:56:48.612] INFO: 41600 events read in total (3485ms).
[16:56:48.612] INFO: Test took 4618ms.
[16:56:48.005] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:56:49.138] INFO: Expecting 2560 events.
[16:56:50.167] INFO: 2560 events read in total (250ms).
[16:56:50.168] INFO: Test took 1163ms.
[16:56:50.170] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:56:50.742] INFO: Expecting 2560 events.
[16:56:51.771] INFO: 2560 events read in total (250ms).
[16:56:51.771] INFO: Test took 1601ms.
[16:56:51.774] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:56:52.345] INFO: Expecting 2560 events.
[16:56:53.374] INFO: 2560 events read in total (250ms).
[16:56:53.375] INFO: Test took 1601ms.
[16:56:53.378] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:56:53.948] INFO: Expecting 2560 events.
[16:56:54.978] INFO: 2560 events read in total (250ms).
[16:56:54.978] INFO: Test took 1600ms.
[16:56:54.981] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:56:55.552] INFO: Expecting 2560 events.
[16:56:56.581] INFO: 2560 events read in total (250ms).
[16:56:56.581] INFO: Test took 1600ms.
[16:56:56.584] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:56:57.155] INFO: Expecting 2560 events.
[16:56:58.184] INFO: 2560 events read in total (250ms).
[16:56:58.185] INFO: Test took 1601ms.
[16:56:58.188] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:56:58.758] INFO: Expecting 2560 events.
[16:56:59.787] INFO: 2560 events read in total (250ms).
[16:56:59.788] INFO: Test took 1600ms.
[16:56:59.792] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:00.362] INFO: Expecting 2560 events.
[16:57:01.391] INFO: 2560 events read in total (250ms).
[16:57:01.392] INFO: Test took 1600ms.
[16:57:01.395] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:01.965] INFO: Expecting 2560 events.
[16:57:02.994] INFO: 2560 events read in total (250ms).
[16:57:02.995] INFO: Test took 1600ms.
[16:57:02.998] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:03.568] INFO: Expecting 2560 events.
[16:57:04.598] INFO: 2560 events read in total (251ms).
[16:57:04.598] INFO: Test took 1600ms.
[16:57:04.601] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:05.172] INFO: Expecting 2560 events.
[16:57:06.201] INFO: 2560 events read in total (250ms).
[16:57:06.201] INFO: Test took 1600ms.
[16:57:06.204] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:06.775] INFO: Expecting 2560 events.
[16:57:07.804] INFO: 2560 events read in total (250ms).
[16:57:07.805] INFO: Test took 1601ms.
[16:57:07.808] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:08.379] INFO: Expecting 2560 events.
[16:57:09.408] INFO: 2560 events read in total (250ms).
[16:57:09.408] INFO: Test took 1601ms.
[16:57:09.411] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:09.982] INFO: Expecting 2560 events.
[16:57:11.011] INFO: 2560 events read in total (250ms).
[16:57:11.011] INFO: Test took 1600ms.
[16:57:11.014] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:11.585] INFO: Expecting 2560 events.
[16:57:12.615] INFO: 2560 events read in total (251ms).
[16:57:12.615] INFO: Test took 1601ms.
[16:57:12.618] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:13.189] INFO: Expecting 2560 events.
[16:57:14.218] INFO: 2560 events read in total (250ms).
[16:57:14.218] INFO: Test took 1600ms.
[16:57:14.221] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:14.792] INFO: Expecting 2560 events.
[16:57:15.822] INFO: 2560 events read in total (251ms).
[16:57:15.822] INFO: Test took 1601ms.
[16:57:15.827] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:16.396] INFO: Expecting 2560 events.
[16:57:17.426] INFO: 2560 events read in total (251ms).
[16:57:17.426] INFO: Test took 1599ms.
[16:57:17.429] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:17.000] INFO: Expecting 2560 events.
[16:57:19.029] INFO: 2560 events read in total (251ms).
[16:57:19.030] INFO: Test took 1601ms.
[16:57:19.033] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:19.604] INFO: Expecting 2560 events.
[16:57:20.633] INFO: 2560 events read in total (250ms).
[16:57:20.634] INFO: Test took 1601ms.
[16:57:20.637] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:21.208] INFO: Expecting 2560 events.
[16:57:22.238] INFO: 2560 events read in total (251ms).
[16:57:22.238] INFO: Test took 1601ms.
[16:57:22.241] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:22.812] INFO: Expecting 2560 events.
[16:57:23.841] INFO: 2560 events read in total (250ms).
[16:57:23.842] INFO: Test took 1601ms.
[16:57:23.845] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:24.416] INFO: Expecting 2560 events.
[16:57:25.446] INFO: 2560 events read in total (251ms).
[16:57:25.446] INFO: Test took 1601ms.
[16:57:25.449] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:26.020] INFO: Expecting 2560 events.
[16:57:27.049] INFO: 2560 events read in total (250ms).
[16:57:27.050] INFO: Test took 1601ms.
[16:57:27.053] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:27.624] INFO: Expecting 2560 events.
[16:57:28.654] INFO: 2560 events read in total (251ms).
[16:57:28.654] INFO: Test took 1601ms.
[16:57:28.657] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:29.228] INFO: Expecting 2560 events.
[16:57:30.257] INFO: 2560 events read in total (251ms).
[16:57:30.257] INFO: Test took 1600ms.
[16:57:30.261] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:30.832] INFO: Expecting 2560 events.
[16:57:31.861] INFO: 2560 events read in total (250ms).
[16:57:31.861] INFO: Test took 1601ms.
[16:57:31.864] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:32.435] INFO: Expecting 2560 events.
[16:57:33.465] INFO: 2560 events read in total (251ms).
[16:57:33.465] INFO: Test took 1601ms.
[16:57:33.468] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:34.039] INFO: Expecting 2560 events.
[16:57:35.069] INFO: 2560 events read in total (251ms).
[16:57:35.069] INFO: Test took 1601ms.
[16:57:35.073] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:35.643] INFO: Expecting 2560 events.
[16:57:36.672] INFO: 2560 events read in total (250ms).
[16:57:36.672] INFO: Test took 1600ms.
[16:57:36.676] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:37.246] INFO: Expecting 2560 events.
[16:57:38.276] INFO: 2560 events read in total (251ms).
[16:57:38.276] INFO: Test took 1601ms.
[16:57:38.279] INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:57:38.850] INFO: Expecting 2560 events.
[16:57:39.880] INFO: 2560 events read in total (251ms).
[16:57:39.880] INFO: Test took 1601ms.
[16:57:40.710] INFO: PixTestPhOptimization::doTest() done, duration: 525 seconds
[16:57:40.710] INFO: PH scale (per ROC): 77 74 63 65 72 70 71 75 70 71 74 69 82 72 61 70
[16:57:40.710] INFO: PH offset (per ROC): 177 175 205 186 176 166 178 176 171 181 161 158 152 172 180 174
[16:57:40.884] INFO: ######################################################################
[16:57:40.884] INFO: PixTestGainPedestal::fullTest() ntrig = 1
[16:57:40.884] INFO: ######################################################################
[16:57:40.898] INFO: scanning low vcal = 10
[16:57:41.255] INFO: Expecting 4160 events.
[16:57:44.133] INFO: 4160 events read in total (2099ms).
[16:57:44.133] INFO: Test took 3235ms.
[16:57:44.136] INFO: scanning low vcal = 20
[16:57:44.707] INFO: Expecting 4160 events.
[16:57:47.585] INFO: 4160 events read in total (2099ms).
[16:57:47.585] INFO: Test took 3449ms.
[16:57:47.588] INFO: scanning low vcal = 30
[16:57:48.159] INFO: Expecting 4160 events.
[16:57:51.043] INFO: 4160 events read in total (2104ms).
[16:57:51.044] INFO: Test took 3456ms.
[16:57:51.048] INFO: scanning low vcal = 40
[16:57:51.614] INFO: Expecting 4160 events.
[16:57:54.558] INFO: 4160 events read in total (2164ms).
[16:57:54.559] INFO: Test took 3511ms.
[16:57:54.563] INFO: scanning low vcal = 50
[16:57:55.112] INFO: Expecting 4160 events.
[16:57:58.062] INFO: 4160 events read in total (2171ms).
[16:57:58.063] INFO: Test took 3500ms.
[16:57:58.067] INFO: scanning low vcal = 60
[16:57:58.613] INFO: Expecting 4160 events.
[16:58:01.565] INFO: 4160 events read in total (2173ms).
[16:58:01.566] INFO: Test took 3499ms.
[16:58:01.569] INFO: scanning low vcal = 70
[16:58:02.113] INFO: Expecting 4160 events.
[16:58:05.071] INFO: 4160 events read in total (2179ms).
[16:58:05.071] INFO: Test took 3502ms.
[16:58:05.075] INFO: scanning low vcal = 80
[16:58:05.623] INFO: Expecting 4160 events.
[16:58:08.584] INFO: 4160 events read in total (2182ms).
[16:58:08.584] INFO: Test took 3509ms.
[16:58:08.589] INFO: scanning low vcal = 90
[16:58:09.132] INFO: Expecting 4160 events.
[16:58:12.163] INFO: 4160 events read in total (2252ms).
[16:58:12.164] INFO: Test took 3575ms.
[16:58:12.168] INFO: scanning low vcal = 100
[16:58:12.715] INFO: Expecting 4160 events.
[16:58:15.666] INFO: 4160 events read in total (2172ms).
[16:58:15.667] INFO: Test took 3499ms.
[16:58:15.671] INFO: scanning low vcal = 110
[16:58:16.217] INFO: Expecting 4160 events.
[16:58:19.169] INFO: 4160 events read in total (2173ms).
[16:58:19.169] INFO: Test took 3498ms.
[16:58:19.173] INFO: scanning low vcal = 120
[16:58:19.720] INFO: Expecting 4160 events.
[16:58:22.672] INFO: 4160 events read in total (2173ms).
[16:58:22.673] INFO: Test took 3500ms.
[16:58:22.677] INFO: scanning low vcal = 130
[16:58:23.222] INFO: Expecting 4160 events.
[16:58:26.175] INFO: 4160 events read in total (2174ms).
[16:58:26.176] INFO: Test took 3499ms.
[16:58:26.180] INFO: scanning low vcal = 140
[16:58:26.723] INFO: Expecting 4160 events.
[16:58:29.678] INFO: 4160 events read in total (2176ms).
[16:58:29.679] INFO: Test took 3499ms.
[16:58:29.683] INFO: scanning low vcal = 150
[16:58:30.226] INFO: Expecting 4160 events.
[16:58:33.175] INFO: 4160 events read in total (2171ms).
[16:58:33.176] INFO: Test took 3493ms.
[16:58:33.179] INFO: scanning low vcal = 160
[16:58:33.727] INFO: Expecting 4160 events.
[16:58:36.678] INFO: 4160 events read in total (2172ms).
[16:58:36.679] INFO: Test took 3500ms.
[16:58:36.682] INFO: scanning low vcal = 170
[16:58:37.229] INFO: Expecting 4160 events.
[16:58:40.181] INFO: 4160 events read in total (2173ms).
[16:58:40.182] INFO: Test took 3500ms.
[16:58:40.188] INFO: scanning low vcal = 180
[16:58:40.732] INFO: Expecting 4160 events.
[16:58:43.685] INFO: 4160 events read in total (2174ms).
[16:58:43.685] INFO: Test took 3497ms.
[16:58:43.689] INFO: scanning low vcal = 190
[16:58:44.234] INFO: Expecting 4160 events.
[16:58:47.188] INFO: 4160 events read in total (2175ms).
[16:58:47.188] INFO: Test took 3499ms.
[16:58:47.193] INFO: scanning low vcal = 200
[16:58:47.737] INFO: Expecting 4160 events.
[16:58:50.691] INFO: 4160 events read in total (2175ms).
[16:58:50.692] INFO: Test took 3499ms.
[16:58:50.695] INFO: scanning low vcal = 210
[16:58:51.239] INFO: Expecting 4160 events.
[16:58:54.194] INFO: 4160 events read in total (2176ms).
[16:58:54.195] INFO: Test took 3500ms.
[16:58:54.199] INFO: scanning low vcal = 220
[16:58:54.741] INFO: Expecting 4160 events.
[16:58:57.698] INFO: 4160 events read in total (2178ms).
[16:58:57.699] INFO: Test took 3500ms.
[16:58:57.703] INFO: scanning low vcal = 230
[16:58:58.245] INFO: Expecting 4160 events.
[16:59:01.195] INFO: 4160 events read in total (2171ms).
[16:59:01.196] INFO: Test took 3493ms.
[16:59:01.200] INFO: scanning low vcal = 240
[16:59:01.748] INFO: Expecting 4160 events.
[16:59:04.702] INFO: 4160 events read in total (2175ms).
[16:59:04.703] INFO: Test took 3502ms.
[16:59:04.707] INFO: scanning low vcal = 250
[16:59:05.250] INFO: Expecting 4160 events.
[16:59:08.201] INFO: 4160 events read in total (2172ms).
[16:59:08.202] INFO: Test took 3495ms.
[16:59:08.208] INFO: scanning high vcal = 30 (= 210 in low range)
[16:59:08.753] INFO: Expecting 4160 events.
[16:59:11.706] INFO: 4160 events read in total (2174ms).
[16:59:11.706] INFO: Test took 3498ms.
[16:59:11.709] INFO: scanning high vcal = 50 (= 350 in low range)
[16:59:12.256] INFO: Expecting 4160 events.
[16:59:15.209] INFO: 4160 events read in total (2174ms).
[16:59:15.210] INFO: Test took 3500ms.
[16:59:15.213] INFO: scanning high vcal = 70 (= 490 in low range)
[16:59:15.759] INFO: Expecting 4160 events.
[16:59:18.716] INFO: 4160 events read in total (2178ms).
[16:59:18.716] INFO: Test took 3503ms.
[16:59:18.720] INFO: scanning high vcal = 90 (= 630 in low range)
[16:59:19.269] INFO: Expecting 4160 events.
[16:59:22.301] INFO: 4160 events read in total (2253ms).
[16:59:22.302] INFO: Test took 3582ms.
[16:59:22.306] INFO: scanning high vcal = 200 (= 1400 in low range)
[16:59:22.851] INFO: Expecting 4160 events.
[16:59:25.806] INFO: 4160 events read in total (2175ms).
[16:59:25.807] INFO: Test took 3501ms.
[16:59:26.309] INFO: PixTestGainPedestal::measure() done
[17:00:00.448] INFO: PixTestGainPedestal::fit() done
[17:00:00.448] INFO: non-linearity mean: 0.957 0.958 0.946 0.962 0.959 0.956 0.951 0.965 0.952 0.955 0.956 0.960 0.949 0.949 0.951 0.952
[17:00:00.448] INFO: non-linearity RMS: 0.008 0.006 0.008 0.007 0.006 0.007 0.007 0.005 0.007 0.006 0.006 0.006 0.006 0.007 0.006 0.007
[17:00:00.448] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C0.dat
[17:00:00.471] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C1.dat
[17:00:00.489] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C2.dat
[17:00:00.508] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C3.dat
[17:00:00.526] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C4.dat
[17:00:00.545] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C5.dat
[17:00:00.563] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C6.dat
[17:00:00.582] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C7.dat
[17:00:00.601] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C8.dat
[17:00:00.619] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C9.dat
[17:00:00.638] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C10.dat
[17:00:00.656] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C11.dat
[17:00:00.675] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C12.dat
[17:00:00.693] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C13.dat
[17:00:00.712] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C14.dat
[17:00:00.730] INFO: write gain/ped parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/phCalibrationFitErr35_C15.dat
[17:00:00.749] INFO: PixTestGainPedestal::doTest() done, duration: 139 seconds
[17:00:00.755] INFO: readReadbackCal: M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C0.dat .. M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C15.dat
[17:00:00.756] INFO: PixTestReadback::doTest() start.
[17:00:00.757] INFO: PixTestReadback::RES sent once
[17:00:13.395] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C0.dat
[17:00:13.395] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C1.dat
[17:00:13.395] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C2.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C3.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C4.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C5.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C6.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C7.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C8.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C9.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C10.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C11.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C12.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C13.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C14.dat
[17:00:13.396] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C15.dat
[17:00:13.444] INFO: PixTestPattern:: pg_setup set to default.
[17:00:13.444] INFO: PixTestReadback::RES sent once
[17:00:26.039] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C0.dat
[17:00:26.040] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C1.dat
[17:00:26.040] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C2.dat
[17:00:26.040] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C3.dat
[17:00:26.040] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C4.dat
[17:00:26.040] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C5.dat
[17:00:26.040] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C6.dat
[17:00:26.040] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C7.dat
[17:00:26.041] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C8.dat
[17:00:26.041] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C9.dat
[17:00:26.041] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C10.dat
[17:00:26.041] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C11.dat
[17:00:26.041] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C12.dat
[17:00:26.041] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C13.dat
[17:00:26.041] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C14.dat
[17:00:26.042] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C15.dat
[17:00:26.090] INFO: PixTestPattern:: pg_setup set to default.
[17:00:26.091] INFO: PixTestReadback::RES sent once
[17:00:35.790] INFO: PixTestPattern:: pg_setup set to default.
[17:00:35.791] INFO: Vbg will be calibrated using Vd calibration
[17:00:35.791] INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 152.2calibrated Vbg = 1.23359 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 150.5calibrated Vbg = 1.23351 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 148.1calibrated Vbg = 1.23551 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 149.4calibrated Vbg = 1.24474 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 156.7calibrated Vbg = 1.24381 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 151.6calibrated Vbg = 1.24764 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 154.2calibrated Vbg = 1.24113 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 149.2calibrated Vbg = 1.24608 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 152calibrated Vbg = 1.24991 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 155.4calibrated Vbg = 1.24544 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 150calibrated Vbg = 1.24602 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 152.9calibrated Vbg = 1.24265 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 148.2calibrated Vbg = 1.24345 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 148calibrated Vbg = 1.23497 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 157.4calibrated Vbg = 1.24334 :::*/*/*/*/
[17:00:35.791] INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 159.6calibrated Vbg = 1.24342 :::*/*/*/*/
[17:00:35.794] INFO: PixTestReadback::RES sent once
[17:03:46.183] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C0.dat
[17:03:46.183] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C1.dat
[17:03:46.183] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C2.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C3.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C4.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C5.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C6.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C7.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C8.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C9.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C10.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C11.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C12.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C13.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C14.dat
[17:03:46.184] INFO: write readback calibration parameters into M4080_FullQualification_2015-09-11_11h43m_1441964587/004_Fulltest_p17/readbackCal_C15.dat
[17:03:46.232] INFO: PixTestPattern:: pg_setup set to default.
[17:03:46.234] INFO: PixTestReadback::doTest() done
[17:03:46.248] INFO: enter test to run
[17:03:46.248] INFO: test: BB2 no parameter change
[17:03:46.248] INFO: running: bb2
[17:03:46.250] INFO: ######################################################################
[17:03:46.250] INFO: PixTestBB2Map::doTest() Ntrig = 16, VcalS = 255, PlWidth = 35
[17:03:46.250] INFO: ######################################################################
[17:03:46.251] INFO: ----------------------------------------------------------------------
[17:03:46.251] INFO: PixTestBB2Map::setVana() target Ia = 30 mA/ROC
[17:03:46.252] INFO: ----------------------------------------------------------------------
[17:04:05.853] INFO: PixTestBB2Map::setVana() done, Module Ia 474.3 mA = 29.6438 mA/ROC
[17:04:05.854] INFO: ----------------------------------------------------------------------
[17:04:05.854] INFO: PixTestBB2Map::setVthrCompCalDel()
[17:04:05.854] INFO: ----------------------------------------------------------------------
[17:04:05.000] INFO: Expecting 1048576 events.
[17:04:17.210] ERROR: <datapipe.cc/CheckEventValidity:L480> Channel 0 Number of ROCs (1) != Token Chain Length (8)
[17:04:17.212] ERROR: <datapipe.cc/CheckEventID:L453> Channel 0 Event ID mismatch: local ID (21) != TBM ID (130)
[17:04:27.529] INFO: 1048576 events read in total (20750ms).
[17:04:27.534] INFO: Test took 21671ms.
[17:04:27.984] INFO: PixTestBB2Map::setVthrCompCalDel() done
[17:04:27.984] INFO: CalDel: 136 136 134 137 151 138 137 144 132 132 138 124 122 156 125 123
[17:04:27.984] INFO: VthrComp: 100 122 129 125 113 112 106 122 114 128 113 109 103 103 115 108
[17:04:28.352] INFO: Expecting 8519680 events.
[17:04:59.028] INFO: 1352784 events read in total (29896ms).
[17:05:28.781] INFO: 2693488 events read in total (59649ms).
[17:05:58.496] INFO: 4027424 events read in total (89364ms).
[17:06:28.336] INFO: 5365984 events read in total (119204ms).
[17:06:58.200] INFO: 6712320 events read in total (149068ms).
[17:07:28.133] INFO: 8067760 events read in total (179001ms).
[17:07:38.317] INFO: 8519680 events read in total (189185ms).
[17:07:38.347] INFO: Test took 190341ms.
[17:07:38.960] INFO: Missing Bumps: 5 4 3 0 1 1 0 0 0 5 1 0 2 2 74 0
[17:07:38.960] INFO: Separation Cut: 45.00 26.68 45.00 35.34 35.39 30.53 38.38 32.00 32.80 44.88 37.82 32.48 35.71 39.70 41.49 27.37
[17:07:38.960] INFO: PixTestBB2Map::doTest() done,232 seconds
[17:07:39.257] INFO: enter test to run
[17:07:39.257] INFO: test: q no parameter change
[17:07:39.923] QUIET: Connection to board 74 closed.
[17:07:39.936] INFO: pXar: this is the end, my friend