[12:40:34.422] <TB3> INFO: *** Welcome to pxar ***
[12:40:34.422] <TB3> INFO: *** Today: 2015/08/24
[12:40:34.422] <TB3> INFO: readRocDacs: /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C15.dat
[12:40:34.423] <TB3> INFO: readTbmDacs: /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//tbmParameters_C0b.dat
[12:40:34.423] <TB3> INFO: readMaskFile: /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//defaultMaskFile.dat
[12:40:34.423] <TB3> INFO: readTrimFile: /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters_C15.dat
[12:40:34.499] <TB3> INFO: clk: 4
[12:40:34.499] <TB3> INFO: ctr: 4
[12:40:34.499] <TB3> INFO: sda: 19
[12:40:34.499] <TB3> INFO: tin: 9
[12:40:34.499] <TB3> INFO: level: 15
[12:40:34.499] <TB3> INFO: triggerdelay: 0
[12:40:34.499] <TB3> QUIET: Instanciating API for pxar prod-01+86~g1838649
[12:40:34.499] <TB3> INFO: Log level: INFO
[12:40:34.507] <TB3> INFO: Found DTB DTB_WZ4I6J
[12:40:34.516] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[12:40:34.520] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 170
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WZ4I6J
MAC address: 40D8551180AA
Hostname: pixelDTB170
Comment:
------------------------------------------------------
[12:40:34.522] <TB3> INFO: RPC call hashes of host and DTB match: 447413373
[12:40:36.076] <TB3> INFO: DUT info:
[12:40:36.076] <TB3> INFO: The DUT currently contains the following objects:
[12:40:36.076] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:40:36.076] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:40:36.076] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:40:36.076] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:40:36.076] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.076] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:36.477] <TB3> INFO: enter 'restricted' command line mode
[12:40:36.477] <TB3> INFO: enter test to run
[12:40:36.477] <TB3> INFO: test: pretest no parameter change
[12:40:36.478] <TB3> INFO: running: pretest
[12:40:36.484] <TB3> INFO: ######################################################################
[12:40:36.484] <TB3> INFO: PixTestPretest::doTest()
[12:40:36.484] <TB3> INFO: ######################################################################
[12:40:36.487] <TB3> INFO: ----------------------------------------------------------------------
[12:40:36.487] <TB3> INFO: PixTestPretest::programROC()
[12:40:36.487] <TB3> INFO: ----------------------------------------------------------------------
[12:40:54.505] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[12:40:54.505] <TB3> INFO: IA differences per ROC: 19.3 17.7 19.3 16.9 18.5 18.5 18.5 20.1 18.5 19.3 19.3 18.5 19.3 17.7 19.3 19.3
[12:40:54.578] <TB3> INFO: ----------------------------------------------------------------------
[12:40:54.578] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[12:40:54.578] <TB3> INFO: ----------------------------------------------------------------------
[12:41:02.187] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 379.4 mA = 23.7125 mA/ROC
[12:41:02.190] <TB3> INFO: ----------------------------------------------------------------------
[12:41:02.190] <TB3> INFO: PixTestPretest::findWorkingPixel()
[12:41:02.190] <TB3> INFO: ----------------------------------------------------------------------
[12:41:10.414] <TB3> INFO: Test took 8218ms.
[12:41:10.715] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[12:41:10.755] <TB3> INFO: ----------------------------------------------------------------------
[12:41:10.755] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[12:41:10.755] <TB3> INFO: ----------------------------------------------------------------------
[12:41:18.921] <TB3> INFO: Test took 8159ms.
[12:41:19.231] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[12:41:19.231] <TB3> INFO: CalDel: 150 128 135 113 152 124 123 117 130 142 166 145 155 120 160 138
[12:41:19.231] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[12:41:19.235] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C0.dat
[12:41:19.235] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C1.dat
[12:41:19.235] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C2.dat
[12:41:19.236] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C3.dat
[12:41:19.236] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C4.dat
[12:41:19.236] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C5.dat
[12:41:19.236] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C6.dat
[12:41:19.237] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C7.dat
[12:41:19.237] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C8.dat
[12:41:19.237] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C9.dat
[12:41:19.237] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C10.dat
[12:41:19.238] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C11.dat
[12:41:19.238] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C12.dat
[12:41:19.238] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C13.dat
[12:41:19.238] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C14.dat
[12:41:19.238] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C15.dat
[12:41:19.239] <TB3> INFO: write tbm parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//tbmParameters_C0a.dat
[12:41:19.239] <TB3> INFO: write tbm parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//tbmParameters_C0b.dat
[12:41:19.239] <TB3> INFO: PixTestPretest::doTest() done, duration: 42 seconds
[12:41:19.333] <TB3> INFO: enter test to run
[12:41:19.333] <TB3> INFO: test: fulltest no parameter change
[12:41:19.333] <TB3> INFO: running: fulltest
[12:41:19.333] <TB3> INFO: ######################################################################
[12:41:19.333] <TB3> INFO: PixTestFullTest::doTest()
[12:41:19.333] <TB3> INFO: ######################################################################
[12:41:19.334] <TB3> INFO: ######################################################################
[12:41:19.334] <TB3> INFO: PixTestAlive::doTest()
[12:41:19.334] <TB3> INFO: ######################################################################
[12:41:19.336] <TB3> INFO: ----------------------------------------------------------------------
[12:41:19.336] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:41:19.336] <TB3> INFO: ----------------------------------------------------------------------
[12:41:22.780] <TB3> INFO: Test took 3441ms.
[12:41:22.801] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:23.031] <TB3> INFO: PixTestAlive::aliveTest() done
[12:41:23.031] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[12:41:23.033] <TB3> INFO: ----------------------------------------------------------------------
[12:41:23.033] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:41:23.033] <TB3> INFO: ----------------------------------------------------------------------
[12:41:25.783] <TB3> INFO: Test took 2748ms.
[12:41:25.786] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:25.787] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[12:41:26.020] <TB3> INFO: PixTestAlive::maskTest() done
[12:41:26.020] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:41:26.021] <TB3> INFO: ----------------------------------------------------------------------
[12:41:26.021] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:41:26.021] <TB3> INFO: ----------------------------------------------------------------------
[12:41:29.460] <TB3> INFO: Test took 3437ms.
[12:41:29.484] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:29.717] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[12:41:29.717] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:41:29.717] <TB3> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[12:41:29.729] <TB3> INFO: ######################################################################
[12:41:29.729] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[12:41:29.729] <TB3> INFO: ######################################################################
[12:41:29.732] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[12:41:29.746] <TB3> INFO: dacScan step from 0 .. 29
[12:41:29.746] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:41:29.746] <TB3> INFO: run 1 of 1
[12:41:51.020] <TB3> INFO: Test took 21274ms.
[12:41:51.055] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:51.055] <TB3> INFO: dacScan step from 30 .. 59
[12:41:51.055] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:41:51.055] <TB3> INFO: run 1 of 1
[12:42:13.327] <TB3> INFO: Test took 22272ms.
[12:42:13.406] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:13.416] <TB3> INFO: dacScan step from 60 .. 89
[12:42:13.416] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:42:13.416] <TB3> INFO: run 1 of 1
[12:42:41.673] <TB3> INFO: Test took 28257ms.
[12:42:41.924] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:41.964] <TB3> INFO: dacScan step from 90 .. 119
[12:42:41.964] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:42:41.964] <TB3> INFO: run 1 of 1
[12:43:10.870] <TB3> INFO: Test took 28906ms.
[12:43:11.122] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:11.166] <TB3> INFO: dacScan step from 120 .. 149
[12:43:11.166] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:43:11.166] <TB3> INFO: run 1 of 1
[12:43:34.965] <TB3> INFO: Test took 23799ms.
[12:43:35.143] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:58.365] <TB3> INFO: PixTestBBMap::doTest() done, duration: 148 seconds
[12:43:58.365] <TB3> INFO: number of dead bumps (per ROC): 9 0 0 0 0 0 0 0 0 1 2 4 6 0 2 12
[12:43:58.365] <TB3> INFO: separation cut (per ROC): 76 104 102 97 98 96 98 96 74 93 87 91 76 94 90 98
[12:43:58.434] <TB3> INFO: ######################################################################
[12:43:58.434] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = 4, ntrig/step = 50
[12:43:58.434] <TB3> INFO: ######################################################################
[12:43:58.434] <TB3> INFO: ----------------------------------------------------------------------
[12:43:58.434] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = 4, ntrig/step = 50
[12:43:58.434] <TB3> INFO: ----------------------------------------------------------------------
[12:43:58.434] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4/50) hits flags = 16 (plus default)
[12:43:58.442] <TB3> INFO: dacScan step from 0 .. 3
[12:43:58.442] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:43:58.442] <TB3> INFO: run 1 of 1
[12:44:08.323] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[12:44:08.323] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 14 readouts!
[12:44:08.323] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[12:44:08.323] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[12:44:08.323] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[12:44:08.323] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[12:44:08.323] <TB3> WARNING: Channel 1 ROC 0: Readback start marker after 2 readouts!
[12:44:08.323] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[12:44:15.864] <TB3> INFO: Test took 17422ms.
[12:44:15.889] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:15.889] <TB3> INFO: dacScan step from 4 .. 7
[12:44:15.889] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:44:15.889] <TB3> INFO: run 1 of 1
[12:44:34.790] <TB3> INFO: Test took 18901ms.
[12:44:34.818] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:34.818] <TB3> INFO: dacScan step from 8 .. 11
[12:44:34.818] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:44:34.818] <TB3> INFO: run 1 of 1
[12:44:53.837] <TB3> INFO: Test took 19019ms.
[12:44:53.872] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:53.872] <TB3> INFO: dacScan step from 12 .. 15
[12:44:53.872] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:44:53.872] <TB3> INFO: run 1 of 1
[12:45:12.785] <TB3> INFO: Test took 18913ms.
[12:45:12.811] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:12.811] <TB3> INFO: dacScan step from 16 .. 19
[12:45:12.811] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:45:12.811] <TB3> INFO: run 1 of 1
[12:45:31.894] <TB3> INFO: Test took 19083ms.
[12:45:31.920] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:31.920] <TB3> INFO: dacScan step from 20 .. 23
[12:45:31.920] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:45:31.920] <TB3> INFO: run 1 of 1
[12:45:50.976] <TB3> INFO: Test took 19056ms.
[12:45:51.001] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:51.001] <TB3> INFO: dacScan step from 24 .. 27
[12:45:51.001] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:45:51.001] <TB3> INFO: run 1 of 1
[12:46:09.938] <TB3> INFO: Test took 18936ms.
[12:46:09.968] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:09.968] <TB3> INFO: dacScan step from 28 .. 31
[12:46:09.968] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:46:09.968] <TB3> INFO: run 1 of 1
[12:46:28.866] <TB3> INFO: Test took 18898ms.
[12:46:28.898] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:28.898] <TB3> INFO: dacScan step from 32 .. 35
[12:46:28.898] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:46:28.898] <TB3> INFO: run 1 of 1
[12:46:47.797] <TB3> INFO: Test took 18899ms.
[12:46:47.826] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:47.826] <TB3> INFO: dacScan step from 36 .. 39
[12:46:47.826] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:46:47.826] <TB3> INFO: run 1 of 1
[12:47:06.780] <TB3> INFO: Test took 18954ms.
[12:47:06.810] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:06.810] <TB3> INFO: dacScan step from 40 .. 43
[12:47:06.810] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:47:06.810] <TB3> INFO: run 1 of 1
[12:47:25.692] <TB3> INFO: Test took 18882ms.
[12:47:25.718] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:25.718] <TB3> INFO: dacScan step from 44 .. 47
[12:47:25.718] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:47:25.718] <TB3> INFO: run 1 of 1
[12:47:44.831] <TB3> INFO: Test took 19113ms.
[12:47:44.861] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:44.861] <TB3> INFO: dacScan step from 48 .. 51
[12:47:44.861] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:47:44.861] <TB3> INFO: run 1 of 1
[12:48:03.867] <TB3> INFO: Test took 19006ms.
[12:48:03.896] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:03.896] <TB3> INFO: dacScan step from 52 .. 55
[12:48:03.897] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:48:03.897] <TB3> INFO: run 1 of 1
[12:48:22.871] <TB3> INFO: Test took 18974ms.
[12:48:22.901] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:22.901] <TB3> INFO: dacScan step from 56 .. 59
[12:48:22.901] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:48:22.901] <TB3> INFO: run 1 of 1
[12:48:41.814] <TB3> INFO: Test took 18913ms.
[12:48:41.840] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:41.840] <TB3> INFO: dacScan step from 60 .. 63
[12:48:41.840] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:48:41.840] <TB3> INFO: run 1 of 1
[12:49:00.702] <TB3> INFO: Test took 18862ms.
[12:49:00.729] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:00.729] <TB3> INFO: dacScan step from 64 .. 67
[12:49:00.729] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:49:00.729] <TB3> INFO: run 1 of 1
[12:49:19.614] <TB3> INFO: Test took 18885ms.
[12:49:19.643] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:19.643] <TB3> INFO: dacScan step from 68 .. 71
[12:49:19.643] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:49:19.643] <TB3> INFO: run 1 of 1
[12:49:38.694] <TB3> INFO: Test took 19051ms.
[12:49:38.727] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:38.728] <TB3> INFO: dacScan step from 72 .. 75
[12:49:38.728] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:49:38.728] <TB3> INFO: run 1 of 1
[12:49:57.829] <TB3> INFO: Test took 19101ms.
[12:49:57.863] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:57.863] <TB3> INFO: dacScan step from 76 .. 79
[12:49:57.863] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:49:57.863] <TB3> INFO: run 1 of 1
[12:50:17.143] <TB3> INFO: Test took 19280ms.
[12:50:17.184] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:17.185] <TB3> INFO: dacScan step from 80 .. 83
[12:50:17.185] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:50:17.185] <TB3> INFO: run 1 of 1
[12:50:37.319] <TB3> INFO: Test took 20133ms.
[12:50:37.396] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:37.399] <TB3> INFO: dacScan step from 84 .. 87
[12:50:37.399] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:50:37.399] <TB3> INFO: run 1 of 1
[12:50:58.791] <TB3> INFO: Test took 21392ms.
[12:50:58.901] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:58.908] <TB3> INFO: dacScan step from 88 .. 91
[12:50:58.908] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:50:58.908] <TB3> INFO: run 1 of 1
[12:51:21.550] <TB3> INFO: Test took 22642ms.
[12:51:21.696] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:21.704] <TB3> INFO: dacScan step from 92 .. 95
[12:51:21.704] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:51:21.704] <TB3> INFO: run 1 of 1
[12:51:46.245] <TB3> INFO: Test took 24541ms.
[12:51:46.440] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:46.450] <TB3> INFO: dacScan step from 96 .. 99
[12:51:46.450] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:51:46.450] <TB3> INFO: run 1 of 1
[12:52:12.720] <TB3> INFO: Test took 26270ms.
[12:52:12.931] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:12.941] <TB3> INFO: dacScan step from 100 .. 103
[12:52:12.941] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:52:12.942] <TB3> INFO: run 1 of 1
[12:52:40.070] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:52:40.070] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:52:40.423] <TB3> INFO: Test took 27481ms.
[12:52:40.645] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:40.658] <TB3> INFO: dacScan step from 104 .. 107
[12:52:40.658] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:52:40.658] <TB3> INFO: run 1 of 1
[12:53:08.117] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (207) != TBM ID (0)
[12:53:08.117] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[12:53:08.117] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (1) != TBM ID (208)
[12:53:08.891] <TB3> INFO: Test took 28233ms.
[12:53:09.121] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:09.131] <TB3> INFO: dacScan step from 108 .. 111
[12:53:09.131] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:53:09.131] <TB3> INFO: run 1 of 1
[12:53:36.750] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:53:36.750] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:53:37.911] <TB3> INFO: Test took 28780ms.
[12:53:38.145] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:38.154] <TB3> INFO: dacScan step from 112 .. 115
[12:53:38.154] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:53:38.154] <TB3> INFO: run 1 of 1
[12:54:05.844] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:54:05.844] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:54:06.926] <TB3> INFO: Test took 28771ms.
[12:54:07.152] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:07.162] <TB3> INFO: dacScan step from 116 .. 119
[12:54:07.162] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:54:07.162] <TB3> INFO: run 1 of 1
[12:54:32.968] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:54:32.968] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:54:34.223] <TB3> INFO: Test took 27061ms.
[12:54:34.457] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:34.466] <TB3> INFO: dacScan step from 120 .. 123
[12:54:34.466] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:54:34.466] <TB3> INFO: run 1 of 1
[12:55:01.015] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[12:55:02.141] <TB3> INFO: Test took 27675ms.
[12:55:02.403] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:02.419] <TB3> INFO: dacScan step from 124 .. 127
[12:55:02.419] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:55:02.420] <TB3> INFO: run 1 of 1
[12:55:28.052] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[12:55:28.052] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (197) != TBM ID (198)
[12:55:28.052] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[12:55:28.052] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[12:55:28.052] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:55:29.161] <TB3> INFO: Test took 26741ms.
[12:55:29.388] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:29.402] <TB3> INFO: dacScan step from 128 .. 131
[12:55:29.402] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:55:29.402] <TB3> INFO: run 1 of 1
[12:55:55.262] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[12:55:55.262] <TB3> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (195) != TBM ID (196)
[12:55:55.262] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[12:55:55.262] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[12:55:55.262] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:55:56.562] <TB3> INFO: Test took 27160ms.
[12:55:56.798] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:56.808] <TB3> INFO: dacScan step from 132 .. 135
[12:55:56.808] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:55:56.808] <TB3> INFO: run 1 of 1
[12:56:25.698] <TB3> INFO: Test took 28890ms.
[12:56:25.920] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:25.929] <TB3> INFO: dacScan step from 136 .. 139
[12:56:25.929] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:56:25.929] <TB3> INFO: run 1 of 1
[12:56:55.151] <TB3> INFO: Test took 29222ms.
[12:56:55.368] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:55.377] <TB3> INFO: dacScan step from 140 .. 143
[12:56:55.377] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:56:55.377] <TB3> INFO: run 1 of 1
[12:57:24.449] <TB3> INFO: Test took 29072ms.
[12:57:24.682] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:24.691] <TB3> INFO: dacScan step from 144 .. 147
[12:57:24.691] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:57:24.691] <TB3> INFO: run 1 of 1
[12:57:54.021] <TB3> INFO: Test took 29330ms.
[12:57:54.268] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:54.277] <TB3> INFO: dacScan step from 148 .. 149
[12:57:54.277] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:57:54.277] <TB3> INFO: run 1 of 1
[12:58:10.329] <TB3> INFO: Test took 16052ms.
[12:58:10.469] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:10.476] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:12.087] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:13.490] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:14.891] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:16.593] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:18.280] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:19.760] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:21.231] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:22.695] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:24.180] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:25.887] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:27.648] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:29.269] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:30.779] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:32.249] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:33.895] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:58:35.553] <TB3> INFO: PixTestScurves::scurves() done
[12:58:35.553] <TB3> INFO: Vcal mean: 96.00 112.49 104.86 89.27 87.66 99.84 103.68 95.42 82.94 92.33 88.35 100.41 89.24 93.68 92.62 100.41
[12:58:35.553] <TB3> INFO: Vcal RMS: 6.18 6.22 5.65 5.63 5.95 5.56 6.24 5.15 4.46 6.07 5.03 5.22 5.43 5.46 5.34 6.64
[12:58:35.553] <TB3> INFO: PixTestScurves::fullTest() done, duration: 877 seconds
[12:58:35.636] <TB3> INFO: ######################################################################
[12:58:35.636] <TB3> INFO: PixTestTrim::doTest()
[12:58:35.636] <TB3> INFO: ######################################################################
[12:58:35.638] <TB3> INFO: ----------------------------------------------------------------------
[12:58:35.638] <TB3> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[12:58:35.638] <TB3> INFO: ----------------------------------------------------------------------
[12:58:35.736] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:58:35.736] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[12:58:35.745] <TB3> INFO: dacScan step from 0 .. 19
[12:58:35.745] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:58:35.745] <TB3> INFO: run 1 of 1
[12:58:50.181] <TB3> INFO: Test took 14436ms.
[12:58:50.202] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:50.202] <TB3> INFO: dacScan step from 20 .. 39
[12:58:50.202] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:58:50.202] <TB3> INFO: run 1 of 1
[12:59:05.312] <TB3> INFO: Test took 15110ms.
[12:59:05.334] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:05.334] <TB3> INFO: dacScan step from 40 .. 59
[12:59:05.334] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:59:05.334] <TB3> INFO: run 1 of 1
[12:59:20.382] <TB3> INFO: Test took 15048ms.
[12:59:20.405] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:20.405] <TB3> INFO: dacScan step from 60 .. 79
[12:59:20.405] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:59:20.405] <TB3> INFO: run 1 of 1
[12:59:35.358] <TB3> INFO: Test took 14953ms.
[12:59:35.382] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:35.382] <TB3> INFO: dacScan step from 80 .. 99
[12:59:35.382] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:59:35.382] <TB3> INFO: run 1 of 1
[12:59:50.537] <TB3> INFO: Test took 15155ms.
[12:59:50.584] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:50.590] <TB3> INFO: dacScan step from 100 .. 119
[12:59:50.590] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:59:50.590] <TB3> INFO: run 1 of 1
[13:00:08.142] <TB3> INFO: Test took 17552ms.
[13:00:08.303] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:08.329] <TB3> INFO: dacScan step from 120 .. 139
[13:00:08.329] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:00:08.329] <TB3> INFO: run 1 of 1
[13:00:26.924] <TB3> INFO: Test took 18595ms.
[13:00:27.097] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:27.128] <TB3> INFO: dacScan step from 140 .. 159
[13:00:27.128] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:00:27.128] <TB3> INFO: run 1 of 1
[13:00:43.088] <TB3> INFO: Test took 15960ms.
[13:00:43.144] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:06.156] <TB3> INFO: ROC 0 VthrComp = 87
[13:01:06.157] <TB3> INFO: ROC 1 VthrComp = 103
[13:01:06.157] <TB3> INFO: ROC 2 VthrComp = 103
[13:01:06.157] <TB3> INFO: ROC 3 VthrComp = 89
[13:01:06.157] <TB3> INFO: ROC 4 VthrComp = 87
[13:01:06.157] <TB3> INFO: ROC 5 VthrComp = 99
[13:01:06.157] <TB3> INFO: ROC 6 VthrComp = 100
[13:01:06.157] <TB3> INFO: ROC 7 VthrComp = 96
[13:01:06.157] <TB3> INFO: ROC 8 VthrComp = 85
[13:01:06.157] <TB3> INFO: ROC 9 VthrComp = 91
[13:01:06.157] <TB3> INFO: ROC 10 VthrComp = 89
[13:01:06.158] <TB3> INFO: ROC 11 VthrComp = 98
[13:01:06.158] <TB3> INFO: ROC 12 VthrComp = 85
[13:01:06.158] <TB3> INFO: ROC 13 VthrComp = 95
[13:01:06.158] <TB3> INFO: ROC 14 VthrComp = 90
[13:01:06.158] <TB3> INFO: ROC 15 VthrComp = 95
[13:01:06.158] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[13:01:06.158] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[13:01:06.167] <TB3> INFO: dacScan step from 0 .. 19
[13:01:06.167] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:01:06.167] <TB3> INFO: run 1 of 1
[13:01:20.730] <TB3> INFO: Test took 14562ms.
[13:01:20.750] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:20.750] <TB3> INFO: dacScan step from 20 .. 39
[13:01:20.750] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:01:20.750] <TB3> INFO: run 1 of 1
[13:01:35.647] <TB3> INFO: Test took 14897ms.
[13:01:35.681] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:35.683] <TB3> INFO: dacScan step from 40 .. 59
[13:01:35.683] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:01:35.683] <TB3> INFO: run 1 of 1
[13:01:54.197] <TB3> INFO: Test took 18514ms.
[13:01:54.363] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:54.395] <TB3> INFO: dacScan step from 60 .. 79
[13:01:54.395] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:01:54.395] <TB3> INFO: run 1 of 1
[13:02:14.611] <TB3> INFO: Test took 20216ms.
[13:02:14.779] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:14.809] <TB3> INFO: dacScan step from 80 .. 99
[13:02:14.809] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:02:14.809] <TB3> INFO: run 1 of 1
[13:02:33.603] <TB3> INFO: Test took 18793ms.
[13:02:33.781] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:33.817] <TB3> INFO: dacScan step from 100 .. 119
[13:02:33.817] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:02:33.817] <TB3> INFO: run 1 of 1
[13:02:53.734] <TB3> INFO: Test took 19917ms.
[13:02:53.903] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:53.934] <TB3> INFO: dacScan step from 120 .. 139
[13:02:53.934] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:02:53.934] <TB3> INFO: run 1 of 1
[13:03:14.061] <TB3> INFO: Test took 20127ms.
[13:03:14.260] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:14.299] <TB3> INFO: dacScan step from 140 .. 159
[13:03:14.299] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:03:14.299] <TB3> INFO: run 1 of 1
[13:03:34.630] <TB3> INFO: Test took 20331ms.
[13:03:34.821] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:00.537] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 65.1659 for pixel 12/0 mean/min/max = 48.8061/32.2442/65.3681
[13:04:00.538] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 65.7501 for pixel 46/9 mean/min/max = 49.2803/32.2323/66.3284
[13:04:00.538] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 60.4621 for pixel 2/1 mean/min/max = 46.2785/32.0892/60.4678
[13:04:00.538] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 59.2396 for pixel 0/55 mean/min/max = 46.1921/32.8805/59.5038
[13:04:00.539] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 60.4861 for pixel 0/32 mean/min/max = 45.9077/31.1813/60.634
[13:04:00.539] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 58.0989 for pixel 0/71 mean/min/max = 45.1296/32.14/58.1192
[13:04:00.539] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 62.8193 for pixel 17/79 mean/min/max = 47.4752/32.0498/62.9006
[13:04:00.539] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 57.382 for pixel 16/79 mean/min/max = 44.7795/32.1295/57.4294
[13:04:00.540] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 57.2572 for pixel 0/3 mean/min/max = 45.1751/32.8943/57.456
[13:04:00.540] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 61.5828 for pixel 11/68 mean/min/max = 47.0743/32.5454/61.6032
[13:04:00.540] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 58.1091 for pixel 11/22 mean/min/max = 46.1493/34.1759/58.1227
[13:04:00.540] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 58.3569 for pixel 0/58 mean/min/max = 45.2526/31.8345/58.6707
[13:04:00.541] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 61.127 for pixel 24/2 mean/min/max = 46.7658/32.2719/61.2598
[13:04:00.541] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 57.9744 for pixel 17/77 mean/min/max = 45.0002/31.9946/58.0057
[13:04:00.541] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 60.8663 for pixel 8/1 mean/min/max = 47.517/34.0689/60.965
[13:04:00.541] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 62.6278 for pixel 8/78 mean/min/max = 47.176/31.6051/62.747
[13:04:00.542] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:05:31.758] <TB3> INFO: Test took 91216ms.
[13:05:33.055] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[13:05:33.064] <TB3> INFO: dacScan step from 0 .. 19
[13:05:33.064] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:05:33.064] <TB3> INFO: run 1 of 2
[13:05:47.980] <TB3> INFO: Test took 14916ms.
[13:05:48.013] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:48.015] <TB3> INFO: run 2 of 2
[13:06:03.198] <TB3> INFO: Test took 15183ms.
[13:06:03.231] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:03.233] <TB3> INFO: dacScan step from 20 .. 39
[13:06:03.233] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:06:03.233] <TB3> INFO: run 1 of 2
[13:06:21.367] <TB3> INFO: Test took 18134ms.
[13:06:21.515] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:21.541] <TB3> INFO: run 2 of 2
[13:06:39.688] <TB3> INFO: Test took 18147ms.
[13:06:39.827] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:39.855] <TB3> INFO: dacScan step from 40 .. 59
[13:06:39.855] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:06:39.855] <TB3> INFO: run 1 of 2
[13:07:00.148] <TB3> INFO: Test took 20293ms.
[13:07:00.344] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:00.378] <TB3> INFO: run 2 of 2
[13:07:20.582] <TB3> INFO: Test took 20204ms.
[13:07:20.781] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:20.814] <TB3> INFO: dacScan step from 60 .. 79
[13:07:20.814] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:07:20.814] <TB3> INFO: run 1 of 2
[13:07:40.971] <TB3> INFO: Test took 20157ms.
[13:07:41.137] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:41.167] <TB3> INFO: run 2 of 2
[13:08:01.341] <TB3> INFO: Test took 20174ms.
[13:08:01.511] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:01.541] <TB3> INFO: dacScan step from 80 .. 99
[13:08:01.541] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:08:01.541] <TB3> INFO: run 1 of 2
[13:08:21.905] <TB3> INFO: Test took 20364ms.
[13:08:22.069] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:22.098] <TB3> INFO: run 2 of 2
[13:08:42.315] <TB3> INFO: Test took 20217ms.
[13:08:42.499] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:42.533] <TB3> INFO: dacScan step from 100 .. 119
[13:08:42.533] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:08:42.533] <TB3> INFO: run 1 of 2
[13:09:02.708] <TB3> INFO: Test took 20175ms.
[13:09:02.875] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:02.906] <TB3> INFO: run 2 of 2
[13:09:23.117] <TB3> INFO: Test took 20211ms.
[13:09:23.281] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:23.310] <TB3> INFO: dacScan step from 120 .. 139
[13:09:23.310] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:09:23.310] <TB3> INFO: run 1 of 2
[13:09:43.581] <TB3> INFO: Test took 20271ms.
[13:09:43.761] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:43.795] <TB3> INFO: run 2 of 2
[13:10:04.083] <TB3> INFO: Test took 20288ms.
[13:10:04.257] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:04.286] <TB3> INFO: dacScan step from 140 .. 159
[13:10:04.286] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:10:04.286] <TB3> INFO: run 1 of 2
[13:10:24.649] <TB3> INFO: Test took 20363ms.
[13:10:24.822] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:24.855] <TB3> INFO: run 2 of 2
[13:10:45.178] <TB3> INFO: Test took 20324ms.
[13:10:45.363] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:45.397] <TB3> INFO: dacScan step from 160 .. 179
[13:10:45.397] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:10:45.397] <TB3> INFO: run 1 of 2
[13:11:05.785] <TB3> INFO: Test took 20388ms.
[13:11:05.955] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:05.993] <TB3> INFO: run 2 of 2
[13:11:26.480] <TB3> INFO: Test took 20487ms.
[13:11:26.653] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:26.686] <TB3> INFO: dacScan step from 180 .. 199
[13:11:26.686] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:11:26.686] <TB3> INFO: run 1 of 2
[13:11:47.924] <TB3> INFO: Test took 21238ms.
[13:11:48.092] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:48.127] <TB3> INFO: run 2 of 2
[13:12:09.289] <TB3> INFO: Test took 21162ms.
[13:12:09.461] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:35.881] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 0.024404 .. 255.000000
[13:12:35.966] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[13:12:35.974] <TB3> INFO: dacScan step from 0 .. 19
[13:12:35.974] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:12:35.974] <TB3> INFO: run 1 of 1
[13:12:48.924] <TB3> INFO: Test took 12950ms.
[13:12:48.943] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:48.943] <TB3> INFO: dacScan step from 20 .. 39
[13:12:48.943] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:12:48.943] <TB3> INFO: run 1 of 1
[13:13:03.397] <TB3> INFO: Test took 14454ms.
[13:13:03.474] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:03.489] <TB3> INFO: dacScan step from 40 .. 59
[13:13:03.489] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:13:03.489] <TB3> INFO: run 1 of 1
[13:13:19.903] <TB3> INFO: Test took 16414ms.
[13:13:20.051] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:20.085] <TB3> INFO: dacScan step from 60 .. 79
[13:13:20.086] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:13:20.086] <TB3> INFO: run 1 of 1
[13:13:37.557] <TB3> INFO: Test took 17471ms.
[13:13:37.700] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:37.731] <TB3> INFO: dacScan step from 80 .. 99
[13:13:37.731] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:13:37.731] <TB3> INFO: run 1 of 1
[13:13:55.380] <TB3> INFO: Test took 17649ms.
[13:13:55.517] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:55.548] <TB3> INFO: dacScan step from 100 .. 119
[13:13:55.548] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:13:55.548] <TB3> INFO: run 1 of 1
[13:14:13.403] <TB3> INFO: Test took 17855ms.
[13:14:13.555] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:13.587] <TB3> INFO: dacScan step from 120 .. 139
[13:14:13.587] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:14:13.587] <TB3> INFO: run 1 of 1
[13:14:31.318] <TB3> INFO: Test took 17731ms.
[13:14:31.473] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:31.507] <TB3> INFO: dacScan step from 140 .. 159
[13:14:31.507] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:14:31.507] <TB3> INFO: run 1 of 1
[13:14:48.072] <TB3> INFO: Test took 16565ms.
[13:14:48.228] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:48.266] <TB3> INFO: dacScan step from 160 .. 179
[13:14:48.266] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:14:48.266] <TB3> INFO: run 1 of 1
[13:15:04.941] <TB3> INFO: Test took 16675ms.
[13:15:05.090] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:05.125] <TB3> INFO: dacScan step from 180 .. 199
[13:15:05.125] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:15:05.125] <TB3> INFO: run 1 of 1
[13:15:23.695] <TB3> INFO: Test took 18570ms.
[13:15:23.839] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:23.869] <TB3> INFO: dacScan step from 200 .. 219
[13:15:23.869] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:15:23.869] <TB3> INFO: run 1 of 1
[13:15:41.539] <TB3> INFO: Test took 17669ms.
[13:15:41.678] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:41.709] <TB3> INFO: dacScan step from 220 .. 239
[13:15:41.709] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:15:41.709] <TB3> INFO: run 1 of 1
[13:15:59.301] <TB3> INFO: Test took 17592ms.
[13:15:59.438] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:59.469] <TB3> INFO: dacScan step from 240 .. 255
[13:15:59.469] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:15:59.469] <TB3> INFO: run 1 of 1
[13:16:14.150] <TB3> INFO: Test took 14681ms.
[13:16:14.263] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:45.619] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 13.294528 .. 66.681795
[13:16:45.704] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 3 .. 76 (20/-1) hits flags = 16 (plus default)
[13:16:45.713] <TB3> INFO: dacScan step from 3 .. 22
[13:16:45.713] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:16:45.713] <TB3> INFO: run 1 of 1
[13:16:58.652] <TB3> INFO: Test took 12939ms.
[13:16:58.671] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:58.671] <TB3> INFO: dacScan step from 23 .. 42
[13:16:58.671] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:16:58.671] <TB3> INFO: run 1 of 1
[13:17:13.528] <TB3> INFO: Test took 14856ms.
[13:17:13.627] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:13.650] <TB3> INFO: dacScan step from 43 .. 62
[13:17:13.650] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:17:13.650] <TB3> INFO: run 1 of 1
[13:17:30.105] <TB3> INFO: Test took 16456ms.
[13:17:30.246] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:30.283] <TB3> INFO: dacScan step from 63 .. 76
[13:17:30.283] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:17:30.284] <TB3> INFO: run 1 of 1
[13:17:42.664] <TB3> INFO: Test took 12380ms.
[13:17:42.758] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:01.514] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 1.500000 .. 66.681795
[13:18:01.612] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 76 (20/-1) hits flags = 16 (plus default)
[13:18:01.621] <TB3> INFO: dacScan step from 1 .. 20
[13:18:01.621] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:18:01.621] <TB3> INFO: run 1 of 1
[13:18:15.063] <TB3> INFO: Test took 13442ms.
[13:18:15.082] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:15.082] <TB3> INFO: dacScan step from 21 .. 40
[13:18:15.082] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:18:15.082] <TB3> INFO: run 1 of 1
[13:18:29.586] <TB3> INFO: Test took 14504ms.
[13:18:29.666] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:29.684] <TB3> INFO: dacScan step from 41 .. 60
[13:18:29.684] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:18:29.684] <TB3> INFO: run 1 of 1
[13:18:46.227] <TB3> INFO: Test took 16543ms.
[13:18:46.372] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:46.423] <TB3> INFO: dacScan step from 61 .. 76
[13:18:46.423] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:18:46.423] <TB3> INFO: run 1 of 1
[13:19:00.198] <TB3> INFO: Test took 13775ms.
[13:19:00.311] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:19.722] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 0.500008 .. 66.681795
[13:19:19.805] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 76 (20/-1) hits flags = 16 (plus default)
[13:19:19.813] <TB3> INFO: dacScan step from 0 .. 19
[13:19:19.814] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:19:19.814] <TB3> INFO: run 1 of 1
[13:19:32.915] <TB3> INFO: Test took 13101ms.
[13:19:32.934] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:32.934] <TB3> INFO: dacScan step from 20 .. 39
[13:19:32.934] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:19:32.934] <TB3> INFO: run 1 of 1
[13:19:47.598] <TB3> INFO: Test took 14664ms.
[13:19:47.669] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:47.686] <TB3> INFO: dacScan step from 40 .. 59
[13:19:47.686] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:19:47.686] <TB3> INFO: run 1 of 1
[13:20:04.906] <TB3> INFO: Test took 17220ms.
[13:20:05.051] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:05.083] <TB3> INFO: dacScan step from 60 .. 76
[13:20:05.083] <TB3> INFO: dacScan split into 1 runs with ntrig = 4
[13:20:05.083] <TB3> INFO: run 1 of 1
[13:20:19.536] <TB3> INFO: Test took 14453ms.
[13:20:19.658] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:37.861] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[13:20:37.861] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[13:20:37.870] <TB3> INFO: dacScan step from 15 .. 34
[13:20:37.870] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:20:37.870] <TB3> INFO: run 1 of 2
[13:20:53.169] <TB3> INFO: Test took 15299ms.
[13:20:53.214] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:53.221] <TB3> INFO: run 2 of 2
[13:21:08.128] <TB3> INFO: Test took 14907ms.
[13:21:08.177] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:08.184] <TB3> INFO: dacScan step from 35 .. 54
[13:21:08.184] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:21:08.184] <TB3> INFO: run 1 of 2
[13:21:28.001] <TB3> INFO: Test took 19817ms.
[13:21:28.167] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:28.198] <TB3> INFO: run 2 of 2
[13:21:47.652] <TB3> INFO: Test took 19454ms.
[13:21:47.903] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:47.940] <TB3> INFO: dacScan step from 55 .. 55
[13:21:47.940] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:21:47.940] <TB3> INFO: run 1 of 2
[13:21:51.583] <TB3> INFO: Test took 3643ms.
[13:21:51.597] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:51.603] <TB3> INFO: run 2 of 2
[13:21:55.250] <TB3> INFO: Test took 3647ms.
[13:21:55.260] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:09.615] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C0.dat
[13:22:09.616] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C1.dat
[13:22:09.616] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C2.dat
[13:22:09.616] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C3.dat
[13:22:09.617] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C4.dat
[13:22:09.617] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C5.dat
[13:22:09.617] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C6.dat
[13:22:09.617] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C7.dat
[13:22:09.618] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C8.dat
[13:22:09.618] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C9.dat
[13:22:09.618] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C10.dat
[13:22:09.618] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C11.dat
[13:22:09.618] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C12.dat
[13:22:09.619] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C13.dat
[13:22:09.619] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C14.dat
[13:22:09.619] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C15.dat
[13:22:09.619] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C0.dat
[13:22:09.630] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C1.dat
[13:22:09.637] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C2.dat
[13:22:09.645] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C3.dat
[13:22:09.652] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C4.dat
[13:22:09.659] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C5.dat
[13:22:09.666] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C6.dat
[13:22:09.673] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C7.dat
[13:22:09.680] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C8.dat
[13:22:09.687] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C9.dat
[13:22:09.694] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C10.dat
[13:22:09.701] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C11.dat
[13:22:09.709] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C12.dat
[13:22:09.717] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C13.dat
[13:22:09.724] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C14.dat
[13:22:09.731] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C15.dat
[13:22:09.737] <TB3> INFO: PixTestTrim::trimTest() done
[13:22:09.737] <TB3> INFO: vtrim: 124 120 110 109 111 101 120 97 94 118 102 98 97 110 100 113
[13:22:09.737] <TB3> INFO: vthrcomp: 87 103 103 89 87 99 100 96 85 91 89 98 85 95 90 95
[13:22:09.737] <TB3> INFO: vcal mean: 34.99 35.13 35.09 35.06 35.02 34.98 35.12 35.05 35.05 35.06 35.12 35.06 35.11 35.02 35.09 35.09
[13:22:09.737] <TB3> INFO: vcal RMS: 1.88 1.35 1.07 1.02 1.03 1.04 1.19 1.05 0.98 1.17 1.01 1.22 1.36 1.04 1.04 1.33
[13:22:09.737] <TB3> INFO: bits mean: 9.59 9.57 9.36 9.70 10.20 9.95 9.80 9.82 9.90 9.90 9.66 10.13 9.72 10.37 9.07 9.67
[13:22:09.737] <TB3> INFO: bits RMS: 2.41 2.40 2.75 2.48 2.48 2.57 2.45 2.63 2.48 2.38 2.35 2.48 2.51 2.38 2.52 2.61
[13:22:09.744] <TB3> INFO: ----------------------------------------------------------------------
[13:22:09.744] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[13:22:09.744] <TB3> INFO: ----------------------------------------------------------------------
[13:22:09.747] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[13:22:09.758] <TB3> INFO: dacScan step from 0 .. 19
[13:22:09.758] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:22:09.758] <TB3> INFO: run 1 of 2
[13:22:24.917] <TB3> INFO: Test took 15159ms.
[13:22:24.945] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:24.945] <TB3> INFO: run 2 of 2
[13:22:40.119] <TB3> INFO: Test took 15173ms.
[13:22:40.144] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:40.144] <TB3> INFO: dacScan step from 20 .. 39
[13:22:40.144] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:22:40.144] <TB3> INFO: run 1 of 2
[13:22:55.216] <TB3> INFO: Test took 15072ms.
[13:22:55.242] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:55.242] <TB3> INFO: run 2 of 2
[13:23:10.400] <TB3> INFO: Test took 15158ms.
[13:23:10.424] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:10.424] <TB3> INFO: dacScan step from 40 .. 59
[13:23:10.424] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:23:10.424] <TB3> INFO: run 1 of 2
[13:23:24.965] <TB3> INFO: Test took 14541ms.
[13:23:24.986] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:24.986] <TB3> INFO: run 2 of 2
[13:23:39.987] <TB3> INFO: Test took 15001ms.
[13:23:40.012] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:40.012] <TB3> INFO: dacScan step from 60 .. 79
[13:23:40.012] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:23:40.012] <TB3> INFO: run 1 of 2
[13:23:55.123] <TB3> INFO: Test took 15111ms.
[13:23:55.150] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:55.150] <TB3> INFO: run 2 of 2
[13:24:09.663] <TB3> INFO: Test took 14513ms.
[13:24:09.687] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:09.688] <TB3> INFO: dacScan step from 80 .. 99
[13:24:09.689] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:24:09.689] <TB3> INFO: run 1 of 2
[13:24:24.014] <TB3> INFO: Test took 14325ms.
[13:24:24.038] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:24.038] <TB3> INFO: run 2 of 2
[13:24:38.409] <TB3> INFO: Test took 14371ms.
[13:24:38.435] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:38.435] <TB3> INFO: dacScan step from 100 .. 119
[13:24:38.435] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:24:38.435] <TB3> INFO: run 1 of 2
[13:24:53.704] <TB3> INFO: Test took 15269ms.
[13:24:53.770] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:53.782] <TB3> INFO: run 2 of 2
[13:25:08.981] <TB3> INFO: Test took 15198ms.
[13:25:09.058] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:09.070] <TB3> INFO: dacScan step from 120 .. 139
[13:25:09.070] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:25:09.070] <TB3> INFO: run 1 of 2
[13:25:27.098] <TB3> INFO: Test took 18027ms.
[13:25:27.350] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:27.427] <TB3> INFO: run 2 of 2
[13:25:46.397] <TB3> INFO: Test took 18970ms.
[13:25:46.577] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:46.606] <TB3> INFO: dacScan step from 140 .. 159
[13:25:46.606] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:25:46.606] <TB3> INFO: run 1 of 2
[13:26:06.783] <TB3> INFO: Test took 20177ms.
[13:26:06.954] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:26:06.986] <TB3> INFO: run 2 of 2
[13:26:27.086] <TB3> INFO: Test took 20100ms.
[13:26:27.281] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:26:27.322] <TB3> INFO: dacScan step from 160 .. 179
[13:26:27.322] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:26:27.322] <TB3> INFO: run 1 of 2
[13:26:47.674] <TB3> INFO: Test took 20352ms.
[13:26:47.842] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:26:47.884] <TB3> INFO: run 2 of 2
[13:27:06.953] <TB3> INFO: Test took 19069ms.
[13:27:07.219] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:27:07.276] <TB3> INFO: dacScan step from 180 .. 199
[13:27:07.276] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:27:07.276] <TB3> INFO: run 1 of 2
[13:27:27.606] <TB3> INFO: Test took 20330ms.
[13:27:27.770] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:27:27.801] <TB3> INFO: run 2 of 2
[13:27:48.975] <TB3> INFO: Test took 21174ms.
[13:27:49.156] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:15.950] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 184 (20/5) hits flags = 16 (plus default)
[13:28:15.959] <TB3> INFO: dacScan step from 0 .. 19
[13:28:15.959] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:28:15.959] <TB3> INFO: run 1 of 2
[13:28:30.947] <TB3> INFO: Test took 14988ms.
[13:28:30.971] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:30.971] <TB3> INFO: run 2 of 2
[13:28:46.112] <TB3> INFO: Test took 15141ms.
[13:28:46.132] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:46.132] <TB3> INFO: dacScan step from 20 .. 39
[13:28:46.132] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:28:46.132] <TB3> INFO: run 1 of 2
[13:29:01.409] <TB3> INFO: Test took 15277ms.
[13:29:01.434] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:01.434] <TB3> INFO: run 2 of 2
[13:29:16.473] <TB3> INFO: Test took 15039ms.
[13:29:16.494] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:16.494] <TB3> INFO: dacScan step from 40 .. 59
[13:29:16.494] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:29:16.494] <TB3> INFO: run 1 of 2
[13:29:31.652] <TB3> INFO: Test took 15159ms.
[13:29:31.680] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:31.680] <TB3> INFO: run 2 of 2
[13:29:45.981] <TB3> INFO: Test took 14301ms.
[13:29:46.003] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:46.003] <TB3> INFO: dacScan step from 60 .. 79
[13:29:46.003] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:29:46.003] <TB3> INFO: run 1 of 2
[13:29:57.818] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 0 Number of ROCs (0) != Token Chain Length (4)
[13:29:57.818] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 10 readouts!
[13:29:57.818] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 1 Number of ROCs (2) != Token Chain Length (4)
[13:29:57.818] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 15 readouts!
[13:29:57.818] <TB3> WARNING: Channel 0 ROC 2: Readback start marker after 15 readouts!
[13:29:57.818] <TB3> WARNING: Channel 0 ROC 3: Readback start marker after 15 readouts!
[13:29:57.818] <TB3> WARNING: Channel 1 ROC 1: Readback start marker after 6 readouts!
[13:29:57.818] <TB3> WARNING: Channel 1 ROC 3: Readback start marker after 15 readouts!
[13:30:00.337] <TB3> INFO: Test took 14334ms.
[13:30:00.357] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:00.357] <TB3> INFO: run 2 of 2
[13:30:15.338] <TB3> INFO: Test took 14981ms.
[13:30:15.363] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:15.363] <TB3> INFO: dacScan step from 80 .. 99
[13:30:15.363] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:30:15.363] <TB3> INFO: run 1 of 2
[13:30:30.674] <TB3> INFO: Test took 15311ms.
[13:30:30.712] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:30.715] <TB3> INFO: run 2 of 2
[13:30:46.021] <TB3> INFO: Test took 15306ms.
[13:30:46.057] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:46.059] <TB3> INFO: dacScan step from 100 .. 119
[13:30:46.059] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:30:46.059] <TB3> INFO: run 1 of 2
[13:31:03.642] <TB3> INFO: Test took 17583ms.
[13:31:03.762] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:03.779] <TB3> INFO: run 2 of 2
[13:31:21.373] <TB3> INFO: Test took 17593ms.
[13:31:21.503] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:21.521] <TB3> INFO: dacScan step from 120 .. 139
[13:31:21.521] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:31:21.521] <TB3> INFO: run 1 of 2
[13:31:41.351] <TB3> INFO: Test took 19830ms.
[13:31:41.518] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:41.547] <TB3> INFO: run 2 of 2
[13:32:01.550] <TB3> INFO: Test took 20003ms.
[13:32:01.733] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:32:01.764] <TB3> INFO: dacScan step from 140 .. 159
[13:32:01.764] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:32:01.764] <TB3> INFO: run 1 of 2
[13:32:21.924] <TB3> INFO: Test took 20160ms.
[13:32:22.091] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:32:22.126] <TB3> INFO: run 2 of 2
[13:32:42.383] <TB3> INFO: Test took 20257ms.
[13:32:42.565] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:32:42.597] <TB3> INFO: dacScan step from 160 .. 179
[13:32:42.597] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:32:42.597] <TB3> INFO: run 1 of 2
[13:33:02.333] <TB3> INFO: Test took 19736ms.
[13:33:02.492] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:02.527] <TB3> INFO: run 2 of 2
[13:33:21.405] <TB3> INFO: Test took 18878ms.
[13:33:21.572] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:21.604] <TB3> INFO: dacScan step from 180 .. 184
[13:33:21.604] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:33:21.604] <TB3> INFO: run 1 of 2
[13:33:28.410] <TB3> INFO: Test took 6806ms.
[13:33:28.450] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:28.463] <TB3> INFO: run 2 of 2
[13:33:35.590] <TB3> INFO: Test took 7127ms.
[13:33:35.639] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:01.919] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 172 (20/5) hits flags = 16 (plus default)
[13:34:01.928] <TB3> INFO: dacScan step from 0 .. 19
[13:34:01.928] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:34:01.928] <TB3> INFO: run 1 of 2
[13:34:17.004] <TB3> INFO: Test took 15076ms.
[13:34:17.027] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:17.027] <TB3> INFO: run 2 of 2
[13:34:31.303] <TB3> INFO: Test took 14276ms.
[13:34:31.323] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:31.323] <TB3> INFO: dacScan step from 20 .. 39
[13:34:31.323] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:34:31.323] <TB3> INFO: run 1 of 2
[13:34:46.361] <TB3> INFO: Test took 15038ms.
[13:34:46.389] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:46.390] <TB3> INFO: run 2 of 2
[13:35:00.983] <TB3> INFO: Test took 14593ms.
[13:35:01.003] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:01.003] <TB3> INFO: dacScan step from 40 .. 59
[13:35:01.003] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:35:01.003] <TB3> INFO: run 1 of 2
[13:35:15.304] <TB3> INFO: Test took 14301ms.
[13:35:15.325] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:15.325] <TB3> INFO: run 2 of 2
[13:35:30.372] <TB3> INFO: Test took 15047ms.
[13:35:30.394] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:30.394] <TB3> INFO: dacScan step from 60 .. 79
[13:35:30.394] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:35:30.394] <TB3> INFO: run 1 of 2
[13:35:45.450] <TB3> INFO: Test took 15056ms.
[13:35:45.473] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:45.473] <TB3> INFO: run 2 of 2
[13:36:00.491] <TB3> INFO: Test took 15018ms.
[13:36:00.513] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:00.513] <TB3> INFO: dacScan step from 80 .. 99
[13:36:00.513] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:36:00.513] <TB3> INFO: run 1 of 2
[13:36:15.776] <TB3> INFO: Test took 15263ms.
[13:36:15.806] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:15.809] <TB3> INFO: run 2 of 2
[13:36:31.116] <TB3> INFO: Test took 15307ms.
[13:36:31.154] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:31.156] <TB3> INFO: dacScan step from 100 .. 119
[13:36:31.156] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:36:31.156] <TB3> INFO: run 1 of 2
[13:36:48.846] <TB3> INFO: Test took 17690ms.
[13:36:48.993] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:49.011] <TB3> INFO: run 2 of 2
[13:37:06.509] <TB3> INFO: Test took 17498ms.
[13:37:06.632] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:06.650] <TB3> INFO: dacScan step from 120 .. 139
[13:37:06.651] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:37:06.651] <TB3> INFO: run 1 of 2
[13:37:26.565] <TB3> INFO: Test took 19914ms.
[13:37:26.757] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:26.785] <TB3> INFO: run 2 of 2
[13:37:46.783] <TB3> INFO: Test took 19997ms.
[13:37:46.952] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:46.981] <TB3> INFO: dacScan step from 140 .. 159
[13:37:46.981] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:37:46.981] <TB3> INFO: run 1 of 2
[13:38:07.232] <TB3> INFO: Test took 20251ms.
[13:38:07.405] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:07.442] <TB3> INFO: run 2 of 2
[13:38:27.612] <TB3> INFO: Test took 20170ms.
[13:38:27.811] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:27.852] <TB3> INFO: dacScan step from 160 .. 172
[13:38:27.852] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:38:27.852] <TB3> INFO: run 1 of 2
[13:38:41.037] <TB3> INFO: Test took 13186ms.
[13:38:41.159] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:41.187] <TB3> INFO: run 2 of 2
[13:38:54.478] <TB3> INFO: Test took 13291ms.
[13:38:54.602] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:18.373] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 168 (20/5) hits flags = 16 (plus default)
[13:39:18.383] <TB3> INFO: dacScan step from 0 .. 19
[13:39:18.383] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:39:18.383] <TB3> INFO: run 1 of 2
[13:39:33.521] <TB3> INFO: Test took 15138ms.
[13:39:33.544] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:33.544] <TB3> INFO: run 2 of 2
[13:39:48.767] <TB3> INFO: Test took 15223ms.
[13:39:48.794] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:48.794] <TB3> INFO: dacScan step from 20 .. 39
[13:39:48.794] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:39:48.794] <TB3> INFO: run 1 of 2
[13:40:03.237] <TB3> INFO: Test took 14443ms.
[13:40:03.257] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:03.257] <TB3> INFO: run 2 of 2
[13:40:17.748] <TB3> INFO: Test took 14491ms.
[13:40:17.775] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:17.775] <TB3> INFO: dacScan step from 40 .. 59
[13:40:17.775] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:40:17.775] <TB3> INFO: run 1 of 2
[13:40:32.156] <TB3> INFO: Test took 14381ms.
[13:40:32.176] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:32.176] <TB3> INFO: run 2 of 2
[13:40:47.356] <TB3> INFO: Test took 15180ms.
[13:40:47.383] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:47.383] <TB3> INFO: dacScan step from 60 .. 79
[13:40:47.383] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:40:47.383] <TB3> INFO: run 1 of 2
[13:41:02.532] <TB3> INFO: Test took 15149ms.
[13:41:02.554] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:02.554] <TB3> INFO: run 2 of 2
[13:41:17.703] <TB3> INFO: Test took 15149ms.
[13:41:17.730] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:17.730] <TB3> INFO: dacScan step from 80 .. 99
[13:41:17.730] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:41:17.730] <TB3> INFO: run 1 of 2
[13:41:33.005] <TB3> INFO: Test took 15275ms.
[13:41:33.041] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:33.043] <TB3> INFO: run 2 of 2
[13:41:48.180] <TB3> INFO: Test took 15137ms.
[13:41:48.213] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:48.214] <TB3> INFO: dacScan step from 100 .. 119
[13:41:48.214] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:41:48.214] <TB3> INFO: run 1 of 2
[13:42:05.742] <TB3> INFO: Test took 17527ms.
[13:42:05.876] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:05.894] <TB3> INFO: run 2 of 2
[13:42:23.646] <TB3> INFO: Test took 17752ms.
[13:42:23.774] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:23.794] <TB3> INFO: dacScan step from 120 .. 139
[13:42:23.795] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:42:23.795] <TB3> INFO: run 1 of 2
[13:42:43.999] <TB3> INFO: Test took 20204ms.
[13:42:44.183] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:44.216] <TB3> INFO: run 2 of 2
[13:43:04.309] <TB3> INFO: Test took 20093ms.
[13:43:04.485] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:04.516] <TB3> INFO: dacScan step from 140 .. 159
[13:43:04.516] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:43:04.516] <TB3> INFO: run 1 of 2
[13:43:24.679] <TB3> INFO: Test took 20163ms.
[13:43:24.849] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:24.879] <TB3> INFO: run 2 of 2
[13:43:44.061] <TB3> INFO: Test took 19182ms.
[13:43:44.249] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:44.288] <TB3> INFO: dacScan step from 160 .. 168
[13:43:44.288] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:43:44.288] <TB3> INFO: run 1 of 2
[13:43:54.324] <TB3> INFO: Test took 10036ms.
[13:43:54.401] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:54.418] <TB3> INFO: run 2 of 2
[13:44:05.088] <TB3> INFO: Test took 10670ms.
[13:44:05.159] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:29.360] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 171 (20/5) hits flags = 16 (plus default)
[13:44:29.369] <TB3> INFO: dacScan step from 0 .. 19
[13:44:29.369] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:44:29.369] <TB3> INFO: run 1 of 2
[13:44:44.467] <TB3> INFO: Test took 15098ms.
[13:44:44.492] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:44.492] <TB3> INFO: run 2 of 2
[13:44:58.951] <TB3> INFO: Test took 14459ms.
[13:44:58.980] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:58.980] <TB3> INFO: dacScan step from 20 .. 39
[13:44:58.980] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:44:58.980] <TB3> INFO: run 1 of 2
[13:45:13.413] <TB3> INFO: Test took 14433ms.
[13:45:13.433] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:13.433] <TB3> INFO: run 2 of 2
[13:45:28.537] <TB3> INFO: Test took 15104ms.
[13:45:28.563] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:28.563] <TB3> INFO: dacScan step from 40 .. 59
[13:45:28.563] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:45:28.563] <TB3> INFO: run 1 of 2
[13:45:43.695] <TB3> INFO: Test took 15132ms.
[13:45:43.722] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:43.722] <TB3> INFO: run 2 of 2
[13:45:58.784] <TB3> INFO: Test took 15062ms.
[13:45:58.809] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:58.809] <TB3> INFO: dacScan step from 60 .. 79
[13:45:58.809] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:45:58.809] <TB3> INFO: run 1 of 2
[13:46:13.550] <TB3> INFO: Test took 14741ms.
[13:46:13.571] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:13.571] <TB3> INFO: run 2 of 2
[13:46:27.832] <TB3> INFO: Test took 14261ms.
[13:46:27.854] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:27.854] <TB3> INFO: dacScan step from 80 .. 99
[13:46:27.854] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:46:27.854] <TB3> INFO: run 1 of 2
[13:46:43.152] <TB3> INFO: Test took 15298ms.
[13:46:43.184] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:43.188] <TB3> INFO: run 2 of 2
[13:46:58.403] <TB3> INFO: Test took 15215ms.
[13:46:58.442] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:58.445] <TB3> INFO: dacScan step from 100 .. 119
[13:46:58.445] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:46:58.445] <TB3> INFO: run 1 of 2
[13:47:16.070] <TB3> INFO: Test took 17625ms.
[13:47:16.190] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:16.208] <TB3> INFO: run 2 of 2
[13:47:33.731] <TB3> INFO: Test took 17523ms.
[13:47:33.856] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:33.874] <TB3> INFO: dacScan step from 120 .. 139
[13:47:33.874] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:47:33.874] <TB3> INFO: run 1 of 2
[13:47:53.953] <TB3> INFO: Test took 20078ms.
[13:47:54.194] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:54.243] <TB3> INFO: run 2 of 2
[13:48:14.144] <TB3> INFO: Test took 19901ms.
[13:48:14.312] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:14.353] <TB3> INFO: dacScan step from 140 .. 159
[13:48:14.353] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:48:14.353] <TB3> INFO: run 1 of 2
[13:48:33.535] <TB3> INFO: Test took 19182ms.
[13:48:33.702] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:33.734] <TB3> INFO: run 2 of 2
[13:48:52.950] <TB3> INFO: Test took 19216ms.
[13:48:53.131] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:53.164] <TB3> INFO: dacScan step from 160 .. 171
[13:48:53.164] <TB3> INFO: dacScan split into 2 runs with ntrig = 5
[13:48:53.164] <TB3> INFO: run 1 of 2
[13:49:06.538] <TB3> INFO: Test took 13374ms.
[13:49:06.644] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:06.664] <TB3> INFO: run 2 of 2
[13:49:19.962] <TB3> INFO: Test took 13297ms.
[13:49:20.057] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:45.391] <TB3> INFO: PixTestTrim::trimBitTest() done
[13:49:45.392] <TB3> INFO: PixTestTrim::doTest() done, duration: 3069 seconds
[13:49:46.084] <TB3> INFO: ######################################################################
[13:49:46.084] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[13:49:46.084] <TB3> INFO: ######################################################################
[13:49:49.426] <TB3> INFO: Test took 3340ms.
[13:49:49.444] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:52.960] <TB3> INFO: Test took 3320ms.
[13:49:53.056] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:56.433] <TB3> INFO: Test took 3363ms.
[13:49:56.493] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:56.500] <TB3> INFO: The DUT currently contains the following objects:
[13:49:56.500] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:49:56.500] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:49:56.500] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:49:56.500] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:49:56.500] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:56.500] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.601] <TB3> INFO: Test took 1101ms.
[13:49:57.602] <TB3> INFO: The DUT currently contains the following objects:
[13:49:57.602] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:49:57.602] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:49:57.602] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:49:57.602] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:49:57.602] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:57.602] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.703] <TB3> INFO: Test took 1101ms.
[13:49:58.704] <TB3> INFO: The DUT currently contains the following objects:
[13:49:58.704] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:49:58.704] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:49:58.704] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:49:58.704] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:49:58.704] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:58.704] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.804] <TB3> INFO: Test took 1100ms.
[13:49:59.805] <TB3> INFO: The DUT currently contains the following objects:
[13:49:59.805] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:49:59.805] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:49:59.805] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:49:59.805] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:49:59.805] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:49:59.805] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.907] <TB3> INFO: Test took 1102ms.
[13:50:00.907] <TB3> INFO: The DUT currently contains the following objects:
[13:50:00.907] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:00.907] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:00.907] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:00.907] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:00.907] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.907] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:00.908] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.011] <TB3> INFO: Test took 1103ms.
[13:50:02.012] <TB3> INFO: The DUT currently contains the following objects:
[13:50:02.012] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:02.012] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:02.012] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:02.012] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:02.012] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:02.012] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.115] <TB3> INFO: Test took 1103ms.
[13:50:03.116] <TB3> INFO: The DUT currently contains the following objects:
[13:50:03.116] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:03.116] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:03.116] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:03.116] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:03.116] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:03.116] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.218] <TB3> INFO: Test took 1102ms.
[13:50:04.218] <TB3> INFO: The DUT currently contains the following objects:
[13:50:04.218] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:04.218] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:04.218] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:04.218] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:04.218] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.218] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.218] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.218] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.218] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.218] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.218] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.218] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.219] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.219] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.219] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.219] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.219] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.219] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.219] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:04.219] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.319] <TB3> INFO: Test took 1100ms.
[13:50:05.320] <TB3> INFO: The DUT currently contains the following objects:
[13:50:05.320] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:05.320] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:05.320] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:05.320] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:05.320] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:05.320] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.421] <TB3> INFO: Test took 1101ms.
[13:50:06.421] <TB3> INFO: The DUT currently contains the following objects:
[13:50:06.427] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:06.427] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:06.427] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:06.427] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:06.427] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:06.427] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.525] <TB3> INFO: Test took 1098ms.
[13:50:07.526] <TB3> INFO: The DUT currently contains the following objects:
[13:50:07.526] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:07.526] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:07.526] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:07.526] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:07.526] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:07.526] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.628] <TB3> INFO: Test took 1102ms.
[13:50:08.629] <TB3> INFO: The DUT currently contains the following objects:
[13:50:08.629] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:08.629] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:08.629] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:08.629] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:08.629] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:08.629] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.732] <TB3> INFO: Test took 1103ms.
[13:50:09.732] <TB3> INFO: The DUT currently contains the following objects:
[13:50:09.732] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:09.732] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:09.732] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:09.732] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:09.732] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.732] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.732] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.732] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.732] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:09.733] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.833] <TB3> INFO: Test took 1100ms.
[13:50:10.834] <TB3> INFO: The DUT currently contains the following objects:
[13:50:10.834] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:10.834] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:10.834] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:10.834] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:10.834] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:10.834] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.935] <TB3> INFO: Test took 1101ms.
[13:50:11.936] <TB3> INFO: The DUT currently contains the following objects:
[13:50:11.936] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:11.936] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:11.936] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:11.936] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:11.936] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:11.936] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.036] <TB3> INFO: Test took 1100ms.
[13:50:13.037] <TB3> INFO: The DUT currently contains the following objects:
[13:50:13.037] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:13.037] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:50:13.037] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:50:13.037] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:13.037] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:13.037] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:14.145] <TB3> INFO: Test took 1108ms.
[13:50:14.149] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:53:57.947] <TB3> INFO: Test took 223798ms.
[13:53:59.533] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:35.276] <TB3> INFO: Test took 215744ms.
[13:57:37.043] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.051] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.058] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.065] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.073] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.080] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.087] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.094] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.102] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.109] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.117] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.124] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.132] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:57:37.139] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[13:57:37.147] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.153] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.161] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.168] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:57:37.200] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C0.dat
[13:57:37.200] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C1.dat
[13:57:37.200] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C2.dat
[13:57:37.200] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C3.dat
[13:57:37.200] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C4.dat
[13:57:37.200] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C5.dat
[13:57:37.200] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C6.dat
[13:57:37.201] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C7.dat
[13:57:37.201] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C8.dat
[13:57:37.201] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C9.dat
[13:57:37.201] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C10.dat
[13:57:37.201] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C11.dat
[13:57:37.201] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C12.dat
[13:57:37.201] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C13.dat
[13:57:37.202] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C14.dat
[13:57:37.202] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C15.dat
[13:57:40.635] <TB3> INFO: Test took 3431ms.
[13:57:44.294] <TB3> INFO: Test took 3386ms.
[13:57:48.028] <TB3> INFO: Test took 3449ms.
[13:57:48.303] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:49.222] <TB3> INFO: Test took 919ms.
[13:57:49.225] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:50.332] <TB3> INFO: Test took 1107ms.
[13:57:50.335] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:51.444] <TB3> INFO: Test took 1109ms.
[13:57:51.448] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:52.550] <TB3> INFO: Test took 1102ms.
[13:57:52.553] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:53.661] <TB3> INFO: Test took 1108ms.
[13:57:53.664] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:54.772] <TB3> INFO: Test took 1108ms.
[13:57:54.775] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:55.884] <TB3> INFO: Test took 1109ms.
[13:57:55.889] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:56.990] <TB3> INFO: Test took 1101ms.
[13:57:56.992] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:58.102] <TB3> INFO: Test took 1110ms.
[13:57:58.106] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:57:59.212] <TB3> INFO: Test took 1107ms.
[13:57:59.215] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:00.323] <TB3> INFO: Test took 1109ms.
[13:58:00.327] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:01.429] <TB3> INFO: Test took 1102ms.
[13:58:01.431] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:02.538] <TB3> INFO: Test took 1107ms.
[13:58:02.542] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:03.648] <TB3> INFO: Test took 1106ms.
[13:58:03.651] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:04.759] <TB3> INFO: Test took 1108ms.
[13:58:04.762] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:05.865] <TB3> INFO: Test took 1103ms.
[13:58:05.867] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:06.988] <TB3> INFO: Test took 1121ms.
[13:58:06.991] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:08.101] <TB3> INFO: Test took 1110ms.
[13:58:08.104] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:09.213] <TB3> INFO: Test took 1109ms.
[13:58:09.219] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:10.321] <TB3> INFO: Test took 1102ms.
[13:58:10.324] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:11.433] <TB3> INFO: Test took 1109ms.
[13:58:11.437] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:12.543] <TB3> INFO: Test took 1107ms.
[13:58:12.547] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:13.655] <TB3> INFO: Test took 1108ms.
[13:58:13.659] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:14.765] <TB3> INFO: Test took 1106ms.
[13:58:14.767] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:15.876] <TB3> INFO: Test took 1109ms.
[13:58:15.879] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:16.981] <TB3> INFO: Test took 1103ms.
[13:58:16.983] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:18.084] <TB3> INFO: Test took 1101ms.
[13:58:18.086] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:19.189] <TB3> INFO: Test took 1103ms.
[13:58:19.191] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:20.300] <TB3> INFO: Test took 1109ms.
[13:58:20.303] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:21.412] <TB3> INFO: Test took 1109ms.
[13:58:21.416] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:22.524] <TB3> INFO: Test took 1108ms.
[13:58:22.527] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:23.634] <TB3> INFO: Test took 1108ms.
[13:58:24.171] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 518 seconds
[13:58:24.171] <TB3> INFO: PH scale (per ROC): 65 61 72 78 72 69 72 76 80 73 69 66 67 73 74 71
[13:58:24.172] <TB3> INFO: PH offset (per ROC): 165 189 186 162 184 176 187 174 166 184 165 176 163 176 174 185
[13:58:24.378] <TB3> INFO: ######################################################################
[13:58:24.378] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[13:58:24.378] <TB3> INFO: ######################################################################
[13:58:24.389] <TB3> INFO: scanning low vcal = 10
[13:58:28.211] <TB3> INFO: Test took 3822ms.
[13:58:28.214] <TB3> INFO: scanning low vcal = 20
[13:58:32.088] <TB3> INFO: Test took 3874ms.
[13:58:32.093] <TB3> INFO: scanning low vcal = 30
[13:58:35.983] <TB3> INFO: Test took 3890ms.
[13:58:35.997] <TB3> INFO: scanning low vcal = 40
[13:58:40.339] <TB3> INFO: Test took 4342ms.
[13:58:40.397] <TB3> INFO: scanning low vcal = 50
[13:58:44.737] <TB3> INFO: Test took 4340ms.
[13:58:44.811] <TB3> INFO: scanning low vcal = 60
[13:58:49.148] <TB3> INFO: Test took 4337ms.
[13:58:49.208] <TB3> INFO: scanning low vcal = 70
[13:58:53.567] <TB3> INFO: Test took 4359ms.
[13:58:53.626] <TB3> INFO: scanning low vcal = 80
[13:58:57.978] <TB3> INFO: Test took 4352ms.
[13:58:58.044] <TB3> INFO: scanning low vcal = 90
[13:59:02.440] <TB3> INFO: Test took 4396ms.
[13:59:02.506] <TB3> INFO: scanning low vcal = 100
[13:59:06.847] <TB3> INFO: Test took 4341ms.
[13:59:06.910] <TB3> INFO: scanning low vcal = 110
[13:59:11.265] <TB3> INFO: Test took 4355ms.
[13:59:11.332] <TB3> INFO: scanning low vcal = 120
[13:59:15.713] <TB3> INFO: Test took 4381ms.
[13:59:15.775] <TB3> INFO: scanning low vcal = 130
[13:59:20.119] <TB3> INFO: Test took 4344ms.
[13:59:20.176] <TB3> INFO: scanning low vcal = 140
[13:59:24.543] <TB3> INFO: Test took 4367ms.
[13:59:24.607] <TB3> INFO: scanning low vcal = 150
[13:59:28.992] <TB3> INFO: Test took 4385ms.
[13:59:29.064] <TB3> INFO: scanning low vcal = 160
[13:59:33.410] <TB3> INFO: Test took 4346ms.
[13:59:33.472] <TB3> INFO: scanning low vcal = 170
[13:59:37.803] <TB3> INFO: Test took 4331ms.
[13:59:37.872] <TB3> INFO: scanning low vcal = 180
[13:59:42.233] <TB3> INFO: Test took 4361ms.
[13:59:42.298] <TB3> INFO: scanning low vcal = 190
[13:59:46.630] <TB3> INFO: Test took 4332ms.
[13:59:46.690] <TB3> INFO: scanning low vcal = 200
[13:59:50.928] <TB3> INFO: Test took 4238ms.
[13:59:51.015] <TB3> INFO: scanning low vcal = 210
[13:59:55.218] <TB3> INFO: Test took 4203ms.
[13:59:55.287] <TB3> INFO: scanning low vcal = 220
[13:59:59.489] <TB3> INFO: Test took 4202ms.
[13:59:59.552] <TB3> INFO: scanning low vcal = 230
[14:00:03.764] <TB3> INFO: Test took 4211ms.
[14:00:03.823] <TB3> INFO: scanning low vcal = 240
[14:00:08.030] <TB3> INFO: Test took 4207ms.
[14:00:08.085] <TB3> INFO: scanning low vcal = 250
[14:00:12.280] <TB3> INFO: Test took 4195ms.
[14:00:12.337] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[14:00:16.534] <TB3> INFO: Test took 4197ms.
[14:00:16.593] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[14:00:20.973] <TB3> INFO: Test took 4380ms.
[14:00:21.034] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[14:00:25.402] <TB3> INFO: Test took 4367ms.
[14:00:25.467] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[14:00:29.802] <TB3> INFO: Test took 4335ms.
[14:00:29.864] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[14:00:34.228] <TB3> INFO: Test took 4364ms.
[14:00:34.784] <TB3> INFO: PixTestGainPedestal::measure() done
[14:01:09.399] <TB3> INFO: PixTestGainPedestal::fit() done
[14:01:09.399] <TB3> INFO: non-linearity mean: 0.957 0.954 0.961 0.950 0.954 0.956 0.959 0.961 0.954 0.951 0.955 0.955 0.955 0.959 0.966 0.962
[14:01:09.399] <TB3> INFO: non-linearity RMS: 0.008 0.008 0.006 0.007 0.006 0.006 0.007 0.007 0.007 0.007 0.006 0.006 0.006 0.007 0.005 0.006
[14:01:09.400] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C0.dat
[14:01:09.419] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C1.dat
[14:01:09.440] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C2.dat
[14:01:09.464] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C3.dat
[14:01:09.486] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C4.dat
[14:01:09.507] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C5.dat
[14:01:09.528] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C6.dat
[14:01:09.551] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C7.dat
[14:01:09.571] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C8.dat
[14:01:09.592] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C9.dat
[14:01:09.613] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C10.dat
[14:01:09.634] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C11.dat
[14:01:09.654] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C12.dat
[14:01:09.674] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C13.dat
[14:01:09.695] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C14.dat
[14:01:09.715] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C15.dat
[14:01:09.738] <TB3> INFO: PixTestGainPedestal::doTest() done, duration: 165 seconds
[14:01:09.744] <TB3> INFO: readReadbackCal: /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C0.dat .. /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C15.dat
[14:01:09.774] <TB3> INFO: PixTestReadback::doTest() start.
[14:01:09.775] <TB3> INFO: PixTestReadback::RES sent once
[14:01:26.302] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C0.dat
[14:01:26.302] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C1.dat
[14:01:26.302] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C2.dat
[14:01:26.302] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C3.dat
[14:01:26.302] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C4.dat
[14:01:26.302] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C5.dat
[14:01:26.302] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C6.dat
[14:01:26.303] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C7.dat
[14:01:26.303] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C8.dat
[14:01:26.303] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C9.dat
[14:01:26.303] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C10.dat
[14:01:26.303] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C11.dat
[14:01:26.303] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C12.dat
[14:01:26.303] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C13.dat
[14:01:26.303] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C14.dat
[14:01:26.303] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C15.dat
[14:01:26.334] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[14:01:26.334] <TB3> INFO: PixTestReadback::RES sent once
[14:01:42.786] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C0.dat
[14:01:42.786] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C1.dat
[14:01:42.786] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C2.dat
[14:01:42.786] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C3.dat
[14:01:42.786] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C4.dat
[14:01:42.786] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C5.dat
[14:01:42.786] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C6.dat
[14:01:42.786] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C7.dat
[14:01:42.787] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C8.dat
[14:01:42.787] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C9.dat
[14:01:42.787] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C10.dat
[14:01:42.787] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C11.dat
[14:01:42.787] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C12.dat
[14:01:42.787] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C13.dat
[14:01:42.787] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C14.dat
[14:01:42.787] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C15.dat
[14:01:42.825] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[14:01:42.825] <TB3> INFO: PixTestReadback::RES sent once
[14:01:55.558] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[14:01:55.558] <TB3> INFO: Vbg will be calibrated using Vd calibration
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 153.1calibrated Vbg = 1.21118 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 156.5calibrated Vbg = 1.20036 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 159.9calibrated Vbg = 1.20842 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 150.8calibrated Vbg = 1.22245 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 153.4calibrated Vbg = 1.22615 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 152.1calibrated Vbg = 1.23125 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 148.1calibrated Vbg = 1.22055 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 162.4calibrated Vbg = 1.22133 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 155.7calibrated Vbg = 1.22369 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 242calibrated Vbg = 1.05744 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 145.5calibrated Vbg = 1.20893 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 165.6calibrated Vbg = 1.20932 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 160.2calibrated Vbg = 1.21933 :::*/*/*/*/
[14:01:55.559] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[14:01:55.562] <TB3> INFO: PixTestReadback::RES sent once
[14:05:50.289] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C0.dat
[14:05:50.289] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C1.dat
[14:05:50.289] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C2.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C3.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C4.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C5.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C6.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C7.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C8.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C9.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C10.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C11.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C12.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C13.dat
[14:05:50.290] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C14.dat
[14:05:50.291] <TB3> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2083_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C15.dat
[14:05:50.325] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[14:05:50.326] <TB3> INFO: PixTestReadback::doTest() done
[14:05:50.348] <TB3> INFO: enter test to run
[14:05:50.348] <TB3> INFO: test: exit no parameter change
[14:05:50.902] <TB3> QUIET: Connection to board 170 closed.
[14:05:50.982] <TB3> INFO: pXar: this is the end, my friend