[12:40:24.329] <TB2> INFO: *** Welcome to pxar ***
[12:40:24.329] <TB2> INFO: *** Today: 2015/08/24
[12:40:24.329] <TB2> INFO: readRocDacs: /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C15.dat
[12:40:24.330] <TB2> INFO: readTbmDacs: /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//tbmParameters_C0b.dat
[12:40:24.331] <TB2> INFO: readMaskFile: /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//defaultMaskFile.dat
[12:40:24.331] <TB2> INFO: readTrimFile: /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters_C15.dat
[12:40:24.405] <TB2> INFO: clk: 4
[12:40:24.405] <TB2> INFO: ctr: 4
[12:40:24.405] <TB2> INFO: sda: 19
[12:40:24.405] <TB2> INFO: tin: 9
[12:40:24.405] <TB2> INFO: level: 15
[12:40:24.405] <TB2> INFO: triggerdelay: 0
[12:40:24.405] <TB2> QUIET: Instanciating API for pxar prod-01+86~g1838649
[12:40:24.405] <TB2> INFO: Log level: INFO
[12:40:24.413] <TB2> INFO: Found DTB DTB_WXC55Z
[12:40:24.420] <TB2> QUIET: Connection to board DTB_WXC55Z opened.
[12:40:24.424] <TB2> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 156
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXC55Z
MAC address: 40D85511809C
Hostname: pixelDTB156
Comment:
------------------------------------------------------
[12:40:24.426] <TB2> INFO: RPC call hashes of host and DTB match: 447413373
[12:40:25.949] <TB2> INFO: DUT info:
[12:40:25.949] <TB2> INFO: The DUT currently contains the following objects:
[12:40:25.949] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:40:25.950] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:40:25.950] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:40:25.950] <TB2> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:40:25.950] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:25.950] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:40:26.351] <TB2> INFO: enter 'restricted' command line mode
[12:40:26.351] <TB2> INFO: enter test to run
[12:40:26.351] <TB2> INFO: test: pretest no parameter change
[12:40:26.351] <TB2> INFO: running: pretest
[12:40:26.357] <TB2> INFO: ######################################################################
[12:40:26.357] <TB2> INFO: PixTestPretest::doTest()
[12:40:26.358] <TB2> INFO: ######################################################################
[12:40:26.359] <TB2> INFO: ----------------------------------------------------------------------
[12:40:26.359] <TB2> INFO: PixTestPretest::programROC()
[12:40:26.359] <TB2> INFO: ----------------------------------------------------------------------
[12:40:44.376] <TB2> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[12:40:44.377] <TB2> INFO: IA differences per ROC: 18.5 20.9 19.3 20.9 21.7 19.3 20.1 20.1 19.3 18.5 16.1 17.7 18.5 19.3 19.3 19.3
[12:40:44.448] <TB2> INFO: ----------------------------------------------------------------------
[12:40:44.448] <TB2> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[12:40:44.448] <TB2> INFO: ----------------------------------------------------------------------
[12:40:47.521] <TB2> INFO: PixTestPretest::setVana() done, Module Ia 377 mA = 23.5625 mA/ROC
[12:40:47.524] <TB2> INFO: ----------------------------------------------------------------------
[12:40:47.524] <TB2> INFO: PixTestPretest::findWorkingPixel()
[12:40:47.524] <TB2> INFO: ----------------------------------------------------------------------
[12:40:56.028] <TB2> INFO: Test took 8502ms.
[12:40:56.308] <TB2> INFO: Found working pixel in all ROCs: col/row = 12/22
[12:40:56.345] <TB2> INFO: ----------------------------------------------------------------------
[12:40:56.345] <TB2> INFO: PixTestPretest::setVthrCompCalDel()
[12:40:56.345] <TB2> INFO: ----------------------------------------------------------------------
[12:41:03.860] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[12:41:03.860] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (91) != TBM ID (89)
[12:41:03.860] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:41:03.860] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (90) != TBM ID (92)
[12:41:03.860] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[12:41:03.860] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:41:04.765] <TB2> INFO: Test took 8413ms.
[12:41:05.072] <TB2> INFO: PixTestPretest::setVthrCompCalDel() done
[12:41:05.072] <TB2> INFO: CalDel: 138 131 138 143 144 164 147 148 127 133 127 139 127 160 133 133
[12:41:05.072] <TB2> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[12:41:05.077] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C0.dat
[12:41:05.077] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C1.dat
[12:41:05.077] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C2.dat
[12:41:05.078] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C3.dat
[12:41:05.078] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C4.dat
[12:41:05.078] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C5.dat
[12:41:05.078] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C6.dat
[12:41:05.079] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C7.dat
[12:41:05.079] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C8.dat
[12:41:05.079] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C9.dat
[12:41:05.079] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C10.dat
[12:41:05.079] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C11.dat
[12:41:05.080] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C12.dat
[12:41:05.080] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C13.dat
[12:41:05.080] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C14.dat
[12:41:05.080] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters_C15.dat
[12:41:05.081] <TB2> INFO: write tbm parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//tbmParameters_C0a.dat
[12:41:05.081] <TB2> INFO: write tbm parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//tbmParameters_C0b.dat
[12:41:05.081] <TB2> INFO: PixTestPretest::doTest() done, duration: 38 seconds
[12:41:05.176] <TB2> INFO: enter test to run
[12:41:05.177] <TB2> INFO: test: fulltest no parameter change
[12:41:05.177] <TB2> INFO: running: fulltest
[12:41:05.177] <TB2> INFO: ######################################################################
[12:41:05.177] <TB2> INFO: PixTestFullTest::doTest()
[12:41:05.177] <TB2> INFO: ######################################################################
[12:41:05.178] <TB2> INFO: ######################################################################
[12:41:05.178] <TB2> INFO: PixTestAlive::doTest()
[12:41:05.178] <TB2> INFO: ######################################################################
[12:41:05.180] <TB2> INFO: ----------------------------------------------------------------------
[12:41:05.180] <TB2> 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:05.180] <TB2> INFO: ----------------------------------------------------------------------
[12:41:08.628] <TB2> INFO: Test took 3447ms.
[12:41:08.651] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:08.869] <TB2> INFO: PixTestAlive::aliveTest() done
[12:41:08.869] <TB2> INFO: number of dead pixels (per ROC): 0 1 0 0 0 1 0 0 0 0 0 0 0 0 0 0
[12:41:08.871] <TB2> INFO: ----------------------------------------------------------------------
[12:41:08.871] <TB2> 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:08.871] <TB2> INFO: ----------------------------------------------------------------------
[12:41:11.602] <TB2> INFO: Test took 2730ms.
[12:41:11.605] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:11.606] <TB2> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[12:41:11.833] <TB2> INFO: PixTestAlive::maskTest() done
[12:41:11.833] <TB2> 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:11.835] <TB2> INFO: ----------------------------------------------------------------------
[12:41:11.835] <TB2> 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:11.835] <TB2> INFO: ----------------------------------------------------------------------
[12:41:15.667] <TB2> INFO: Test took 3830ms.
[12:41:15.689] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:15.918] <TB2> INFO: PixTestAlive::addressDecodingTest() done
[12:41:15.918] <TB2> 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:15.919] <TB2> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[12:41:15.930] <TB2> INFO: ######################################################################
[12:41:15.930] <TB2> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[12:41:15.930] <TB2> INFO: ######################################################################
[12:41:15.933] <TB2> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[12:41:15.946] <TB2> INFO: dacScan step from 0 .. 29
[12:41:15.946] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[12:41:15.946] <TB2> INFO: run 1 of 1
[12:41:37.996] <TB2> INFO: Test took 22050ms.
[12:41:38.028] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:38.028] <TB2> INFO: dacScan step from 30 .. 59
[12:41:38.028] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[12:41:38.028] <TB2> INFO: run 1 of 1
[12:41:55.348] <TB2> WARNING: Channel 2 ROC 1: Readback start marker after 1 readouts!
[12:41:55.348] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[12:41:55.348] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:41:55.348] <TB2> WARNING: Channel 2 ROC 2: Readback start marker after 15 readouts!
[12:41:55.348] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[12:41:55.348] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:41:57.744] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[12:41:57.744] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (71) != TBM ID (69)
[12:41:57.744] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:41:57.744] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (70) != TBM ID (72)
[12:41:57.744] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[12:41:57.744] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:42:01.246] <TB2> INFO: Test took 23218ms.
[12:42:01.317] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:01.324] <TB2> INFO: dacScan step from 60 .. 89
[12:42:01.324] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[12:42:01.324] <TB2> INFO: run 1 of 1
[12:42:30.707] <TB2> INFO: Test took 29383ms.
[12:42:30.976] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:31.023] <TB2> INFO: dacScan step from 90 .. 119
[12:42:31.023] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[12:42:31.023] <TB2> INFO: run 1 of 1
[12:42:59.063] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (0) != Token Chain Length (4)
[12:42:59.063] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:42:59.063] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 2 Event ID mismatch: local ID (135) != TBM ID (58)
[12:42:59.063] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[12:42:59.063] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 2 Event ID mismatch: local ID (59) != TBM ID (135)
[12:42:59.063] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:42:59.063] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[12:43:00.982] <TB2> CRITICAL: <hal.cc/MultiRocAllPixelsDacScan:L1040> Incomplete DAQ data readout! Missing -1 Events.
[12:43:28.291] <TB2> INFO: Test took 27266ms.
[12:43:28.564] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:28.618] <TB2> INFO: dacScan step from 120 .. 149
[12:43:28.618] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[12:43:28.618] <TB2> INFO: run 1 of 1
[12:43:55.095] <TB2> INFO: Test took 26477ms.
[12:43:55.267] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:20.154] <TB2> INFO: PixTestBBMap::doTest() done, duration: 184 seconds
[12:44:20.154] <TB2> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:44:20.154] <TB2> INFO: separation cut (per ROC): 92 99 94 99 106 96 89 85 91 90 91 92 87 77 86 90
[12:44:20.234] <TB2> INFO: ######################################################################
[12:44:20.234] <TB2> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = 4, ntrig/step = 50
[12:44:20.234] <TB2> INFO: ######################################################################
[12:44:20.234] <TB2> INFO: ----------------------------------------------------------------------
[12:44:20.234] <TB2> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = 4, ntrig/step = 50
[12:44:20.234] <TB2> INFO: ----------------------------------------------------------------------
[12:44:20.234] <TB2> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4/50) hits flags = 16 (plus default)
[12:44:20.243] <TB2> INFO: dacScan step from 0 .. 3
[12:44:20.243] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:44:20.243] <TB2> INFO: run 1 of 1
[12:44:40.120] <TB2> INFO: Test took 19877ms.
[12:44:40.148] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:40.148] <TB2> INFO: dacScan step from 4 .. 7
[12:44:40.148] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:44:40.148] <TB2> INFO: run 1 of 1
[12:45:00.333] <TB2> INFO: Test took 20185ms.
[12:45:00.361] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:00.361] <TB2> INFO: dacScan step from 8 .. 11
[12:45:00.361] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:45:00.361] <TB2> INFO: run 1 of 1
[12:45:20.307] <TB2> INFO: Test took 19946ms.
[12:45:20.340] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:20.341] <TB2> INFO: dacScan step from 12 .. 15
[12:45:20.341] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:45:20.341] <TB2> INFO: run 1 of 1
[12:45:40.125] <TB2> INFO: Test took 19784ms.
[12:45:40.152] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:40.152] <TB2> INFO: dacScan step from 16 .. 19
[12:45:40.152] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:45:40.152] <TB2> INFO: run 1 of 1
[12:46:00.184] <TB2> INFO: Test took 20031ms.
[12:46:00.213] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:00.213] <TB2> INFO: dacScan step from 20 .. 23
[12:46:00.213] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:46:00.213] <TB2> INFO: run 1 of 1
[12:46:20.063] <TB2> INFO: Test took 19850ms.
[12:46:20.092] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:20.092] <TB2> INFO: dacScan step from 24 .. 27
[12:46:20.092] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:46:20.092] <TB2> INFO: run 1 of 1
[12:46:39.971] <TB2> INFO: Test took 19879ms.
[12:46:39.999] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:39.999] <TB2> INFO: dacScan step from 28 .. 31
[12:46:39.999] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:46:39.999] <TB2> INFO: run 1 of 1
[12:47:00.227] <TB2> INFO: Test took 20228ms.
[12:47:00.262] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:00.262] <TB2> INFO: dacScan step from 32 .. 35
[12:47:00.262] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:47:00.262] <TB2> INFO: run 1 of 1
[12:47:20.296] <TB2> INFO: Test took 20034ms.
[12:47:20.328] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:20.328] <TB2> INFO: dacScan step from 36 .. 39
[12:47:20.328] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:47:20.328] <TB2> INFO: run 1 of 1
[12:47:40.102] <TB2> INFO: Test took 19774ms.
[12:47:40.131] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:40.131] <TB2> INFO: dacScan step from 40 .. 43
[12:47:40.131] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:47:40.131] <TB2> INFO: run 1 of 1
[12:47:59.904] <TB2> INFO: Test took 19773ms.
[12:47:59.935] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:59.935] <TB2> INFO: dacScan step from 44 .. 47
[12:47:59.935] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:47:59.935] <TB2> INFO: run 1 of 1
[12:48:19.734] <TB2> INFO: Test took 19799ms.
[12:48:19.764] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:19.764] <TB2> INFO: dacScan step from 48 .. 51
[12:48:19.764] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:48:19.764] <TB2> INFO: run 1 of 1
[12:48:39.180] <TB2> INFO: Test took 19415ms.
[12:48:39.209] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:39.209] <TB2> INFO: dacScan step from 52 .. 55
[12:48:39.209] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:48:39.209] <TB2> INFO: run 1 of 1
[12:48:59.154] <TB2> INFO: Test took 19945ms.
[12:48:59.183] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:59.183] <TB2> INFO: dacScan step from 56 .. 59
[12:48:59.183] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:48:59.183] <TB2> INFO: run 1 of 1
[12:49:18.871] <TB2> INFO: Test took 19688ms.
[12:49:18.906] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:18.906] <TB2> INFO: dacScan step from 60 .. 63
[12:49:18.906] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:49:18.906] <TB2> INFO: run 1 of 1
[12:49:38.749] <TB2> INFO: Test took 19842ms.
[12:49:38.776] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:38.777] <TB2> INFO: dacScan step from 64 .. 67
[12:49:38.777] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:49:38.777] <TB2> INFO: run 1 of 1
[12:49:58.406] <TB2> INFO: Test took 19629ms.
[12:49:58.442] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:58.442] <TB2> INFO: dacScan step from 68 .. 71
[12:49:58.442] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:49:58.442] <TB2> INFO: run 1 of 1
[12:50:18.129] <TB2> INFO: Test took 19687ms.
[12:50:18.167] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:18.168] <TB2> INFO: dacScan step from 72 .. 75
[12:50:18.168] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:50:18.168] <TB2> INFO: run 1 of 1
[12:50:38.361] <TB2> INFO: Test took 20193ms.
[12:50:38.402] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:38.403] <TB2> INFO: dacScan step from 76 .. 79
[12:50:38.403] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:50:38.403] <TB2> INFO: run 1 of 1
[12:50:59.132] <TB2> INFO: Test took 20729ms.
[12:50:59.201] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:59.203] <TB2> INFO: dacScan step from 80 .. 83
[12:50:59.203] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:50:59.203] <TB2> INFO: run 1 of 1
[12:51:22.820] <TB2> INFO: Test took 23617ms.
[12:51:22.935] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:22.941] <TB2> INFO: dacScan step from 84 .. 87
[12:51:22.941] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:51:22.941] <TB2> INFO: run 1 of 1
[12:51:49.390] <TB2> INFO: Test took 26449ms.
[12:51:49.548] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:49.557] <TB2> INFO: dacScan step from 88 .. 91
[12:51:49.557] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:51:49.557] <TB2> INFO: run 1 of 1
[12:52:17.748] <TB2> INFO: Test took 28191ms.
[12:52:17.934] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:17.942] <TB2> INFO: dacScan step from 92 .. 95
[12:52:17.942] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:52:17.942] <TB2> INFO: run 1 of 1
[12:52:48.411] <TB2> INFO: Test took 30468ms.
[12:52:48.628] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:48.638] <TB2> INFO: dacScan step from 96 .. 99
[12:52:48.638] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:52:48.638] <TB2> INFO: run 1 of 1
[12:53:18.460] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:53:18.460] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:53:19.481] <TB2> INFO: Test took 30843ms.
[12:53:19.714] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:19.724] <TB2> INFO: dacScan step from 100 .. 103
[12:53:19.724] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:53:19.724] <TB2> INFO: run 1 of 1
[12:53:47.081] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (0) != Token Chain Length (4)
[12:53:47.081] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:53:47.081] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 2 Event ID mismatch: local ID (205) != TBM ID (206)
[12:53:47.081] <TB2> WARNING: Channel 2 ROC 1: Readback start marker after 15 readouts!
[12:53:47.081] <TB2> WARNING: Channel 2 ROC 2: Readback start marker after 15 readouts!
[12:53:47.081] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[12:53:47.081] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:53:50.225] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:53:50.226] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:53:51.553] <TB2> INFO: Test took 31829ms.
[12:53:51.798] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:51.808] <TB2> INFO: dacScan step from 104 .. 107
[12:53:51.808] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:53:51.808] <TB2> INFO: run 1 of 1
[12:53:59.232] <TB2> WARNING: Channel 2 ROC 2: Readback start marker after 10 readouts!
[12:53:59.232] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (3) != Token Chain Length (4)
[12:53:59.232] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[12:54:20.470] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:54:20.470] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!
[12:54:21.605] <TB2> INFO: Test took 29797ms.
[12:54:21.846] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:21.859] <TB2> INFO: dacScan step from 108 .. 111
[12:54:21.859] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:54:21.859] <TB2> INFO: run 1 of 1
[12:54:49.066] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[12:54:49.066] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:54:49.066] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[12:54:49.066] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:54:53.822] <TB2> INFO: Test took 31963ms.
[12:54:54.076] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:54.088] <TB2> INFO: dacScan step from 112 .. 115
[12:54:54.088] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:54:54.088] <TB2> INFO: run 1 of 1
[12:55:21.942] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (7) != Token Chain Length (4)
[12:55:21.942] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (80) != TBM ID (81)
[12:55:21.942] <TB2> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[12:55:21.942] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[12:55:21.942] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:55:23.129] <TB2> INFO: Test took 29041ms.
[12:55:23.384] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:23.398] <TB2> INFO: dacScan step from 116 .. 119
[12:55:23.398] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:55:23.398] <TB2> INFO: run 1 of 1
[12:55:51.236] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (68) != TBM ID (0)
[12:55:51.236] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[12:55:51.236] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (1) != TBM ID (69)
[12:55:52.573] <TB2> INFO: Test took 29175ms.
[12:55:52.798] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:52.807] <TB2> INFO: dacScan step from 120 .. 123
[12:55:52.807] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:55:52.807] <TB2> INFO: run 1 of 1
[12:56:25.071] <TB2> INFO: Test took 32264ms.
[12:56:25.315] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:25.324] <TB2> INFO: dacScan step from 124 .. 127
[12:56:25.324] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:56:25.324] <TB2> INFO: run 1 of 1
[12:56:57.301] <TB2> INFO: Test took 31977ms.
[12:56:57.530] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:57.542] <TB2> INFO: dacScan step from 128 .. 131
[12:56:57.542] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:56:57.542] <TB2> INFO: run 1 of 1
[12:57:29.461] <TB2> INFO: Test took 31919ms.
[12:57:29.742] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:29.753] <TB2> INFO: dacScan step from 132 .. 135
[12:57:29.753] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:57:29.753] <TB2> INFO: run 1 of 1
[12:58:02.234] <TB2> INFO: Test took 32481ms.
[12:58:02.462] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:02.472] <TB2> INFO: dacScan step from 136 .. 139
[12:58:02.472] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:58:02.472] <TB2> INFO: run 1 of 1
[12:58:31.893] <TB2> INFO: Test took 29421ms.
[12:58:32.119] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:32.129] <TB2> INFO: dacScan step from 140 .. 143
[12:58:32.129] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:58:32.129] <TB2> INFO: run 1 of 1
[12:58:58.962] <TB2> INFO: Test took 26833ms.
[12:58:59.190] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:59.199] <TB2> INFO: dacScan step from 144 .. 147
[12:58:59.199] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:58:59.199] <TB2> INFO: run 1 of 1
[12:59:25.823] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[12:59:25.823] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:59:25.823] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[12:59:25.823] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:59:30.613] <TB2> INFO: Test took 31414ms.
[12:59:30.839] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:30.848] <TB2> INFO: dacScan step from 148 .. 149
[12:59:30.848] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[12:59:30.848] <TB2> INFO: run 1 of 1
[12:59:48.027] <TB2> INFO: Test took 17179ms.
[12:59:48.161] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:48.168] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[12:59:49.620] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[12:59:51.016] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[12:59:52.679] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[12:59:54.237] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[12:59:55.741] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[12:59:57.248] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[12:59:58.815] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[13:00:00.322] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[13:00:01.725] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[13:00:03.163] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[13:00:04.672] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[13:00:06.192] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[13:00:07.671] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[13:00:09.232] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[13:00:10.858] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[13:00:12.469] <TB2> INFO: PixTestScurves::scurves() done
[13:00:12.469] <TB2> INFO: Vcal mean: 96.22 91.91 85.70 101.72 92.58 91.65 86.04 81.91 98.81 85.24 91.52 83.65 89.51 79.60 83.22 84.41
[13:00:12.469] <TB2> INFO: Vcal RMS: 5.54 6.62 5.41 5.82 6.41 6.11 5.72 4.44 5.32 5.34 5.04 5.65 6.32 4.05 4.94 5.18
[13:00:12.469] <TB2> INFO: PixTestScurves::fullTest() done, duration: 952 seconds
[13:00:12.542] <TB2> INFO: ######################################################################
[13:00:12.542] <TB2> INFO: PixTestTrim::doTest()
[13:00:12.542] <TB2> INFO: ######################################################################
[13:00:12.544] <TB2> INFO: ----------------------------------------------------------------------
[13:00:12.544] <TB2> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[13:00:12.544] <TB2> INFO: ----------------------------------------------------------------------
[13:00:12.628] <TB2> INFO: ---> VthrComp thr map (minimal VthrComp)
[13:00:12.628] <TB2> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[13:00:12.637] <TB2> INFO: dacScan step from 0 .. 19
[13:00:12.637] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:00:12.637] <TB2> INFO: run 1 of 1
[13:00:27.878] <TB2> INFO: Test took 15241ms.
[13:00:27.906] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:27.906] <TB2> INFO: dacScan step from 20 .. 39
[13:00:27.906] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:00:27.906] <TB2> INFO: run 1 of 1
[13:00:43.074] <TB2> INFO: Test took 15168ms.
[13:00:43.101] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:43.101] <TB2> INFO: dacScan step from 40 .. 59
[13:00:43.101] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:00:43.101] <TB2> INFO: run 1 of 1
[13:00:58.086] <TB2> INFO: Test took 14985ms.
[13:00:58.108] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:58.108] <TB2> INFO: dacScan step from 60 .. 79
[13:00:58.108] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:00:58.108] <TB2> INFO: run 1 of 1
[13:01:13.076] <TB2> INFO: Test took 14968ms.
[13:01:13.097] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:13.097] <TB2> INFO: dacScan step from 80 .. 99
[13:01:13.097] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:01:13.097] <TB2> INFO: run 1 of 1
[13:01:28.513] <TB2> INFO: Test took 15416ms.
[13:01:28.579] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:28.588] <TB2> INFO: dacScan step from 100 .. 119
[13:01:28.589] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:01:28.589] <TB2> INFO: run 1 of 1
[13:01:49.434] <TB2> INFO: Test took 20845ms.
[13:01:49.601] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:49.630] <TB2> INFO: dacScan step from 120 .. 139
[13:01:49.630] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:01:49.630] <TB2> INFO: run 1 of 1
[13:02:08.721] <TB2> INFO: Test took 19091ms.
[13:02:08.854] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:08.877] <TB2> INFO: dacScan step from 140 .. 159
[13:02:08.877] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:02:08.877] <TB2> INFO: run 1 of 1
[13:02:25.470] <TB2> INFO: Test took 16593ms.
[13:02:25.514] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:45.398] <TB2> INFO: ROC 0 VthrComp = 95
[13:02:45.398] <TB2> INFO: ROC 1 VthrComp = 91
[13:02:45.398] <TB2> INFO: ROC 2 VthrComp = 87
[13:02:45.398] <TB2> INFO: ROC 3 VthrComp = 99
[13:02:45.399] <TB2> INFO: ROC 4 VthrComp = 94
[13:02:45.399] <TB2> INFO: ROC 5 VthrComp = 89
[13:02:45.399] <TB2> INFO: ROC 6 VthrComp = 86
[13:02:45.399] <TB2> INFO: ROC 7 VthrComp = 83
[13:02:45.399] <TB2> INFO: ROC 8 VthrComp = 100
[13:02:45.399] <TB2> INFO: ROC 9 VthrComp = 90
[13:02:45.399] <TB2> INFO: ROC 10 VthrComp = 92
[13:02:45.399] <TB2> INFO: ROC 11 VthrComp = 85
[13:02:45.400] <TB2> INFO: ROC 12 VthrComp = 85
[13:02:45.400] <TB2> INFO: ROC 13 VthrComp = 82
[13:02:45.400] <TB2> INFO: ROC 14 VthrComp = 85
[13:02:45.400] <TB2> INFO: ROC 15 VthrComp = 86
[13:02:45.400] <TB2> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[13:02:45.400] <TB2> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[13:02:45.410] <TB2> INFO: dacScan step from 0 .. 19
[13:02:45.410] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:02:45.410] <TB2> INFO: run 1 of 1
[13:03:01.335] <TB2> INFO: Test took 15925ms.
[13:03:01.360] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:01.360] <TB2> INFO: dacScan step from 20 .. 39
[13:03:01.360] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:03:01.360] <TB2> INFO: run 1 of 1
[13:03:16.891] <TB2> INFO: Test took 15531ms.
[13:03:16.931] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:16.935] <TB2> INFO: dacScan step from 40 .. 59
[13:03:16.935] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:03:16.935] <TB2> INFO: run 1 of 1
[13:03:35.725] <TB2> INFO: Test took 18790ms.
[13:03:35.870] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:35.897] <TB2> INFO: dacScan step from 60 .. 79
[13:03:35.897] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:03:35.897] <TB2> INFO: run 1 of 1
[13:03:54.782] <TB2> INFO: Test took 18885ms.
[13:03:54.954] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:54.985] <TB2> INFO: dacScan step from 80 .. 99
[13:03:54.985] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:03:54.985] <TB2> INFO: run 1 of 1
[13:04:14.031] <TB2> INFO: Test took 19046ms.
[13:04:14.193] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:14.226] <TB2> INFO: dacScan step from 100 .. 119
[13:04:14.226] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:04:14.226] <TB2> INFO: run 1 of 1
[13:04:34.073] <TB2> INFO: Test took 19847ms.
[13:04:34.252] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:34.284] <TB2> INFO: dacScan step from 120 .. 139
[13:04:34.284] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:04:34.284] <TB2> INFO: run 1 of 1
[13:04:56.174] <TB2> INFO: Test took 21890ms.
[13:04:56.334] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:56.363] <TB2> INFO: dacScan step from 140 .. 159
[13:04:56.363] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:04:56.363] <TB2> INFO: run 1 of 1
[13:05:17.956] <TB2> INFO: Test took 21593ms.
[13:05:18.136] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:44.416] <TB2> INFO: roc 0 with ID = 0 has maximal Vcal 59.2909 for pixel 19/77 mean/min/max = 45.5709/31.7996/59.3422
[13:05:44.416] <TB2> INFO: roc 1 with ID = 1 has maximal Vcal 62.6793 for pixel 14/64 mean/min/max = 47.2817/31.8151/62.7483
[13:05:44.416] <TB2> INFO: roc 2 with ID = 2 has maximal Vcal 58.0159 for pixel 0/74 mean/min/max = 45.5103/32.731/58.2896
[13:05:44.417] <TB2> INFO: roc 3 with ID = 3 has maximal Vcal 60.2665 for pixel 24/71 mean/min/max = 46.0984/31.9198/60.277
[13:05:44.417] <TB2> INFO: roc 4 with ID = 4 has maximal Vcal 61.3304 for pixel 10/71 mean/min/max = 46.4795/31.6202/61.3387
[13:05:44.417] <TB2> INFO: roc 5 with ID = 5 has maximal Vcal 62.7834 for pixel 15/76 mean/min/max = 47.7002/32.5013/62.8991
[13:05:44.417] <TB2> INFO: roc 6 with ID = 6 has maximal Vcal 59.3146 for pixel 5/1 mean/min/max = 45.8481/32.3412/59.3551
[13:05:44.418] <TB2> INFO: roc 7 with ID = 7 has maximal Vcal 57.016 for pixel 6/70 mean/min/max = 44.9447/32.7763/57.1131
[13:05:44.418] <TB2> INFO: roc 8 with ID = 8 has maximal Vcal 57.3572 for pixel 51/18 mean/min/max = 44.3539/31.1722/57.5357
[13:05:44.419] <TB2> INFO: roc 9 with ID = 9 has maximal Vcal 59.1865 for pixel 17/1 mean/min/max = 45.8557/32.5142/59.1972
[13:05:44.419] <TB2> INFO: roc 10 with ID = 10 has maximal Vcal 58.7424 for pixel 23/14 mean/min/max = 46.1749/33.404/58.9457
[13:05:44.419] <TB2> INFO: roc 11 with ID = 11 has maximal Vcal 59.7339 for pixel 4/71 mean/min/max = 45.6333/31.4246/59.842
[13:05:44.420] <TB2> INFO: roc 12 with ID = 12 has maximal Vcal 63.4505 for pixel 4/74 mean/min/max = 47.5729/31.6049/63.541
[13:05:44.420] <TB2> INFO: roc 13 with ID = 13 has maximal Vcal 57.0635 for pixel 16/0 mean/min/max = 44.9498/32.7853/57.1143
[13:05:44.421] <TB2> INFO: roc 14 with ID = 14 has maximal Vcal 58.807 for pixel 22/6 mean/min/max = 45.9878/33.1173/58.8584
[13:05:44.421] <TB2> INFO: roc 15 with ID = 15 has maximal Vcal 57.6036 for pixel 51/79 mean/min/max = 44.5866/31.5039/57.6692
[13:05:44.421] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:06:00.040] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[13:06:00.040] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[13:06:00.040] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[13:06:00.040] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[13:06:56.738] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 2 Event ID mismatch: local ID (182) != TBM ID (183)
[13:06:56.738] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (182) != TBM ID (183)
[13:06:56.738] <TB2> WARNING: Channel 2 ROC 0: Readback start marker after 15 readouts!
[13:06:56.738] <TB2> WARNING: Channel 2 ROC 1: Readback start marker after 15 readouts!
[13:06:56.738] <TB2> WARNING: Channel 2 ROC 2: Readback start marker after 15 readouts!
[13:06:56.738] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[13:06:56.738] <TB2> WARNING: Channel 3 ROC 0: Readback start marker after 15 readouts!
[13:06:56.738] <TB2> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[13:06:56.738] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[13:06:56.738] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[13:07:26.359] <TB2> INFO: Test took 101938ms.
[13:07:27.743] <TB2> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[13:07:27.751] <TB2> INFO: dacScan step from 0 .. 19
[13:07:27.751] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:07:27.751] <TB2> INFO: run 1 of 2
[13:07:43.353] <TB2> INFO: Test took 15602ms.
[13:07:43.386] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:43.387] <TB2> INFO: run 2 of 2
[13:07:59.725] <TB2> INFO: Test took 16337ms.
[13:07:59.757] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:59.759] <TB2> INFO: dacScan step from 20 .. 39
[13:07:59.759] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:07:59.759] <TB2> INFO: run 1 of 2
[13:08:19.304] <TB2> INFO: Test took 19545ms.
[13:08:19.455] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:19.482] <TB2> INFO: run 2 of 2
[13:08:38.697] <TB2> INFO: Test took 19215ms.
[13:08:38.844] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:38.870] <TB2> INFO: dacScan step from 40 .. 59
[13:08:38.870] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:08:38.870] <TB2> INFO: run 1 of 2
[13:09:00.084] <TB2> INFO: Test took 21214ms.
[13:09:00.287] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:00.321] <TB2> INFO: run 2 of 2
[13:09:22.062] <TB2> INFO: Test took 21741ms.
[13:09:22.249] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:22.280] <TB2> INFO: dacScan step from 60 .. 79
[13:09:22.280] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:09:22.280] <TB2> INFO: run 1 of 2
[13:09:43.829] <TB2> INFO: Test took 21549ms.
[13:09:43.996] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:44.033] <TB2> INFO: run 2 of 2
[13:10:05.171] <TB2> INFO: Test took 21138ms.
[13:10:05.365] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:05.442] <TB2> INFO: dacScan step from 80 .. 99
[13:10:05.442] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:10:05.442] <TB2> INFO: run 1 of 2
[13:10:26.803] <TB2> INFO: Test took 21360ms.
[13:10:26.966] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:27.001] <TB2> INFO: run 2 of 2
[13:10:48.228] <TB2> INFO: Test took 21227ms.
[13:10:48.407] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:48.442] <TB2> INFO: dacScan step from 100 .. 119
[13:10:48.442] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:10:48.442] <TB2> INFO: run 1 of 2
[13:10:58.548] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (1) != Token Chain Length (4)
[13:10:58.548] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[13:10:58.549] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 2 Event ID mismatch: local ID (145) != TBM ID (129)
[13:10:58.549] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (1) != Token Chain Length (4)
[13:10:58.549] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 2 Event ID mismatch: local ID (130) != TBM ID (145)
[13:10:58.549] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[13:10:58.549] <TB2> WARNING: Channel 2 ROC 1: Readback start marker after 15 readouts!
[13:10:58.549] <TB2> WARNING: Channel 2 ROC 2: Readback start marker after 15 readouts!
[13:10:58.549] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[13:11:09.877] <TB2> CRITICAL: <hal.cc/MultiRocAllPixelsDacScan:L1040> Incomplete DAQ data readout! Missing -1 Events.
[13:11:31.101] <TB2> INFO: Test took 21195ms.
[13:11:31.271] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:31.309] <TB2> INFO: run 2 of 2
[13:11:52.409] <TB2> INFO: Test took 21100ms.
[13:11:52.571] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:52.602] <TB2> INFO: dacScan step from 120 .. 139
[13:11:52.602] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:11:52.602] <TB2> INFO: run 1 of 2
[13:12:13.653] <TB2> INFO: Test took 21051ms.
[13:12:13.822] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:13.858] <TB2> INFO: run 2 of 2
[13:12:33.881] <TB2> INFO: Test took 20023ms.
[13:12:34.146] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:34.204] <TB2> INFO: dacScan step from 140 .. 159
[13:12:34.204] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:12:34.204] <TB2> INFO: run 1 of 2
[13:12:53.515] <TB2> INFO: Test took 19310ms.
[13:12:53.675] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:53.708] <TB2> INFO: run 2 of 2
[13:13:12.702] <TB2> INFO: Test took 18994ms.
[13:13:12.869] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:12.902] <TB2> INFO: dacScan step from 160 .. 179
[13:13:12.911] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:13:12.911] <TB2> INFO: run 1 of 2
[13:13:32.649] <TB2> INFO: Test took 19738ms.
[13:13:32.816] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:32.847] <TB2> INFO: run 2 of 2
[13:13:54.242] <TB2> INFO: Test took 21395ms.
[13:13:54.423] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:54.459] <TB2> INFO: dacScan step from 180 .. 199
[13:13:54.459] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:13:54.459] <TB2> INFO: run 1 of 2
[13:14:17.597] <TB2> INFO: Test took 23138ms.
[13:14:17.768] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:14:17.798] <TB2> INFO: run 2 of 2
[13:14:40.165] <TB2> INFO: Test took 22367ms.
[13:14:40.359] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:06.919] <TB2> INFO: ---> TrimStepCorr4 extremal thresholds: 0.059462 .. 255.000000
[13:15:07.000] <TB2> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[13:15:07.009] <TB2> INFO: dacScan step from 0 .. 19
[13:15:07.009] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:15:07.009] <TB2> INFO: run 1 of 1
[13:15:20.989] <TB2> INFO: Test took 13980ms.
[13:15:21.017] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:21.017] <TB2> INFO: dacScan step from 20 .. 39
[13:15:21.017] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:15:21.017] <TB2> INFO: run 1 of 1
[13:15:35.991] <TB2> INFO: Test took 14974ms.
[13:15:36.073] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:36.092] <TB2> INFO: dacScan step from 40 .. 59
[13:15:36.092] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:15:36.092] <TB2> INFO: run 1 of 1
[13:15:53.933] <TB2> INFO: Test took 17841ms.
[13:15:54.082] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:15:54.117] <TB2> INFO: dacScan step from 60 .. 79
[13:15:54.117] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:15:54.117] <TB2> INFO: run 1 of 1
[13:16:11.889] <TB2> INFO: Test took 17771ms.
[13:16:12.048] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:12.078] <TB2> INFO: dacScan step from 80 .. 99
[13:16:12.078] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:16:12.078] <TB2> INFO: run 1 of 1
[13:16:28.745] <TB2> INFO: Test took 16667ms.
[13:16:28.885] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:28.922] <TB2> INFO: dacScan step from 100 .. 119
[13:16:28.922] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:16:28.922] <TB2> INFO: run 1 of 1
[13:16:46.141] <TB2> INFO: Test took 17219ms.
[13:16:46.281] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:16:46.313] <TB2> INFO: dacScan step from 120 .. 139
[13:16:46.313] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:16:46.313] <TB2> INFO: run 1 of 1
[13:17:02.951] <TB2> INFO: Test took 16638ms.
[13:17:03.092] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:03.124] <TB2> INFO: dacScan step from 140 .. 159
[13:17:03.124] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:17:03.124] <TB2> INFO: run 1 of 1
[13:17:19.617] <TB2> INFO: Test took 16493ms.
[13:17:19.786] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:19.826] <TB2> INFO: dacScan step from 160 .. 179
[13:17:19.826] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:17:19.826] <TB2> INFO: run 1 of 1
[13:17:36.612] <TB2> INFO: Test took 16786ms.
[13:17:36.754] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:36.806] <TB2> INFO: dacScan step from 180 .. 199
[13:17:36.806] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:17:36.806] <TB2> INFO: run 1 of 1
[13:17:55.266] <TB2> INFO: Test took 18460ms.
[13:17:55.415] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:17:55.453] <TB2> INFO: dacScan step from 200 .. 219
[13:17:55.453] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:17:55.453] <TB2> INFO: run 1 of 1
[13:18:14.619] <TB2> INFO: Test took 19166ms.
[13:18:14.764] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:14.796] <TB2> INFO: dacScan step from 220 .. 239
[13:18:14.796] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:18:14.796] <TB2> INFO: run 1 of 1
[13:18:32.090] <TB2> INFO: Test took 17294ms.
[13:18:32.242] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:18:32.275] <TB2> INFO: dacScan step from 240 .. 255
[13:18:32.275] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:18:32.275] <TB2> INFO: run 1 of 1
[13:18:46.246] <TB2> INFO: Test took 13971ms.
[13:18:46.362] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:19.014] <TB2> INFO: ---> TrimStepCorr2 extremal thresholds: 13.720546 .. 45.185214
[13:19:19.093] <TB2> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 3 .. 55 (20/-1) hits flags = 16 (plus default)
[13:19:19.101] <TB2> INFO: dacScan step from 3 .. 22
[13:19:19.101] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:19:19.101] <TB2> INFO: run 1 of 1
[13:19:32.206] <TB2> INFO: Test took 13105ms.
[13:19:32.223] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:32.223] <TB2> INFO: dacScan step from 23 .. 42
[13:19:32.223] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:19:32.223] <TB2> INFO: run 1 of 1
[13:19:48.343] <TB2> INFO: Test took 16119ms.
[13:19:48.449] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:48.470] <TB2> INFO: dacScan step from 43 .. 55
[13:19:48.470] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:19:48.470] <TB2> INFO: run 1 of 1
[13:20:02.144] <TB2> INFO: Test took 13674ms.
[13:20:02.240] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:18.169] <TB2> INFO: ---> TrimStepCorr1a extremal thresholds: 18.324973 .. 41.825640
[13:20:18.252] <TB2> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 8 .. 51 (20/-1) hits flags = 16 (plus default)
[13:20:18.261] <TB2> INFO: dacScan step from 8 .. 27
[13:20:18.261] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:20:18.261] <TB2> INFO: run 1 of 1
[13:20:31.287] <TB2> INFO: Test took 13026ms.
[13:20:31.309] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:31.309] <TB2> INFO: dacScan step from 28 .. 47
[13:20:31.309] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:20:31.309] <TB2> INFO: run 1 of 1
[13:20:47.854] <TB2> INFO: Test took 16545ms.
[13:20:47.988] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:48.015] <TB2> INFO: dacScan step from 48 .. 51
[13:20:48.015] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:20:48.015] <TB2> INFO: run 1 of 1
[13:20:54.152] <TB2> INFO: Test took 6137ms.
[13:20:54.182] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:08.893] <TB2> INFO: ---> TrimStepCorr1b extremal thresholds: 20.063714 .. 41.416440
[13:21:08.972] <TB2> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 10 .. 51 (20/-1) hits flags = 16 (plus default)
[13:21:08.981] <TB2> INFO: dacScan step from 10 .. 29
[13:21:08.981] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:21:08.981] <TB2> INFO: run 1 of 1
[13:21:22.702] <TB2> INFO: Test took 13721ms.
[13:21:22.723] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:22.724] <TB2> INFO: dacScan step from 30 .. 49
[13:21:22.724] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:21:22.724] <TB2> INFO: run 1 of 1
[13:21:40.294] <TB2> INFO: Test took 17570ms.
[13:21:40.438] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:40.468] <TB2> INFO: dacScan step from 50 .. 51
[13:21:40.468] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[13:21:40.468] <TB2> INFO: run 1 of 1
[13:21:44.822] <TB2> INFO: Test took 4354ms.
[13:21:44.838] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:59.562] <TB2> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[13:21:59.562] <TB2> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[13:21:59.571] <TB2> INFO: dacScan step from 15 .. 34
[13:21:59.571] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:21:59.571] <TB2> INFO: run 1 of 2
[13:22:16.033] <TB2> INFO: Test took 16462ms.
[13:22:16.079] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:16.086] <TB2> INFO: run 2 of 2
[13:22:32.566] <TB2> INFO: Test took 16476ms.
[13:22:32.609] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:32.617] <TB2> INFO: dacScan step from 35 .. 54
[13:22:32.617] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:22:32.617] <TB2> INFO: run 1 of 2
[13:22:53.213] <TB2> INFO: Test took 20596ms.
[13:22:53.401] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:53.440] <TB2> INFO: run 2 of 2
[13:23:13.894] <TB2> INFO: Test took 20454ms.
[13:23:14.076] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:14.111] <TB2> INFO: dacScan step from 55 .. 55
[13:23:14.111] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:23:14.111] <TB2> INFO: run 1 of 2
[13:23:17.901] <TB2> INFO: Test took 3790ms.
[13:23:17.919] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:17.922] <TB2> INFO: run 2 of 2
[13:23:21.681] <TB2> INFO: Test took 3759ms.
[13:23:21.693] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:35.552] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C0.dat
[13:23:35.552] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C1.dat
[13:23:35.552] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C2.dat
[13:23:35.553] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C3.dat
[13:23:35.553] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C4.dat
[13:23:35.553] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C5.dat
[13:23:35.553] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C6.dat
[13:23:35.554] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C7.dat
[13:23:35.554] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C8.dat
[13:23:35.554] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C9.dat
[13:23:35.555] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C10.dat
[13:23:35.555] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C11.dat
[13:23:35.555] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C12.dat
[13:23:35.556] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C13.dat
[13:23:35.556] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C14.dat
[13:23:35.556] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C15.dat
[13:23:35.557] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C0.dat
[13:23:35.571] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C1.dat
[13:23:35.578] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C2.dat
[13:23:35.585] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C3.dat
[13:23:35.592] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C4.dat
[13:23:35.599] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C5.dat
[13:23:35.605] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C6.dat
[13:23:35.611] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C7.dat
[13:23:35.617] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C8.dat
[13:23:35.624] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C9.dat
[13:23:35.630] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C10.dat
[13:23:35.637] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C11.dat
[13:23:35.645] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C12.dat
[13:23:35.651] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C13.dat
[13:23:35.657] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C14.dat
[13:23:35.663] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//trimParameters35_C15.dat
[13:23:35.670] <TB2> INFO: PixTestTrim::trimTest() done
[13:23:35.670] <TB2> INFO: vtrim: 100 136 98 110 120 133 105 101 105 117 114 104 117 116 102 88
[13:23:35.670] <TB2> INFO: vthrcomp: 95 91 87 99 94 89 86 83 100 90 92 85 85 82 85 86
[13:23:35.670] <TB2> INFO: vcal mean: 35.07 35.06 35.08 35.09 35.10 35.09 35.07 35.07 35.01 35.03 35.09 35.13 35.10 35.11 35.05 35.03
[13:23:35.670] <TB2> INFO: vcal RMS: 1.09 1.18 1.01 1.11 1.04 1.22 1.08 1.05 1.09 1.04 1.15 1.09 1.12 1.09 1.05 1.02
[13:23:35.670] <TB2> INFO: bits mean: 10.04 9.61 9.27 9.68 9.93 9.59 9.79 10.17 9.97 10.02 10.22 9.96 9.57 10.43 9.72 9.59
[13:23:35.670] <TB2> INFO: bits RMS: 2.48 2.58 2.76 2.60 2.50 2.43 2.51 2.33 2.67 2.40 2.17 2.60 2.58 2.25 2.50 2.90
[13:23:35.677] <TB2> INFO: ----------------------------------------------------------------------
[13:23:35.677] <TB2> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[13:23:35.677] <TB2> INFO: ----------------------------------------------------------------------
[13:23:35.679] <TB2> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[13:23:35.689] <TB2> INFO: dacScan step from 0 .. 19
[13:23:35.689] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:23:35.689] <TB2> INFO: run 1 of 2
[13:23:51.061] <TB2> INFO: Test took 15372ms.
[13:23:51.084] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:51.084] <TB2> INFO: run 2 of 2
[13:24:06.571] <TB2> INFO: Test took 15487ms.
[13:24:06.591] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:06.591] <TB2> INFO: dacScan step from 20 .. 39
[13:24:06.591] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:24:06.591] <TB2> INFO: run 1 of 2
[13:24:21.429] <TB2> INFO: Test took 14838ms.
[13:24:21.449] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:21.449] <TB2> INFO: run 2 of 2
[13:24:36.529] <TB2> INFO: Test took 15080ms.
[13:24:36.550] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:36.550] <TB2> INFO: dacScan step from 40 .. 59
[13:24:36.550] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:24:36.550] <TB2> INFO: run 1 of 2
[13:24:51.657] <TB2> INFO: Test took 15107ms.
[13:24:51.678] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:51.678] <TB2> INFO: run 2 of 2
[13:25:07.010] <TB2> INFO: Test took 15332ms.
[13:25:07.031] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:07.031] <TB2> INFO: dacScan step from 60 .. 79
[13:25:07.031] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:25:07.031] <TB2> INFO: run 1 of 2
[13:25:22.934] <TB2> INFO: Test took 15903ms.
[13:25:22.957] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:22.957] <TB2> INFO: run 2 of 2
[13:25:38.306] <TB2> INFO: Test took 15349ms.
[13:25:38.331] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:38.331] <TB2> INFO: dacScan step from 80 .. 99
[13:25:38.331] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:25:38.331] <TB2> INFO: run 1 of 2
[13:25:53.536] <TB2> INFO: Test took 15205ms.
[13:25:53.568] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:53.568] <TB2> INFO: run 2 of 2
[13:26:09.222] <TB2> INFO: Test took 15653ms.
[13:26:09.255] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:26:09.256] <TB2> INFO: dacScan step from 100 .. 119
[13:26:09.256] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:26:09.256] <TB2> INFO: run 1 of 2
[13:26:27.750] <TB2> INFO: Test took 18494ms.
[13:26:27.873] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:26:27.899] <TB2> INFO: run 2 of 2
[13:26:47.066] <TB2> INFO: Test took 19167ms.
[13:26:47.185] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:26:47.205] <TB2> INFO: dacScan step from 120 .. 139
[13:26:47.205] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:26:47.205] <TB2> INFO: run 1 of 2
[13:27:06.879] <TB2> INFO: Test took 19674ms.
[13:27:07.064] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:27:07.108] <TB2> INFO: run 2 of 2
[13:27:27.321] <TB2> INFO: Test took 20213ms.
[13:27:27.498] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:27:27.527] <TB2> INFO: dacScan step from 140 .. 159
[13:27:27.527] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:27:27.527] <TB2> INFO: run 1 of 2
[13:27:48.903] <TB2> INFO: Test took 21376ms.
[13:27:49.072] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:27:49.121] <TB2> INFO: run 2 of 2
[13:28:08.218] <TB2> INFO: Test took 19097ms.
[13:28:08.480] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:08.531] <TB2> INFO: dacScan step from 160 .. 179
[13:28:08.531] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:28:08.531] <TB2> INFO: run 1 of 2
[13:28:28.890] <TB2> INFO: Test took 20359ms.
[13:28:29.050] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:29.078] <TB2> INFO: run 2 of 2
[13:28:50.530] <TB2> INFO: Test took 21451ms.
[13:28:50.699] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:28:50.735] <TB2> INFO: dacScan step from 180 .. 199
[13:28:50.735] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:28:50.735] <TB2> INFO: run 1 of 2
[13:29:12.877] <TB2> INFO: Test took 22142ms.
[13:29:13.055] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:29:13.089] <TB2> INFO: run 2 of 2
[13:29:34.704] <TB2> INFO: Test took 21615ms.
[13:29:34.911] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:01.445] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 167 (20/5) hits flags = 16 (plus default)
[13:30:01.455] <TB2> INFO: dacScan step from 0 .. 19
[13:30:01.455] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:30:01.455] <TB2> INFO: run 1 of 2
[13:30:16.448] <TB2> INFO: Test took 14993ms.
[13:30:16.474] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:16.474] <TB2> INFO: run 2 of 2
[13:30:31.632] <TB2> INFO: Test took 15158ms.
[13:30:31.660] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:31.660] <TB2> INFO: dacScan step from 20 .. 39
[13:30:31.660] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:30:31.660] <TB2> INFO: run 1 of 2
[13:30:46.944] <TB2> INFO: Test took 15284ms.
[13:30:46.972] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:30:46.972] <TB2> INFO: run 2 of 2
[13:31:02.107] <TB2> INFO: Test took 15135ms.
[13:31:02.134] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:02.134] <TB2> INFO: dacScan step from 40 .. 59
[13:31:02.134] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:31:02.134] <TB2> INFO: run 1 of 2
[13:31:17.402] <TB2> INFO: Test took 15268ms.
[13:31:17.430] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:17.430] <TB2> INFO: run 2 of 2
[13:31:32.557] <TB2> INFO: Test took 15127ms.
[13:31:32.581] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:32.581] <TB2> INFO: dacScan step from 60 .. 79
[13:31:32.581] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:31:32.581] <TB2> INFO: run 1 of 2
[13:31:48.944] <TB2> INFO: Test took 16363ms.
[13:31:48.973] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:31:48.973] <TB2> INFO: run 2 of 2
[13:32:05.336] <TB2> INFO: Test took 16363ms.
[13:32:05.361] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:32:05.361] <TB2> INFO: dacScan step from 80 .. 99
[13:32:05.361] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:32:05.361] <TB2> INFO: run 1 of 2
[13:32:20.965] <TB2> INFO: Test took 15604ms.
[13:32:21.015] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:32:21.022] <TB2> INFO: run 2 of 2
[13:32:36.580] <TB2> INFO: Test took 15558ms.
[13:32:36.625] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:32:36.631] <TB2> INFO: dacScan step from 100 .. 119
[13:32:36.631] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:32:36.631] <TB2> INFO: run 1 of 2
[13:32:56.474] <TB2> INFO: Test took 19843ms.
[13:32:56.660] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:32:56.695] <TB2> INFO: run 2 of 2
[13:33:15.520] <TB2> INFO: Test took 18824ms.
[13:33:15.701] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:15.739] <TB2> INFO: dacScan step from 120 .. 139
[13:33:15.739] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:33:15.739] <TB2> INFO: run 1 of 2
[13:33:36.737] <TB2> INFO: Test took 20998ms.
[13:33:36.906] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:36.939] <TB2> INFO: run 2 of 2
[13:33:58.181] <TB2> INFO: Test took 21242ms.
[13:33:58.345] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:33:58.379] <TB2> INFO: dacScan step from 140 .. 159
[13:33:58.379] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:33:58.379] <TB2> INFO: run 1 of 2
[13:34:19.414] <TB2> INFO: Test took 21035ms.
[13:34:19.583] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:19.618] <TB2> INFO: run 2 of 2
[13:34:38.342] <TB2> INFO: Test took 18724ms.
[13:34:38.501] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:38.537] <TB2> INFO: dacScan step from 160 .. 167
[13:34:38.537] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:34:38.537] <TB2> INFO: run 1 of 2
[13:34:48.342] <TB2> INFO: Test took 9805ms.
[13:34:48.409] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:34:48.425] <TB2> INFO: run 2 of 2
[13:34:58.786] <TB2> INFO: Test took 10361ms.
[13:34:58.861] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:25.340] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 155 (20/5) hits flags = 16 (plus default)
[13:35:25.349] <TB2> INFO: dacScan step from 0 .. 19
[13:35:25.349] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:35:25.349] <TB2> INFO: run 1 of 2
[13:35:41.484] <TB2> INFO: Test took 16135ms.
[13:35:41.509] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:41.509] <TB2> INFO: run 2 of 2
[13:35:57.670] <TB2> INFO: Test took 16161ms.
[13:35:57.696] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:35:57.696] <TB2> INFO: dacScan step from 20 .. 39
[13:35:57.696] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:35:57.696] <TB2> INFO: run 1 of 2
[13:36:13.896] <TB2> INFO: Test took 16200ms.
[13:36:13.921] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:13.921] <TB2> INFO: run 2 of 2
[13:36:30.137] <TB2> INFO: Test took 16215ms.
[13:36:30.164] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:30.164] <TB2> INFO: dacScan step from 40 .. 59
[13:36:30.164] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:36:30.164] <TB2> INFO: run 1 of 2
[13:36:46.504] <TB2> INFO: Test took 16340ms.
[13:36:46.529] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:46.529] <TB2> INFO: run 2 of 2
[13:37:02.311] <TB2> INFO: Test took 15782ms.
[13:37:02.334] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:02.334] <TB2> INFO: dacScan step from 60 .. 79
[13:37:02.334] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:37:02.334] <TB2> INFO: run 1 of 2
[13:37:18.302] <TB2> INFO: Test took 15968ms.
[13:37:18.324] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:18.324] <TB2> INFO: run 2 of 2
[13:37:34.524] <TB2> INFO: Test took 16201ms.
[13:37:34.552] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:34.552] <TB2> INFO: dacScan step from 80 .. 99
[13:37:34.552] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:37:34.552] <TB2> INFO: run 1 of 2
[13:37:50.581] <TB2> INFO: Test took 16029ms.
[13:37:50.626] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:50.636] <TB2> INFO: run 2 of 2
[13:38:06.222] <TB2> INFO: Test took 15586ms.
[13:38:06.267] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:06.273] <TB2> INFO: dacScan step from 100 .. 119
[13:38:06.273] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:38:06.273] <TB2> INFO: run 1 of 2
[13:38:25.295] <TB2> INFO: Test took 19022ms.
[13:38:25.481] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:25.513] <TB2> INFO: run 2 of 2
[13:38:43.095] <TB2> INFO: Test took 17581ms.
[13:38:43.246] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:43.271] <TB2> INFO: dacScan step from 120 .. 139
[13:38:43.271] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:38:43.271] <TB2> INFO: run 1 of 2
[13:39:02.640] <TB2> INFO: Test took 19369ms.
[13:39:02.901] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:02.951] <TB2> INFO: run 2 of 2
[13:39:22.455] <TB2> INFO: Test took 19504ms.
[13:39:22.655] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:22.692] <TB2> INFO: dacScan step from 140 .. 155
[13:39:22.692] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:39:22.692] <TB2> INFO: run 1 of 2
[13:39:39.978] <TB2> INFO: Test took 17286ms.
[13:39:40.130] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:40.160] <TB2> INFO: run 2 of 2
[13:39:58.196] <TB2> INFO: Test took 18036ms.
[13:39:58.341] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:21.770] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 155 (20/5) hits flags = 16 (plus default)
[13:40:21.778] <TB2> INFO: dacScan step from 0 .. 19
[13:40:21.778] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:40:21.778] <TB2> INFO: run 1 of 2
[13:40:36.305] <TB2> INFO: Test took 14526ms.
[13:40:36.325] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:36.325] <TB2> INFO: run 2 of 2
[13:40:52.272] <TB2> INFO: Test took 15947ms.
[13:40:52.294] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:52.294] <TB2> INFO: dacScan step from 20 .. 39
[13:40:52.294] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:40:52.294] <TB2> INFO: run 1 of 2
[13:41:08.469] <TB2> INFO: Test took 16175ms.
[13:41:08.494] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:08.494] <TB2> INFO: run 2 of 2
[13:41:24.531] <TB2> INFO: Test took 16037ms.
[13:41:24.555] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:24.555] <TB2> INFO: dacScan step from 40 .. 59
[13:41:24.555] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:41:24.555] <TB2> INFO: run 1 of 2
[13:41:40.709] <TB2> INFO: Test took 16154ms.
[13:41:40.733] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:40.733] <TB2> INFO: run 2 of 2
[13:41:56.997] <TB2> INFO: Test took 16264ms.
[13:41:57.023] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:57.023] <TB2> INFO: dacScan step from 60 .. 79
[13:41:57.023] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:41:57.023] <TB2> INFO: run 1 of 2
[13:42:13.074] <TB2> INFO: Test took 16051ms.
[13:42:13.100] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:13.100] <TB2> INFO: run 2 of 2
[13:42:29.168] <TB2> INFO: Test took 16068ms.
[13:42:29.193] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:29.193] <TB2> INFO: dacScan step from 80 .. 99
[13:42:29.193] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:42:29.193] <TB2> INFO: run 1 of 2
[13:42:45.952] <TB2> INFO: Test took 16759ms.
[13:42:45.995] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:46.001] <TB2> INFO: run 2 of 2
[13:43:02.804] <TB2> INFO: Test took 16803ms.
[13:43:02.856] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:02.863] <TB2> INFO: dacScan step from 100 .. 119
[13:43:02.863] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:43:02.863] <TB2> INFO: run 1 of 2
[13:43:22.650] <TB2> INFO: Test took 19787ms.
[13:43:22.804] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:22.829] <TB2> INFO: run 2 of 2
[13:43:41.221] <TB2> INFO: Test took 18392ms.
[13:43:41.368] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:41.393] <TB2> INFO: dacScan step from 120 .. 139
[13:43:41.393] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:43:41.393] <TB2> INFO: run 1 of 2
[13:44:00.386] <TB2> INFO: Test took 18993ms.
[13:44:00.561] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:00.593] <TB2> INFO: run 2 of 2
[13:44:19.514] <TB2> INFO: Test took 18921ms.
[13:44:19.680] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:19.712] <TB2> INFO: dacScan step from 140 .. 155
[13:44:19.712] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:44:19.712] <TB2> INFO: run 1 of 2
[13:44:36.414] <TB2> INFO: Test took 16702ms.
[13:44:36.564] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:36.587] <TB2> INFO: run 2 of 2
[13:44:54.490] <TB2> INFO: Test took 17903ms.
[13:44:54.623] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:16.646] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 155 (20/5) hits flags = 16 (plus default)
[13:45:16.654] <TB2> INFO: dacScan step from 0 .. 19
[13:45:16.654] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:45:16.654] <TB2> INFO: run 1 of 2
[13:45:33.168] <TB2> INFO: Test took 16514ms.
[13:45:33.193] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:33.193] <TB2> INFO: run 2 of 2
[13:45:49.355] <TB2> INFO: Test took 16161ms.
[13:45:49.381] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:49.381] <TB2> INFO: dacScan step from 20 .. 39
[13:45:49.381] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:45:49.381] <TB2> INFO: run 1 of 2
[13:46:05.206] <TB2> INFO: Test took 15825ms.
[13:46:05.232] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:05.232] <TB2> INFO: run 2 of 2
[13:46:19.675] <TB2> INFO: Test took 14443ms.
[13:46:19.698] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:19.698] <TB2> INFO: dacScan step from 40 .. 59
[13:46:19.698] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:46:19.698] <TB2> INFO: run 1 of 2
[13:46:34.082] <TB2> INFO: Test took 14384ms.
[13:46:34.102] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:34.102] <TB2> INFO: run 2 of 2
[13:46:49.815] <TB2> INFO: Test took 15713ms.
[13:46:49.842] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:49.842] <TB2> INFO: dacScan step from 60 .. 79
[13:46:49.842] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:46:49.842] <TB2> INFO: run 1 of 2
[13:47:05.581] <TB2> INFO: Test took 15739ms.
[13:47:05.610] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:05.611] <TB2> INFO: run 2 of 2
[13:47:21.335] <TB2> INFO: Test took 15724ms.
[13:47:21.370] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:21.370] <TB2> INFO: dacScan step from 80 .. 99
[13:47:21.370] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:47:21.370] <TB2> INFO: run 1 of 2
[13:47:37.530] <TB2> INFO: Test took 16159ms.
[13:47:37.577] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:37.583] <TB2> INFO: run 2 of 2
[13:47:54.007] <TB2> INFO: Test took 16424ms.
[13:47:54.071] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:54.080] <TB2> INFO: dacScan step from 100 .. 119
[13:47:54.080] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:47:54.080] <TB2> INFO: run 1 of 2
[13:48:14.276] <TB2> INFO: Test took 20196ms.
[13:48:14.447] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:14.476] <TB2> INFO: run 2 of 2
[13:48:33.275] <TB2> INFO: Test took 18799ms.
[13:48:33.428] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:33.454] <TB2> INFO: dacScan step from 120 .. 139
[13:48:33.454] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:48:33.454] <TB2> INFO: run 1 of 2
[13:48:52.764] <TB2> INFO: Test took 19310ms.
[13:48:52.951] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:52.999] <TB2> INFO: run 2 of 2
[13:49:14.302] <TB2> INFO: Test took 21303ms.
[13:49:14.461] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:14.499] <TB2> INFO: dacScan step from 140 .. 155
[13:49:14.499] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[13:49:14.499] <TB2> INFO: run 1 of 2
[13:49:31.738] <TB2> INFO: Test took 17239ms.
[13:49:31.880] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:31.911] <TB2> INFO: run 2 of 2
[13:49:49.122] <TB2> INFO: Test took 17211ms.
[13:49:49.259] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:13.089] <TB2> INFO: PixTestTrim::trimBitTest() done
[13:50:13.090] <TB2> INFO: PixTestTrim::doTest() done, duration: 3000 seconds
[13:50:13.846] <TB2> INFO: ######################################################################
[13:50:13.846] <TB2> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[13:50:13.846] <TB2> INFO: ######################################################################
[13:50:17.277] <TB2> INFO: Test took 3428ms.
[13:50:17.303] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:21.235] <TB2> INFO: Test took 3732ms.
[13:50:21.307] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:25.028] <TB2> INFO: Test took 3709ms.
[13:50:25.089] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:25.096] <TB2> INFO: The DUT currently contains the following objects:
[13:50:25.096] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:25.096] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:25.096] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:25.096] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:25.096] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:25.096] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.235] <TB2> INFO: Test took 1139ms.
[13:50:26.237] <TB2> INFO: The DUT currently contains the following objects:
[13:50:26.237] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:26.237] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:26.237] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:26.237] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:26.237] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.237] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.238] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.238] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.238] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.238] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:26.238] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.346] <TB2> INFO: Test took 1108ms.
[13:50:27.347] <TB2> INFO: The DUT currently contains the following objects:
[13:50:27.347] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:27.347] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:27.347] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:27.347] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:27.348] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:27.348] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.456] <TB2> INFO: Test took 1108ms.
[13:50:28.458] <TB2> INFO: The DUT currently contains the following objects:
[13:50:28.458] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:28.458] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:28.458] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:28.458] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:28.458] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.458] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.459] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.459] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.459] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:28.459] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.593] <TB2> INFO: Test took 1134ms.
[13:50:29.594] <TB2> INFO: The DUT currently contains the following objects:
[13:50:29.594] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:29.595] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:29.595] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:29.595] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:29.595] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:29.595] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.714] <TB2> INFO: Test took 1119ms.
[13:50:30.714] <TB2> INFO: The DUT currently contains the following objects:
[13:50:30.714] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:30.714] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:30.714] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:30.715] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:30.715] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:30.715] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.823] <TB2> INFO: Test took 1108ms.
[13:50:31.824] <TB2> INFO: The DUT currently contains the following objects:
[13:50:31.824] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:31.824] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:31.824] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:31.825] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:31.825] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:31.825] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.931] <TB2> INFO: Test took 1106ms.
[13:50:32.932] <TB2> INFO: The DUT currently contains the following objects:
[13:50:32.932] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:32.932] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:32.932] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:32.932] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:32.932] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.932] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.932] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.932] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.932] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.932] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:32.933] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.040] <TB2> INFO: Test took 1107ms.
[13:50:34.042] <TB2> INFO: The DUT currently contains the following objects:
[13:50:34.042] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:34.042] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:34.042] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:34.042] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:34.042] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.042] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:34.043] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.151] <TB2> INFO: Test took 1108ms.
[13:50:35.153] <TB2> INFO: The DUT currently contains the following objects:
[13:50:35.153] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:35.153] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:35.153] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:35.153] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:35.153] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.153] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:35.154] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.262] <TB2> INFO: Test took 1108ms.
[13:50:36.263] <TB2> INFO: The DUT currently contains the following objects:
[13:50:36.263] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:36.263] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:36.263] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:36.263] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:36.263] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.263] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.263] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.263] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.263] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.263] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.263] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.263] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.263] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.263] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.264] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.264] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.264] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.264] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.264] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:36.264] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.371] <TB2> INFO: Test took 1107ms.
[13:50:37.372] <TB2> INFO: The DUT currently contains the following objects:
[13:50:37.372] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:37.372] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:37.372] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:37.372] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:37.372] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.372] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.373] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.373] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.373] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.373] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:37.373] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.481] <TB2> INFO: Test took 1108ms.
[13:50:38.482] <TB2> INFO: The DUT currently contains the following objects:
[13:50:38.482] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:38.482] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:38.482] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:38.482] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:38.482] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.482] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.482] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:38.483] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.589] <TB2> INFO: Test took 1107ms.
[13:50:39.591] <TB2> INFO: The DUT currently contains the following objects:
[13:50:39.591] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:39.591] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:39.591] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:39.591] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:39.591] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.591] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.591] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.591] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.591] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:39.592] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.697] <TB2> INFO: Test took 1105ms.
[13:50:40.699] <TB2> INFO: The DUT currently contains the following objects:
[13:50:40.699] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:40.699] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:40.699] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:40.699] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:40.699] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.699] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.700] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.700] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.700] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.700] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:40.700] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.806] <TB2> INFO: Test took 1106ms.
[13:50:41.807] <TB2> INFO: The DUT currently contains the following objects:
[13:50:41.807] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:50:41.807] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:50:41.807] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:50:41.807] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:50:41.808] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:41.808] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:50:42.914] <TB2> INFO: Test took 1106ms.
[13:50:42.919] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:54:04.308] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 4 readouts!
[13:54:04.308] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (1) != Token Chain Length (4)
[13:54:04.308] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (0) != Token Chain Length (4)
[13:54:04.308] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 12 readouts!
[13:54:04.308] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[13:54:04.308] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[13:54:13.358] <TB2> CRITICAL: <hal.cc/SingleRocOnePixelDacDacScan:L1547> Incomplete DAQ data readout! Missing -1 Events.
[13:54:13.395] <TB2> CRITICAL: <PixTestPhOptimization.cc/MaxPhVsDacDac:L868> pXar execption: Incomplete DAQ data readout in function SingleRocOnePixelDacDacScan
[13:54:13.395] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:58:16.913] <TB2> INFO: Test took 243518ms.
[13:58:18.501] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:01:39.757] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[14:01:39.757] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (1) != Token Chain Length (4)
[14:01:39.757] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (0) != Token Chain Length (4)
[14:01:39.757] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[14:01:39.757] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[14:01:39.757] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:01:48.652] <TB2> CRITICAL: <hal.cc/SingleRocOnePixelDacDacScan:L1547> Incomplete DAQ data readout! Missing -1 Events.
[14:01:48.722] <TB2> CRITICAL: <PixTestPhOptimization.cc/MinPhVsDacDac:L897> pXar execption: Incomplete DAQ data readout in function SingleRocOnePixelDacDacScan
[14:01:48.722] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:03:21.627] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 2 Event ID mismatch: local ID (71) != TBM ID (72)
[14:03:21.627] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (71) != TBM ID (72)
[14:03:21.627] <TB2> WARNING: Channel 2 ROC 0: Readback start marker after 15 readouts!
[14:03:21.627] <TB2> WARNING: Channel 2 ROC 1: Readback start marker after 15 readouts!
[14:03:21.627] <TB2> WARNING: Channel 2 ROC 2: Readback start marker after 15 readouts!
[14:03:21.627] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[14:03:21.627] <TB2> WARNING: Channel 3 ROC 0: Readback start marker after 15 readouts!
[14:03:21.627] <TB2> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[14:03:21.627] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[14:03:21.627] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:04:47.957] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[14:04:47.957] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:04:47.957] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[14:04:47.957] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:05:37.236] <TB2> INFO: Test took 228514ms.
[14:05:38.822] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.829] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.836] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.842] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.849] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.856] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.863] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.870] <TB2> INFO: safety margin for low PH: adding 1, margin is now 21
[14:05:38.877] <TB2> INFO: safety margin for low PH: adding 2, margin is now 22
[14:05:38.883] <TB2> INFO: safety margin for low PH: adding 3, margin is now 23
[14:05:38.890] <TB2> INFO: safety margin for low PH: adding 4, margin is now 24
[14:05:38.897] <TB2> INFO: safety margin for low PH: adding 5, margin is now 25
[14:05:38.903] <TB2> INFO: safety margin for low PH: adding 6, margin is now 26
[14:05:38.910] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.917] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.923] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.930] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.937] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.943] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.950] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.957] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:38.963] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[14:05:39.019] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C0.dat
[14:05:39.019] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C1.dat
[14:05:39.019] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C2.dat
[14:05:39.020] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C3.dat
[14:05:39.020] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C4.dat
[14:05:39.021] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C5.dat
[14:05:39.029] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C6.dat
[14:05:39.029] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C7.dat
[14:05:39.034] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C8.dat
[14:05:39.034] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C9.dat
[14:05:39.053] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C10.dat
[14:05:39.062] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C11.dat
[14:05:39.062] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C12.dat
[14:05:39.063] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C13.dat
[14:05:39.063] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C14.dat
[14:05:39.063] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//dacParameters35_C15.dat
[14:05:42.538] <TB2> INFO: Test took 3472ms.
[14:05:46.302] <TB2> INFO: Test took 3494ms.
[14:05:50.065] <TB2> INFO: Test took 3465ms.
[14:05:50.350] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:05:51.281] <TB2> INFO: Test took 932ms.
[14:05:51.284] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:05:52.393] <TB2> INFO: Test took 1109ms.
[14:05:52.397] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:05:53.506] <TB2> INFO: Test took 1109ms.
[14:05:53.509] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:05:54.617] <TB2> INFO: Test took 1108ms.
[14:05:54.620] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:05:55.740] <TB2> INFO: Test took 1120ms.
[14:05:55.744] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:05:56.850] <TB2> INFO: Test took 1107ms.
[14:05:56.853] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:05:57.959] <TB2> INFO: Test took 1106ms.
[14:05:57.963] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:05:59.071] <TB2> INFO: Test took 1108ms.
[14:05:59.075] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:00.182] <TB2> INFO: Test took 1108ms.
[14:06:00.186] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:01.293] <TB2> INFO: Test took 1107ms.
[14:06:01.297] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:02.417] <TB2> INFO: Test took 1121ms.
[14:06:02.420] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:03.529] <TB2> INFO: Test took 1109ms.
[14:06:03.533] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:04.639] <TB2> INFO: Test took 1106ms.
[14:06:04.643] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:05.749] <TB2> INFO: Test took 1106ms.
[14:06:05.753] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:06.860] <TB2> INFO: Test took 1107ms.
[14:06:06.863] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:07.974] <TB2> INFO: Test took 1111ms.
[14:06:07.979] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:09.088] <TB2> INFO: Test took 1109ms.
[14:06:09.091] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:10.197] <TB2> INFO: Test took 1106ms.
[14:06:10.199] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:11.307] <TB2> INFO: Test took 1108ms.
[14:06:11.310] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:12.419] <TB2> INFO: Test took 1109ms.
[14:06:12.422] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:13.532] <TB2> INFO: Test took 1111ms.
[14:06:13.537] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:14.658] <TB2> INFO: Test took 1122ms.
[14:06:14.661] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:15.768] <TB2> INFO: Test took 1107ms.
[14:06:15.772] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:16.880] <TB2> INFO: Test took 1108ms.
[14:06:16.883] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:17.995] <TB2> INFO: Test took 1112ms.
[14:06:18.000] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:19.107] <TB2> INFO: Test took 1107ms.
[14:06:19.110] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:20.217] <TB2> INFO: Test took 1107ms.
[14:06:20.220] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:21.328] <TB2> INFO: Test took 1108ms.
[14:06:21.332] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:22.444] <TB2> INFO: Test took 1112ms.
[14:06:22.449] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:23.558] <TB2> INFO: Test took 1110ms.
[14:06:23.563] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:24.674] <TB2> INFO: Test took 1113ms.
[14:06:24.679] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:25.791] <TB2> INFO: Test took 1113ms.
[14:06:26.322] <TB2> INFO: PixTestPhOptimization::doTest() done, duration: 972 seconds
[14:06:26.322] <TB2> INFO: PH scale (per ROC): 68 75 82 67 76 70 69 72 68 74 74 78 65 79 72 74
[14:06:26.322] <TB2> INFO: PH offset (per ROC): 177 180 174 181 187 175 176 158 179 175 181 183 176 160 174 171
[14:06:26.504] <TB2> INFO: ######################################################################
[14:06:26.504] <TB2> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[14:06:26.504] <TB2> INFO: ######################################################################
[14:06:26.514] <TB2> INFO: scanning low vcal = 10
[14:06:30.369] <TB2> INFO: Test took 3855ms.
[14:06:30.374] <TB2> INFO: scanning low vcal = 20
[14:06:34.250] <TB2> INFO: Test took 3876ms.
[14:06:34.257] <TB2> INFO: scanning low vcal = 30
[14:06:38.146] <TB2> INFO: Test took 3889ms.
[14:06:38.158] <TB2> INFO: scanning low vcal = 40
[14:06:42.547] <TB2> INFO: Test took 4353ms.
[14:06:42.606] <TB2> INFO: scanning low vcal = 50
[14:06:46.997] <TB2> INFO: Test took 4391ms.
[14:06:47.057] <TB2> INFO: scanning low vcal = 60
[14:06:51.414] <TB2> INFO: Test took 4357ms.
[14:06:51.481] <TB2> INFO: scanning low vcal = 70
[14:06:55.881] <TB2> INFO: Test took 4400ms.
[14:06:55.946] <TB2> INFO: scanning low vcal = 80
[14:07:00.412] <TB2> INFO: Test took 4466ms.
[14:07:00.469] <TB2> INFO: scanning low vcal = 90
[14:07:04.825] <TB2> INFO: Test took 4356ms.
[14:07:04.886] <TB2> INFO: scanning low vcal = 100
[14:07:09.308] <TB2> INFO: Test took 4422ms.
[14:07:09.365] <TB2> INFO: scanning low vcal = 110
[14:07:13.770] <TB2> INFO: Test took 4404ms.
[14:07:13.827] <TB2> INFO: scanning low vcal = 120
[14:07:18.202] <TB2> INFO: Test took 4375ms.
[14:07:18.266] <TB2> INFO: scanning low vcal = 130
[14:07:22.709] <TB2> INFO: Test took 4443ms.
[14:07:22.776] <TB2> INFO: scanning low vcal = 140
[14:07:27.219] <TB2> INFO: Test took 4443ms.
[14:07:27.318] <TB2> INFO: scanning low vcal = 150
[14:07:31.666] <TB2> INFO: Test took 4348ms.
[14:07:31.725] <TB2> INFO: scanning low vcal = 160
[14:07:36.126] <TB2> INFO: Test took 4401ms.
[14:07:36.222] <TB2> INFO: scanning low vcal = 170
[14:07:40.667] <TB2> INFO: Test took 4445ms.
[14:07:40.727] <TB2> INFO: scanning low vcal = 180
[14:07:45.053] <TB2> INFO: Test took 4326ms.
[14:07:45.114] <TB2> INFO: scanning low vcal = 190
[14:07:49.630] <TB2> INFO: Test took 4516ms.
[14:07:49.698] <TB2> INFO: scanning low vcal = 200
[14:07:54.177] <TB2> INFO: Test took 4479ms.
[14:07:54.276] <TB2> INFO: scanning low vcal = 210
[14:07:58.738] <TB2> INFO: Test took 4462ms.
[14:07:58.836] <TB2> INFO: scanning low vcal = 220
[14:08:03.304] <TB2> INFO: Test took 4468ms.
[14:08:03.385] <TB2> INFO: scanning low vcal = 230
[14:08:07.772] <TB2> INFO: Test took 4387ms.
[14:08:07.834] <TB2> INFO: scanning low vcal = 240
[14:08:12.244] <TB2> INFO: Test took 4410ms.
[14:08:12.305] <TB2> INFO: scanning low vcal = 250
[14:08:16.729] <TB2> INFO: Test took 4424ms.
[14:08:16.835] <TB2> INFO: scanning high vcal = 30 (= 210 in low range)
[14:08:21.205] <TB2> INFO: Test took 4370ms.
[14:08:21.265] <TB2> INFO: scanning high vcal = 50 (= 350 in low range)
[14:08:25.606] <TB2> INFO: Test took 4341ms.
[14:08:25.666] <TB2> INFO: scanning high vcal = 70 (= 490 in low range)
[14:08:30.019] <TB2> INFO: Test took 4353ms.
[14:08:30.077] <TB2> INFO: scanning high vcal = 90 (= 630 in low range)
[14:08:34.405] <TB2> INFO: Test took 4328ms.
[14:08:34.465] <TB2> INFO: scanning high vcal = 200 (= 1400 in low range)
[14:08:38.806] <TB2> INFO: Test took 4341ms.
[14:08:39.274] <TB2> INFO: PixTestGainPedestal::measure() done
[14:09:11.966] <TB2> INFO: PixTestGainPedestal::fit() done
[14:09:11.966] <TB2> INFO: non-linearity mean: 0.962 0.958 0.958 0.961 0.959 0.960 0.963 0.953 0.955 0.955 0.961 0.959 0.954 0.956 0.955 0.953
[14:09:11.966] <TB2> INFO: non-linearity RMS: 0.006 0.008 0.006 0.007 0.006 0.006 0.005 0.007 0.007 0.006 0.006 0.005 0.008 0.007 0.006 0.007
[14:09:11.966] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C0.dat
[14:09:11.987] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C1.dat
[14:09:12.006] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C2.dat
[14:09:12.025] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C3.dat
[14:09:12.044] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C4.dat
[14:09:12.063] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C5.dat
[14:09:12.082] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C6.dat
[14:09:12.101] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C7.dat
[14:09:12.120] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C8.dat
[14:09:12.139] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C9.dat
[14:09:12.158] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C10.dat
[14:09:12.177] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C11.dat
[14:09:12.196] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C12.dat
[14:09:12.215] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C13.dat
[14:09:12.233] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C14.dat
[14:09:12.252] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//phCalibrationFitErr35_C15.dat
[14:09:12.270] <TB2> INFO: PixTestGainPedestal::doTest() done, duration: 165 seconds
[14:09:12.276] <TB2> INFO: readReadbackCal: /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C0.dat .. /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C15.dat
[14:09:12.294] <TB2> INFO: PixTestReadback::doTest() start.
[14:09:12.295] <TB2> INFO: PixTestReadback::RES sent once
[14:09:28.815] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C0.dat
[14:09:28.815] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C1.dat
[14:09:28.815] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C2.dat
[14:09:28.815] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C3.dat
[14:09:28.815] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C4.dat
[14:09:28.815] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C5.dat
[14:09:28.815] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C6.dat
[14:09:28.815] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C7.dat
[14:09:28.816] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C8.dat
[14:09:28.816] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C9.dat
[14:09:28.816] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C10.dat
[14:09:28.816] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C11.dat
[14:09:28.816] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C12.dat
[14:09:28.816] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C13.dat
[14:09:28.816] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C14.dat
[14:09:28.816] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C15.dat
[14:09:28.840] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[14:09:28.841] <TB2> INFO: PixTestReadback::RES sent once
[14:09:45.275] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C0.dat
[14:09:45.275] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C1.dat
[14:09:45.275] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C2.dat
[14:09:45.275] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C3.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C4.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C5.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C6.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C7.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C8.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C9.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C10.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C11.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C12.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C13.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C14.dat
[14:09:45.276] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C15.dat
[14:09:45.308] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[14:09:45.309] <TB2> INFO: PixTestReadback::RES sent once
[14:09:58.025] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[14:09:58.026] <TB2> INFO: Vbg will be calibrated using Vd calibration
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 154.8calibrated Vbg = 1.20785 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 153.1calibrated Vbg = 1.20121 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 157.1calibrated Vbg = 1.21249 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 146.1calibrated Vbg = 1.22786 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 149.2calibrated Vbg = 1.22864 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 151.1calibrated Vbg = 1.23229 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 167.2calibrated Vbg = 1.22674 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 153calibrated Vbg = 1.22974 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 154.5calibrated Vbg = 1.22099 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 160.3calibrated Vbg = 1.20993 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 146.1calibrated Vbg = 1.21335 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 154.6calibrated Vbg = 1.21499 :::*/*/*/*/
[14:09:58.026] <TB2> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[14:09:58.029] <TB2> INFO: PixTestReadback::RES sent once
[14:13:52.367] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C0.dat
[14:13:52.367] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C1.dat
[14:13:52.367] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C2.dat
[14:13:52.367] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C3.dat
[14:13:52.367] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C4.dat
[14:13:52.367] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C5.dat
[14:13:52.367] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C6.dat
[14:13:52.367] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C7.dat
[14:13:52.367] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C8.dat
[14:13:52.368] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C9.dat
[14:13:52.368] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C10.dat
[14:13:52.368] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C11.dat
[14:13:52.368] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C12.dat
[14:13:52.368] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C13.dat
[14:13:52.368] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C14.dat
[14:13:52.368] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2082_FullQualification_2015-08-24_09h18m_1440400713//004_FulltestPxar_p17//readbackCal_C15.dat
[14:13:52.395] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[14:13:52.396] <TB2> INFO: PixTestReadback::doTest() done
[14:13:52.408] <TB2> INFO: enter test to run
[14:13:52.408] <TB2> INFO: test: exit no parameter change
[14:13:52.985] <TB2> QUIET: Connection to board 156 closed.
[14:13:53.065] <TB2> INFO: pXar: this is the end, my friend