[14:02:34.929] <TB3> INFO: *** Welcome to pxar ***
[14:02:34.929] <TB3> INFO: *** Today: 2015/08/06
[14:02:34.929] <TB3> INFO: readRocDacs: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C15.dat
[14:02:34.930] <TB3> INFO: readTbmDacs: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//tbmParameters_C0b.dat
[14:02:34.931] <TB3> INFO: readMaskFile: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//defaultMaskFile.dat
[14:02:34.931] <TB3> INFO: readTrimFile: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters_C15.dat
[14:02:35.017] <TB3> INFO: clk: 4
[14:02:35.017] <TB3> INFO: ctr: 4
[14:02:35.017] <TB3> INFO: sda: 19
[14:02:35.017] <TB3> INFO: tin: 9
[14:02:35.017] <TB3> INFO: level: 15
[14:02:35.017] <TB3> INFO: triggerdelay: 0
[14:02:35.017] <TB3> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[14:02:35.017] <TB3> INFO: Log level: INFO
[14:02:35.036] <TB3> INFO: Found DTB DTB_WZ4I6J
[14:02:35.052] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[14:02:35.055] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 170
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WZ4I6J
MAC address: 40D8551180AA
Hostname: pixelDTB170
Comment:
------------------------------------------------------
[14:02:35.058] <TB3> INFO: RPC call hashes of host and DTB match: 447413373
[14:02:36.603] <TB3> INFO: DUT info:
[14:02:36.603] <TB3> INFO: The DUT currently contains the following objects:
[14:02:36.603] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[14:02:36.603] <TB3> INFO: TBM Core alpha (0): 7 registers set
[14:02:36.603] <TB3> INFO: TBM Core beta (1): 7 registers set
[14:02:36.603] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:02:36.603] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.603] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.603] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:36.604] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:37.005] <TB3> INFO: enter 'restricted' command line mode
[14:02:37.005] <TB3> INFO: enter test to run
[14:02:37.005] <TB3> INFO: test: pretest no parameter change
[14:02:37.005] <TB3> INFO: running: pretest
[14:02:37.012] <TB3> INFO: ######################################################################
[14:02:37.012] <TB3> INFO: PixTestPretest::doTest()
[14:02:37.012] <TB3> INFO: ######################################################################
[14:02:37.014] <TB3> INFO: ----------------------------------------------------------------------
[14:02:37.014] <TB3> INFO: PixTestPretest::programROC()
[14:02:37.014] <TB3> INFO: ----------------------------------------------------------------------
[14:02:55.045] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[14:02:55.045] <TB3> INFO: IA differences per ROC: 20.9 19.3 19.3 19.3 18.5 19.3 18.5 18.5 18.5 19.3 17.7 20.1 20.9 17.7 19.3 18.5
[14:02:55.104] <TB3> INFO: ----------------------------------------------------------------------
[14:02:55.104] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[14:02:55.104] <TB3> INFO: ----------------------------------------------------------------------
[14:02:59.258] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[14:02:59.262] <TB3> INFO: ----------------------------------------------------------------------
[14:02:59.262] <TB3> INFO: PixTestPretest::findWorkingPixel()
[14:02:59.262] <TB3> INFO: ----------------------------------------------------------------------
[14:03:07.982] <TB3> INFO: Test took 8715ms.
[14:03:08.292] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[14:03:08.312] <TB3> INFO: ----------------------------------------------------------------------
[14:03:08.312] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[14:03:08.312] <TB3> INFO: ----------------------------------------------------------------------
[14:03:17.041] <TB3> INFO: Test took 8725ms.
[14:03:17.333] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[14:03:17.333] <TB3> INFO: CalDel: 160 160 168 151 147 139 156 152 132 127 127 130 128 143 130 139
[14:03:17.333] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[14:03:17.337] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C0.dat
[14:03:17.337] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C1.dat
[14:03:17.337] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C2.dat
[14:03:17.337] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C3.dat
[14:03:17.338] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C4.dat
[14:03:17.338] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C5.dat
[14:03:17.338] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C6.dat
[14:03:17.338] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C7.dat
[14:03:17.339] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C8.dat
[14:03:17.339] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C9.dat
[14:03:17.339] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C10.dat
[14:03:17.339] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C11.dat
[14:03:17.339] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C12.dat
[14:03:17.340] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C13.dat
[14:03:17.340] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C14.dat
[14:03:17.340] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C15.dat
[14:03:17.340] <TB3> INFO: PixTestPretest::doTest() done, duration: 40 seconds
[14:03:17.428] <TB3> INFO: enter test to run
[14:03:17.428] <TB3> INFO: test: fulltest no parameter change
[14:03:17.428] <TB3> INFO: running: fulltest
[14:03:17.428] <TB3> INFO: ######################################################################
[14:03:17.428] <TB3> INFO: PixTestFullTest::doTest()
[14:03:17.428] <TB3> INFO: ######################################################################
[14:03:17.430] <TB3> INFO: ######################################################################
[14:03:17.430] <TB3> INFO: PixTestAlive::doTest()
[14:03:17.430] <TB3> INFO: ######################################################################
[14:03:17.431] <TB3> INFO: ----------------------------------------------------------------------
[14:03:17.431] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:03:17.431] <TB3> INFO: ----------------------------------------------------------------------
[14:03:20.983] <TB3> INFO: Test took 3550ms.
[14:03:21.008] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:21.219] <TB3> INFO: PixTestAlive::aliveTest() done
[14:03:21.219] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[14:03:21.221] <TB3> INFO: ----------------------------------------------------------------------
[14:03:21.222] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:03:21.222] <TB3> INFO: ----------------------------------------------------------------------
[14:03:24.083] <TB3> INFO: Test took 2861ms.
[14:03:24.086] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:24.087] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[14:03:24.301] <TB3> INFO: PixTestAlive::maskTest() done
[14:03:24.301] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:03:24.303] <TB3> INFO: ----------------------------------------------------------------------
[14:03:24.303] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:03:24.303] <TB3> INFO: ----------------------------------------------------------------------
[14:03:27.850] <TB3> INFO: Test took 3547ms.
[14:03:27.878] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:28.089] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[14:03:28.089] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:03:28.089] <TB3> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[14:03:28.096] <TB3> INFO: ######################################################################
[14:03:28.096] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[14:03:28.096] <TB3> INFO: ######################################################################
[14:03:28.097] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[14:03:28.108] <TB3> INFO: dacScan step from 0 .. 29
[14:03:50.643] <TB3> INFO: Test took 22535ms.
[14:03:50.675] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:50.675] <TB3> INFO: dacScan step from 30 .. 59
[14:04:14.632] <TB3> INFO: Test took 23957ms.
[14:04:14.737] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:14.748] <TB3> INFO: dacScan step from 60 .. 89
[14:04:45.383] <TB3> INFO: Test took 30635ms.
[14:04:45.628] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:45.712] <TB3> INFO: dacScan step from 90 .. 119
[14:05:16.542] <TB3> INFO: Test took 30830ms.
[14:05:16.789] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:16.867] <TB3> INFO: dacScan step from 120 .. 149
[14:05:44.482] <TB3> INFO: Test took 27615ms.
[14:05:44.690] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:09.393] <TB3> INFO: PixTestBBMap::doTest() done, duration: 161 seconds
[14:06:09.393] <TB3> INFO: number of dead bumps (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[14:06:09.393] <TB3> INFO: separation cut (per ROC): 68 66 100 92 101 90 73 85 86 98 89 105 103 87 92 102
[14:06:09.464] <TB3> INFO: ######################################################################
[14:06:09.464] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50
[14:06:09.464] <TB3> INFO: ######################################################################
[14:06:09.464] <TB3> INFO: ----------------------------------------------------------------------
[14:06:09.464] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[14:06:09.464] <TB3> INFO: ----------------------------------------------------------------------
[14:06:09.464] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[14:06:09.474] <TB3> INFO: dacScan step from 0 .. 3
[14:06:28.009] <TB3> INFO: Test took 18535ms.
[14:06:28.046] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:28.046] <TB3> INFO: dacScan step from 4 .. 7
[14:06:47.316] <TB3> INFO: Test took 19270ms.
[14:06:47.348] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:47.348] <TB3> INFO: dacScan step from 8 .. 11
[14:07:06.700] <TB3> INFO: Test took 19352ms.
[14:07:06.726] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:06.726] <TB3> INFO: dacScan step from 12 .. 15
[14:07:25.365] <TB3> INFO: Test took 18638ms.
[14:07:25.390] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:25.390] <TB3> INFO: dacScan step from 16 .. 19
[14:07:45.739] <TB3> INFO: Test took 20349ms.
[14:07:45.770] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:45.770] <TB3> INFO: dacScan step from 20 .. 23
[14:08:06.006] <TB3> INFO: Test took 20236ms.
[14:08:06.030] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:06.030] <TB3> INFO: dacScan step from 24 .. 27
[14:08:26.502] <TB3> INFO: Test took 20472ms.
[14:08:26.528] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:26.528] <TB3> INFO: dacScan step from 28 .. 31
[14:08:47.044] <TB3> INFO: Test took 20516ms.
[14:08:47.070] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:47.070] <TB3> INFO: dacScan step from 32 .. 35
[14:09:07.371] <TB3> INFO: Test took 20301ms.
[14:09:07.397] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:07.397] <TB3> INFO: dacScan step from 36 .. 39
[14:09:27.656] <TB3> INFO: Test took 20259ms.
[14:09:27.682] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:27.682] <TB3> INFO: dacScan step from 40 .. 43
[14:09:48.121] <TB3> INFO: Test took 20439ms.
[14:09:48.149] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:48.149] <TB3> INFO: dacScan step from 44 .. 47
[14:10:08.627] <TB3> INFO: Test took 20478ms.
[14:10:08.653] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:08.654] <TB3> INFO: dacScan step from 48 .. 51
[14:10:28.946] <TB3> INFO: Test took 20292ms.
[14:10:28.970] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:28.970] <TB3> INFO: dacScan step from 52 .. 55
[14:10:49.150] <TB3> INFO: Test took 20180ms.
[14:10:49.180] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:49.180] <TB3> INFO: dacScan step from 56 .. 59
[14:11:09.631] <TB3> INFO: Test took 20450ms.
[14:11:09.661] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:09.661] <TB3> INFO: dacScan step from 60 .. 63
[14:11:30.312] <TB3> INFO: Test took 20651ms.
[14:11:30.340] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:30.340] <TB3> INFO: dacScan step from 64 .. 67
[14:11:50.770] <TB3> INFO: Test took 20430ms.
[14:11:50.800] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:50.800] <TB3> INFO: dacScan step from 68 .. 71
[14:12:11.165] <TB3> INFO: Test took 20365ms.
[14:12:11.197] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:11.197] <TB3> INFO: dacScan step from 72 .. 75
[14:12:31.616] <TB3> INFO: Test took 20419ms.
[14:12:31.655] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:31.655] <TB3> INFO: dacScan step from 76 .. 79
[14:12:52.542] <TB3> INFO: Test took 20886ms.
[14:12:52.582] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:52.583] <TB3> INFO: dacScan step from 80 .. 83
[14:13:14.684] <TB3> INFO: Test took 22101ms.
[14:13:14.764] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:14.767] <TB3> INFO: dacScan step from 84 .. 87
[14:13:38.188] <TB3> INFO: Test took 23420ms.
[14:13:38.287] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:38.292] <TB3> INFO: dacScan step from 88 .. 91
[14:14:03.077] <TB3> INFO: Test took 24785ms.
[14:14:03.207] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:03.216] <TB3> INFO: dacScan step from 92 .. 95
[14:14:30.442] <TB3> INFO: Test took 27226ms.
[14:14:30.616] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:30.628] <TB3> INFO: dacScan step from 96 .. 99
[14:15:00.089] <TB3> INFO: Test took 29461ms.
[14:15:00.289] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:00.300] <TB3> INFO: dacScan step from 100 .. 103
[14:15:31.051] <TB3> INFO: Test took 30751ms.
[14:15:31.272] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:31.285] <TB3> INFO: dacScan step from 104 .. 107
[14:16:02.468] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:16:02.468] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:16:02.899] <TB3> INFO: Test took 31614ms.
[14:16:03.145] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:03.156] <TB3> INFO: dacScan step from 108 .. 111
[14:16:34.318] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:16:35.387] <TB3> INFO: Test took 32230ms.
[14:16:35.605] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:35.617] <TB3> INFO: dacScan step from 112 .. 115
[14:17:06.621] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:17:06.621] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:17:08.055] <TB3> INFO: Test took 32438ms.
[14:17:08.274] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:08.286] <TB3> INFO: dacScan step from 116 .. 119
[14:17:39.282] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:17:40.767] <TB3> INFO: Test took 32481ms.
[14:17:41.014] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:41.027] <TB3> INFO: dacScan step from 120 .. 123
[14:18:11.666] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:18:13.168] <TB3> INFO: Test took 32141ms.
[14:18:13.413] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:13.426] <TB3> INFO: dacScan step from 124 .. 127
[14:18:43.852] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:18:43.852] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:18:45.259] <TB3> INFO: Test took 31833ms.
[14:18:45.496] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:45.508] <TB3> INFO: dacScan step from 128 .. 131
[14:19:16.125] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:19:16.125] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:19:17.555] <TB3> INFO: Test took 32047ms.
[14:19:17.812] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:17.825] <TB3> INFO: dacScan step from 132 .. 135
[14:19:48.874] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[14:19:48.874] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (195) != TBM ID (196)
[14:19:48.874] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[14:19:48.874] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[14:19:48.874] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:19:50.285] <TB3> INFO: Test took 32460ms.
[14:19:50.516] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:50.527] <TB3> INFO: dacScan step from 136 .. 139
[14:20:22.783] <TB3> INFO: Test took 32256ms.
[14:20:23.031] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:23.043] <TB3> INFO: dacScan step from 140 .. 143
[14:20:54.736] <TB3> INFO: Test took 31693ms.
[14:20:54.958] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:54.968] <TB3> INFO: dacScan step from 144 .. 147
[14:21:27.234] <TB3> INFO: Test took 32266ms.
[14:21:27.448] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:27.460] <TB3> INFO: dacScan step from 148 .. 149
[14:21:44.815] <TB3> INFO: Test took 17355ms.
[14:21:44.937] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:44.943] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:46.318] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:47.722] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:49.069] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:50.434] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:51.754] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:53.118] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:54.488] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:55.872] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:57.240] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:58.563] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:21:59.906] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:22:01.241] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:22:02.614] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:22:03.981] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:22:05.418] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[14:22:06.790] <TB3> INFO: PixTestScurves::scurves() done
[14:22:06.790] <TB3> INFO: Vcal mean: 88.72 80.28 99.66 92.97 108.22 89.79 94.19 94.48 90.04 105.92 96.71 101.25 100.38 86.75 91.72 96.47
[14:22:06.790] <TB3> INFO: Vcal RMS: 5.88 4.24 6.31 6.02 6.15 6.06 4.94 5.66 5.44 5.86 4.90 5.33 6.04 5.02 4.67 5.97
[14:22:06.790] <TB3> INFO: PixTestScurves::fullTest() done, duration: 957 seconds
[14:22:06.863] <TB3> INFO: ######################################################################
[14:22:06.863] <TB3> INFO: PixTestTrim::doTest()
[14:22:06.863] <TB3> INFO: ######################################################################
[14:22:06.864] <TB3> INFO: ----------------------------------------------------------------------
[14:22:06.864] <TB3> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[14:22:06.864] <TB3> INFO: ----------------------------------------------------------------------
[14:22:06.947] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[14:22:06.947] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[14:22:06.956] <TB3> INFO: dacScan step from 0 .. 19
[14:22:22.803] <TB3> INFO: Test took 15847ms.
[14:22:22.827] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:22.827] <TB3> INFO: dacScan step from 20 .. 39
[14:22:37.802] <TB3> INFO: Test took 14975ms.
[14:22:37.821] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:37.821] <TB3> INFO: dacScan step from 40 .. 59
[14:22:52.712] <TB3> INFO: Test took 14890ms.
[14:22:52.732] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:52.732] <TB3> INFO: dacScan step from 60 .. 79
[14:23:07.845] <TB3> INFO: Test took 15113ms.
[14:23:07.867] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:07.868] <TB3> INFO: dacScan step from 80 .. 99
[14:23:23.399] <TB3> INFO: Test took 15531ms.
[14:23:23.445] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:23.449] <TB3> INFO: dacScan step from 100 .. 119
[14:23:41.813] <TB3> INFO: Test took 18363ms.
[14:23:41.973] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:42.011] <TB3> INFO: dacScan step from 120 .. 139
[14:24:01.533] <TB3> INFO: Test took 19523ms.
[14:24:01.685] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:01.715] <TB3> INFO: dacScan step from 140 .. 159
[14:24:18.881] <TB3> INFO: Test took 17166ms.
[14:24:18.950] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:40.156] <TB3> INFO: ROC 0 VthrComp = 85
[14:24:40.156] <TB3> INFO: ROC 1 VthrComp = 82
[14:24:40.156] <TB3> INFO: ROC 2 VthrComp = 98
[14:24:40.156] <TB3> INFO: ROC 3 VthrComp = 93
[14:24:40.156] <TB3> INFO: ROC 4 VthrComp = 103
[14:24:40.156] <TB3> INFO: ROC 5 VthrComp = 91
[14:24:40.156] <TB3> INFO: ROC 6 VthrComp = 92
[14:24:40.156] <TB3> INFO: ROC 7 VthrComp = 93
[14:24:40.156] <TB3> INFO: ROC 8 VthrComp = 89
[14:24:40.156] <TB3> INFO: ROC 9 VthrComp = 102
[14:24:40.157] <TB3> INFO: ROC 10 VthrComp = 99
[14:24:40.157] <TB3> INFO: ROC 11 VthrComp = 107
[14:24:40.157] <TB3> INFO: ROC 12 VthrComp = 102
[14:24:40.157] <TB3> INFO: ROC 13 VthrComp = 89
[14:24:40.157] <TB3> INFO: ROC 14 VthrComp = 97
[14:24:40.157] <TB3> INFO: ROC 15 VthrComp = 97
[14:24:40.157] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[14:24:40.157] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[14:24:40.166] <TB3> INFO: dacScan step from 0 .. 19
[14:24:55.875] <TB3> INFO: Test took 15709ms.
[14:24:55.900] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:55.900] <TB3> INFO: dacScan step from 20 .. 39
[14:25:11.978] <TB3> INFO: Test took 16078ms.
[14:25:12.011] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:12.014] <TB3> INFO: dacScan step from 40 .. 59
[14:25:31.900] <TB3> INFO: Test took 19886ms.
[14:25:32.051] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:32.086] <TB3> INFO: dacScan step from 60 .. 79
[14:25:53.891] <TB3> INFO: Test took 21805ms.
[14:25:54.057] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:54.104] <TB3> INFO: dacScan step from 80 .. 99
[14:26:15.924] <TB3> INFO: Test took 21820ms.
[14:26:16.083] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:16.128] <TB3> INFO: dacScan step from 100 .. 119
[14:26:38.181] <TB3> INFO: Test took 22053ms.
[14:26:38.361] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:38.410] <TB3> INFO: dacScan step from 120 .. 139
[14:27:00.338] <TB3> INFO: Test took 21928ms.
[14:27:00.503] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:00.550] <TB3> INFO: dacScan step from 140 .. 159
[14:27:22.336] <TB3> INFO: Test took 21786ms.
[14:27:22.509] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:47.758] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 63.1399 for pixel 1/50 mean/min/max = 47.5891/32.0033/63.1749
[14:27:47.758] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 57.6795 for pixel 31/0 mean/min/max = 45.3016/32.9096/57.6935
[14:27:47.759] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 60.6791 for pixel 16/70 mean/min/max = 46.2274/31.7361/60.7187
[14:27:47.759] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 59.6425 for pixel 16/78 mean/min/max = 46.4932/33.311/59.6755
[14:27:47.760] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 59.8865 for pixel 21/53 mean/min/max = 45.925/31.9557/59.8943
[14:27:47.760] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 60.5768 for pixel 5/39 mean/min/max = 46.6575/32.6797/60.6353
[14:27:47.761] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 61.3374 for pixel 21/0 mean/min/max = 47.9101/34.4397/61.3805
[14:27:47.761] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 60.9384 for pixel 30/2 mean/min/max = 46.7202/32.4998/60.9406
[14:27:47.762] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 57.6805 for pixel 0/17 mean/min/max = 45.7548/33.6999/57.8096
[14:27:47.762] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 61.6608 for pixel 2/65 mean/min/max = 47.0625/32.4422/61.6827
[14:27:47.763] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 57.0061 for pixel 7/79 mean/min/max = 44.4836/31.8493/57.118
[14:27:47.764] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 58.8248 for pixel 20/77 mean/min/max = 46.2772/33.6207/58.9338
[14:27:47.764] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 59.5832 for pixel 5/20 mean/min/max = 45.9219/32.1792/59.6645
[14:27:47.765] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 57.4641 for pixel 2/3 mean/min/max = 45.8889/34.1157/57.6621
[14:27:47.765] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 55.4394 for pixel 6/2 mean/min/max = 43.8598/32.1459/55.5737
[14:27:47.765] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 59.9503 for pixel 1/78 mean/min/max = 45.7897/31.4581/60.1213
[14:27:47.765] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:28.635] <TB3> INFO: Test took 100870ms.
[14:29:29.983] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[14:29:29.991] <TB3> INFO: dacScan step from 0 .. 19
[14:29:54.426] <TB3> INFO: Test took 24435ms.
[14:29:54.480] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:54.482] <TB3> INFO: dacScan step from 20 .. 39
[14:30:22.606] <TB3> INFO: Test took 28123ms.
[14:30:22.830] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:22.865] <TB3> INFO: dacScan step from 40 .. 59
[14:30:54.336] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (205) != TBM ID (8)
[14:30:54.336] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:30:54.336] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (206)
[14:30:55.603] <TB3> INFO: Test took 32738ms.
[14:30:56.001] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:56.059] <TB3> INFO: dacScan step from 60 .. 79
[14:31:35.836] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (77) != TBM ID (8)
[14:31:35.836] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:31:35.836] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (78)
[14:31:37.298] <TB3> INFO: Test took 41239ms.
[14:31:37.623] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:37.681] <TB3> INFO: dacScan step from 80 .. 99
[14:32:12.121] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (92) != TBM ID (8)
[14:32:12.122] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:32:12.122] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (93)
[14:32:13.625] <TB3> INFO: Test took 35944ms.
[14:32:13.895] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:13.949] <TB3> INFO: dacScan step from 100 .. 119
[14:32:46.679] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[14:32:46.679] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (118) != TBM ID (119)
[14:32:46.679] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[14:32:46.679] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[14:32:46.679] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:32:48.062] <TB3> INFO: Test took 34113ms.
[14:32:48.362] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:48.414] <TB3> INFO: dacScan step from 120 .. 139
[14:33:22.968] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:33:22.968] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:33:24.460] <TB3> INFO: Test took 36046ms.
[14:33:24.735] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:24.786] <TB3> INFO: dacScan step from 140 .. 159
[14:33:55.986] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:33:55.986] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:33:57.202] <TB3> INFO: Test took 32416ms.
[14:33:57.461] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:57.513] <TB3> INFO: dacScan step from 160 .. 179
[14:34:31.047] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:34:32.590] <TB3> INFO: Test took 35077ms.
[14:34:32.883] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:32.934] <TB3> INFO: dacScan step from 180 .. 199
[14:35:09.840] <TB3> INFO: Test took 36906ms.
[14:35:10.175] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:37.660] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 0.006385 .. 255.000000
[14:35:37.743] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[14:35:37.752] <TB3> INFO: dacScan step from 0 .. 19
[14:35:51.802] <TB3> INFO: Test took 14050ms.
[14:35:51.828] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:51.829] <TB3> INFO: dacScan step from 20 .. 39
[14:36:06.441] <TB3> INFO: Test took 14612ms.
[14:36:06.519] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:06.540] <TB3> INFO: dacScan step from 40 .. 59
[14:36:23.930] <TB3> INFO: Test took 17390ms.
[14:36:24.081] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:24.134] <TB3> INFO: dacScan step from 60 .. 79
[14:36:43.077] <TB3> INFO: Test took 18942ms.
[14:36:43.233] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:43.287] <TB3> INFO: dacScan step from 80 .. 99
[14:37:02.084] <TB3> INFO: Test took 18797ms.
[14:37:02.239] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:02.295] <TB3> INFO: dacScan step from 100 .. 119
[14:37:21.037] <TB3> INFO: Test took 18742ms.
[14:37:21.179] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:21.230] <TB3> INFO: dacScan step from 120 .. 139
[14:37:40.280] <TB3> INFO: Test took 19050ms.
[14:37:40.423] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:40.479] <TB3> INFO: dacScan step from 140 .. 159
[14:37:58.383] <TB3> INFO: Test took 17904ms.
[14:37:58.609] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:58.666] <TB3> INFO: dacScan step from 160 .. 179
[14:38:16.764] <TB3> INFO: Test took 18098ms.
[14:38:16.907] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:16.958] <TB3> INFO: dacScan step from 180 .. 199
[14:38:36.865] <TB3> INFO: Test took 19907ms.
[14:38:37.007] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:37.067] <TB3> INFO: dacScan step from 200 .. 219
[14:38:55.745] <TB3> INFO: Test took 18678ms.
[14:38:55.922] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:55.978] <TB3> INFO: dacScan step from 220 .. 239
[14:39:14.920] <TB3> INFO: Test took 18942ms.
[14:39:15.069] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:15.120] <TB3> INFO: dacScan step from 240 .. 255
[14:39:30.736] <TB3> INFO: Test took 15616ms.
[14:39:30.844] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:04.064] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 13.461686 .. 72.561837
[14:40:04.185] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 3 .. 82 (20) hits flags = 16 (plus default)
[14:40:04.195] <TB3> INFO: dacScan step from 3 .. 22
[14:40:18.498] <TB3> INFO: Test took 14303ms.
[14:40:18.527] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:18.528] <TB3> INFO: dacScan step from 23 .. 42
[14:40:34.461] <TB3> INFO: Test took 15933ms.
[14:40:34.583] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:34.610] <TB3> INFO: dacScan step from 43 .. 62
[14:40:53.504] <TB3> INFO: Test took 18894ms.
[14:40:53.658] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:53.715] <TB3> INFO: dacScan step from 63 .. 82
[14:41:12.513] <TB3> INFO: Test took 18798ms.
[14:41:12.650] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:33.457] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 19.140937 .. 70.747092
[14:41:33.547] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 9 .. 80 (20) hits flags = 16 (plus default)
[14:41:33.555] <TB3> INFO: dacScan step from 9 .. 28
[14:41:47.728] <TB3> INFO: Test took 14173ms.
[14:41:47.750] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:47.751] <TB3> INFO: dacScan step from 29 .. 48
[14:42:05.256] <TB3> INFO: Test took 17505ms.
[14:42:05.418] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:05.459] <TB3> INFO: dacScan step from 49 .. 68
[14:42:24.556] <TB3> INFO: Test took 19097ms.
[14:42:24.700] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:24.754] <TB3> INFO: dacScan step from 69 .. 80
[14:42:37.139] <TB3> INFO: Test took 12385ms.
[14:42:37.231] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:57.986] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 2.860131 .. 70.747092
[14:42:58.086] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 2 .. 80 (20) hits flags = 16 (plus default)
[14:42:58.095] <TB3> INFO: dacScan step from 2 .. 21
[14:43:12.365] <TB3> INFO: Test took 14270ms.
[14:43:12.389] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:12.389] <TB3> INFO: dacScan step from 22 .. 41
[14:43:28.179] <TB3> INFO: Test took 15790ms.
[14:43:28.268] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:28.287] <TB3> INFO: dacScan step from 42 .. 61
[14:43:47.209] <TB3> INFO: Test took 18922ms.
[14:43:47.393] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:47.441] <TB3> INFO: dacScan step from 62 .. 80
[14:44:05.681] <TB3> INFO: Test took 18240ms.
[14:44:05.834] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:26.663] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[14:44:26.663] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[14:44:26.672] <TB3> INFO: dacScan step from 15 .. 34
[14:44:51.609] <TB3> INFO: Test took 24937ms.
[14:44:51.683] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:51.695] <TB3> INFO: dacScan step from 35 .. 54
[14:45:26.565] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:45:26.566] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:45:27.254] <TB3> INFO: Test took 35559ms.
[14:45:27.633] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:27.679] <TB3> INFO: dacScan step from 55 .. 55
[14:45:32.159] <TB3> INFO: Test took 4480ms.
[14:45:32.180] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:46.813] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C0.dat
[14:45:46.817] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C1.dat
[14:45:46.818] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C2.dat
[14:45:46.818] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C3.dat
[14:45:46.818] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C4.dat
[14:45:46.819] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C5.dat
[14:45:46.819] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C6.dat
[14:45:46.819] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C7.dat
[14:45:46.819] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C8.dat
[14:45:46.820] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C9.dat
[14:45:46.820] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C10.dat
[14:45:46.820] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C11.dat
[14:45:46.820] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C12.dat
[14:45:46.820] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C13.dat
[14:45:46.821] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C14.dat
[14:45:46.821] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C15.dat
[14:45:46.821] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C0.dat
[14:45:46.831] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C1.dat
[14:45:46.839] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C2.dat
[14:45:46.846] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C3.dat
[14:45:46.852] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C4.dat
[14:45:46.859] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C5.dat
[14:45:46.866] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C6.dat
[14:45:46.873] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C7.dat
[14:45:46.879] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C8.dat
[14:45:46.885] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C9.dat
[14:45:46.891] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C10.dat
[14:45:46.897] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C11.dat
[14:45:46.903] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C12.dat
[14:45:46.909] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C13.dat
[14:45:46.915] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C14.dat
[14:45:46.921] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C15.dat
[14:45:46.927] <TB3> INFO: PixTestTrim::trimTest() done
[14:45:46.927] <TB3> INFO: vtrim: 110 97 114 114 109 110 108 105 92 133 107 121 204 99 99 116
[14:45:46.927] <TB3> INFO: vthrcomp: 85 82 98 93 103 91 92 93 89 102 99 107 102 89 97 97
[14:45:46.927] <TB3> INFO: vcal mean: 35.14 35.12 35.12 35.12 35.15 35.06 35.13 35.12 35.10 35.08 35.07 35.13 34.98 35.11 35.10 35.07
[14:45:46.927] <TB3> INFO: vcal RMS: 1.25 1.16 1.20 1.05 1.20 1.06 1.20 1.25 1.06 1.06 1.06 1.02 2.40 1.01 1.01 1.11
[14:45:46.927] <TB3> INFO: bits mean: 9.67 10.19 10.15 9.62 9.66 9.44 9.08 9.89 9.56 9.48 10.14 9.63 11.81 9.51 10.56 10.13
[14:45:46.927] <TB3> INFO: bits RMS: 2.49 2.35 2.40 2.43 2.59 2.58 2.47 2.45 2.48 2.56 2.53 2.42 1.60 2.44 2.32 2.49
[14:45:46.933] <TB3> INFO: ----------------------------------------------------------------------
[14:45:46.933] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[14:45:46.934] <TB3> INFO: ----------------------------------------------------------------------
[14:45:46.935] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[14:45:46.946] <TB3> INFO: dacScan step from 0 .. 19
[14:46:11.266] <TB3> INFO: Test took 24320ms.
[14:46:11.298] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:11.298] <TB3> INFO: dacScan step from 20 .. 39
[14:46:35.605] <TB3> INFO: Test took 24307ms.
[14:46:35.637] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:35.637] <TB3> INFO: dacScan step from 40 .. 59
[14:46:57.899] <TB3> INFO: Test took 22262ms.
[14:46:57.934] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:57.934] <TB3> INFO: dacScan step from 60 .. 79
[14:47:22.288] <TB3> INFO: Test took 24354ms.
[14:47:22.327] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:22.327] <TB3> INFO: dacScan step from 80 .. 99
[14:47:46.850] <TB3> INFO: Test took 24523ms.
[14:47:46.889] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:46.889] <TB3> INFO: dacScan step from 100 .. 119
[14:48:13.486] <TB3> INFO: Test took 26597ms.
[14:48:13.616] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:13.629] <TB3> INFO: dacScan step from 120 .. 139
[14:48:44.361] <TB3> INFO: Test took 30731ms.
[14:48:44.623] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:44.659] <TB3> INFO: dacScan step from 140 .. 159
[14:49:19.036] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:49:19.036] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:49:20.346] <TB3> INFO: Test took 35687ms.
[14:49:20.675] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:20.727] <TB3> INFO: dacScan step from 160 .. 179
[14:49:53.574] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:49:53.574] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:49:55.019] <TB3> INFO: Test took 34292ms.
[14:49:55.314] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:55.364] <TB3> INFO: dacScan step from 180 .. 199
[14:50:32.149] <TB3> INFO: Test took 36784ms.
[14:50:32.461] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:01.074] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 184 (20) hits flags = 16 (plus default)
[14:51:01.084] <TB3> INFO: dacScan step from 0 .. 19
[14:51:25.280] <TB3> INFO: Test took 24196ms.
[14:51:25.321] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:25.321] <TB3> INFO: dacScan step from 20 .. 39
[14:51:49.454] <TB3> INFO: Test took 24133ms.
[14:51:49.487] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:49.487] <TB3> INFO: dacScan step from 40 .. 59
[14:52:13.632] <TB3> INFO: Test took 24145ms.
[14:52:13.666] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:13.666] <TB3> INFO: dacScan step from 60 .. 79
[14:52:36.207] <TB3> INFO: Test took 22541ms.
[14:52:36.254] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:36.254] <TB3> INFO: dacScan step from 80 .. 99
[14:52:59.560] <TB3> INFO: Test took 23306ms.
[14:52:59.616] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:59.619] <TB3> INFO: dacScan step from 100 .. 119
[14:53:27.718] <TB3> INFO: Test took 28098ms.
[14:53:27.928] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:27.961] <TB3> INFO: dacScan step from 120 .. 139
[14:53:59.902] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:54:00.858] <TB3> INFO: Test took 32896ms.
[14:54:01.156] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:01.206] <TB3> INFO: dacScan step from 140 .. 159
[14:54:33.794] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:54:35.252] <TB3> INFO: Test took 34046ms.
[14:54:35.547] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:35.603] <TB3> INFO: dacScan step from 160 .. 179
[14:55:09.044] <TB3> INFO: Test took 33441ms.
[14:55:09.312] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:09.359] <TB3> INFO: dacScan step from 180 .. 184
[14:55:20.427] <TB3> INFO: Test took 11068ms.
[14:55:20.507] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:46.742] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 170 (20) hits flags = 16 (plus default)
[14:55:46.750] <TB3> INFO: dacScan step from 0 .. 19
[14:56:09.714] <TB3> INFO: Test took 22964ms.
[14:56:09.760] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:09.760] <TB3> INFO: dacScan step from 20 .. 39
[14:56:33.125] <TB3> INFO: Test took 23365ms.
[14:56:33.164] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:33.164] <TB3> INFO: dacScan step from 40 .. 59
[14:56:57.479] <TB3> INFO: Test took 24315ms.
[14:56:57.519] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:57.519] <TB3> INFO: dacScan step from 60 .. 79
[14:57:20.846] <TB3> INFO: Test took 23327ms.
[14:57:20.891] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:20.891] <TB3> INFO: dacScan step from 80 .. 99
[14:57:43.821] <TB3> INFO: Test took 22930ms.
[14:57:43.883] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:43.886] <TB3> INFO: dacScan step from 100 .. 119
[14:58:14.138] <TB3> INFO: Test took 30252ms.
[14:58:14.344] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:14.365] <TB3> INFO: dacScan step from 120 .. 139
[14:58:46.978] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:58:46.978] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:58:48.050] <TB3> INFO: Test took 33685ms.
[14:58:48.331] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:48.372] <TB3> INFO: dacScan step from 140 .. 159
[14:59:22.819] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:59:22.819] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:59:24.228] <TB3> INFO: Test took 35856ms.
[14:59:24.487] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:24.533] <TB3> INFO: dacScan step from 160 .. 170
[14:59:44.231] <TB3> INFO: Test took 19698ms.
[14:59:44.479] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:08.576] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 171 (20) hits flags = 16 (plus default)
[15:00:08.584] <TB3> INFO: dacScan step from 0 .. 19
[15:00:32.381] <TB3> INFO: Test took 23797ms.
[15:00:32.417] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:32.417] <TB3> INFO: dacScan step from 20 .. 39
[15:00:56.688] <TB3> INFO: Test took 24271ms.
[15:00:56.725] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:56.725] <TB3> INFO: dacScan step from 40 .. 59
[15:01:20.464] <TB3> INFO: Test took 23739ms.
[15:01:20.508] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:20.508] <TB3> INFO: dacScan step from 60 .. 79
[15:01:44.527] <TB3> INFO: Test took 24019ms.
[15:01:44.564] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:44.564] <TB3> INFO: dacScan step from 80 .. 99
[15:02:09.149] <TB3> INFO: Test took 24585ms.
[15:02:09.209] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:09.212] <TB3> INFO: dacScan step from 100 .. 119
[15:02:39.416] <TB3> INFO: Test took 30204ms.
[15:02:39.618] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:39.642] <TB3> INFO: dacScan step from 120 .. 139
[15:03:14.136] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[15:03:14.137] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!
[15:03:15.215] <TB3> INFO: Test took 35573ms.
[15:03:15.510] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:15.555] <TB3> INFO: dacScan step from 140 .. 159
[15:03:49.862] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[15:03:51.406] <TB3> INFO: Test took 35851ms.
[15:03:51.683] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:51.733] <TB3> INFO: dacScan step from 160 .. 171
[15:04:14.426] <TB3> INFO: Test took 22693ms.
[15:04:14.631] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:04:37.508] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 170 (20) hits flags = 16 (plus default)
[15:04:37.517] <TB3> INFO: dacScan step from 0 .. 19
[15:05:01.375] <TB3> INFO: Test took 23858ms.
[15:05:01.410] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:01.410] <TB3> INFO: dacScan step from 20 .. 39
[15:05:25.654] <TB3> INFO: Test took 24244ms.
[15:05:25.693] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:25.693] <TB3> INFO: dacScan step from 40 .. 59
[15:05:49.863] <TB3> INFO: Test took 24170ms.
[15:05:49.902] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:49.902] <TB3> INFO: dacScan step from 60 .. 79
[15:06:14.124] <TB3> INFO: Test took 24222ms.
[15:06:14.163] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:14.163] <TB3> INFO: dacScan step from 80 .. 99
[15:06:38.689] <TB3> INFO: Test took 24526ms.
[15:06:38.746] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:38.749] <TB3> INFO: dacScan step from 100 .. 119
[15:07:06.212] <TB3> INFO: Test took 27463ms.
[15:07:06.430] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:06.460] <TB3> INFO: dacScan step from 120 .. 139
[15:07:40.994] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[15:07:40.994] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!
[15:07:42.072] <TB3> INFO: Test took 35612ms.
[15:07:42.342] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:42.383] <TB3> INFO: dacScan step from 140 .. 159
[15:08:17.022] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[15:08:17.022] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[15:08:18.368] <TB3> INFO: Test took 35985ms.
[15:08:18.672] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:18.720] <TB3> INFO: dacScan step from 160 .. 170
[15:08:38.396] <TB3> INFO: Test took 19676ms.
[15:08:38.640] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:02.188] <TB3> INFO: PixTestTrim::trimBitTest() done
[15:09:02.190] <TB3> INFO: PixTestTrim::doTest() done, duration: 2815 seconds
[15:09:02.865] <TB3> INFO: ######################################################################
[15:09:02.865] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[15:09:02.865] <TB3> INFO: ######################################################################
[15:09:06.470] <TB3> INFO: Test took 3603ms.
[15:09:06.494] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:10.303] <TB3> INFO: Test took 3613ms.
[15:09:10.372] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:13.982] <TB3> INFO: Test took 3602ms.
[15:09:14.058] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:14.065] <TB3> INFO: The DUT currently contains the following objects:
[15:09:14.065] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:14.065] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:14.065] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:14.065] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:14.065] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:14.065] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.180] <TB3> INFO: Test took 1115ms.
[15:09:15.181] <TB3> INFO: The DUT currently contains the following objects:
[15:09:15.181] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:15.181] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:15.181] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:15.182] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:15.182] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:15.182] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: Test took 1106ms.
[15:09:16.288] <TB3> INFO: The DUT currently contains the following objects:
[15:09:16.288] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:16.288] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:16.288] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:16.288] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:16.288] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:16.288] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.402] <TB3> INFO: Test took 1114ms.
[15:09:17.403] <TB3> INFO: The DUT currently contains the following objects:
[15:09:17.403] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:17.403] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:17.403] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:17.403] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:17.403] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.403] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.404] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.404] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.404] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.404] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:17.404] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.515] <TB3> INFO: Test took 1111ms.
[15:09:18.517] <TB3> INFO: The DUT currently contains the following objects:
[15:09:18.517] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:18.517] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:18.517] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:18.517] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:18.517] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.517] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.517] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.517] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.517] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.517] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.517] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.517] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.518] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.518] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.518] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.518] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.518] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.518] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.518] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:18.518] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.630] <TB3> INFO: Test took 1112ms.
[15:09:19.631] <TB3> INFO: The DUT currently contains the following objects:
[15:09:19.631] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:19.631] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:19.631] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:19.631] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:19.631] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.631] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.631] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.631] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.631] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.631] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.631] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.631] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.631] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.631] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.632] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.632] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.632] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.632] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.632] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:19.632] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.744] <TB3> INFO: Test took 1112ms.
[15:09:20.745] <TB3> INFO: The DUT currently contains the following objects:
[15:09:20.745] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:20.745] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:20.745] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:20.745] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:20.745] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.745] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.745] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.745] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.745] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:20.746] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.858] <TB3> INFO: Test took 1112ms.
[15:09:21.859] <TB3> INFO: The DUT currently contains the following objects:
[15:09:21.859] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:21.859] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:21.859] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:21.859] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:21.859] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.859] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.860] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.860] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:21.860] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.972] <TB3> INFO: Test took 1112ms.
[15:09:22.973] <TB3> INFO: The DUT currently contains the following objects:
[15:09:22.973] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:22.973] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:22.973] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:22.973] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:22.973] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.973] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.974] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.974] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.974] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.974] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:22.974] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.086] <TB3> INFO: Test took 1112ms.
[15:09:24.087] <TB3> INFO: The DUT currently contains the following objects:
[15:09:24.087] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:24.087] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:24.087] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:24.087] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:24.087] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.087] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.087] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.087] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.087] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.087] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.087] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.087] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.087] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.087] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.088] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.088] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.088] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.088] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.088] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:24.088] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.200] <TB3> INFO: Test took 1112ms.
[15:09:25.201] <TB3> INFO: The DUT currently contains the following objects:
[15:09:25.201] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:25.201] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:25.201] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:25.201] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:25.201] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.201] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.202] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.202] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.202] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:25.202] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.314] <TB3> INFO: Test took 1112ms.
[15:09:26.316] <TB3> INFO: The DUT currently contains the following objects:
[15:09:26.316] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:26.316] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:26.316] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:26.316] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:26.316] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:26.316] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.428] <TB3> INFO: Test took 1112ms.
[15:09:27.429] <TB3> INFO: The DUT currently contains the following objects:
[15:09:27.429] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:27.429] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:27.429] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:27.429] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:27.429] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.429] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.429] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.429] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.429] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:27.430] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.542] <TB3> INFO: Test took 1112ms.
[15:09:28.543] <TB3> INFO: The DUT currently contains the following objects:
[15:09:28.543] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:28.543] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:28.543] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:28.543] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:28.543] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.543] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:28.544] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.656] <TB3> INFO: Test took 1112ms.
[15:09:29.657] <TB3> INFO: The DUT currently contains the following objects:
[15:09:29.657] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:29.657] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:29.657] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:29.657] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:29.657] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.657] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.657] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.657] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.657] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:29.658] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.772] <TB3> INFO: Test took 1114ms.
[15:09:30.774] <TB3> INFO: The DUT currently contains the following objects:
[15:09:30.774] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:09:30.774] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:09:30.774] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:09:30.774] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:09:30.774] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.774] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.775] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.775] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.775] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.775] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:30.775] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:09:31.887] <TB3> INFO: Test took 1112ms.
[15:09:31.890] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:13:34.510] <TB3> INFO: Test took 242620ms.
[15:13:36.093] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:17:37.630] <TB3> INFO: Test took 241537ms.
[15:17:39.293] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.299] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.306] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.313] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.319] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.326] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.333] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.339] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.346] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.353] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.359] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[15:17:39.366] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.373] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.379] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.386] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.393] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.399] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:17:39.422] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C0.dat
[15:17:39.422] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C1.dat
[15:17:39.422] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C2.dat
[15:17:39.422] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C3.dat
[15:17:39.422] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C4.dat
[15:17:39.422] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C5.dat
[15:17:39.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C6.dat
[15:17:39.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C7.dat
[15:17:39.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C8.dat
[15:17:39.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C9.dat
[15:17:39.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C10.dat
[15:17:39.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C11.dat
[15:17:39.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C12.dat
[15:17:39.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C13.dat
[15:17:39.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C14.dat
[15:17:39.424] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C15.dat
[15:17:42.815] <TB3> INFO: Test took 3390ms.
[15:17:46.461] <TB3> INFO: Test took 3385ms.
[15:17:50.145] <TB3> INFO: Test took 3384ms.
[15:17:50.410] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:17:51.329] <TB3> INFO: Test took 919ms.
[15:17:51.331] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:17:52.436] <TB3> INFO: Test took 1105ms.
[15:17:52.438] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:17:53.543] <TB3> INFO: Test took 1105ms.
[15:17:53.545] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:17:54.657] <TB3> INFO: Test took 1112ms.
[15:17:54.659] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:17:55.773] <TB3> INFO: Test took 1114ms.
[15:17:55.776] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:17:56.889] <TB3> INFO: Test took 1113ms.
[15:17:56.892] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:17:58.005] <TB3> INFO: Test took 1113ms.
[15:17:58.008] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:17:59.122] <TB3> INFO: Test took 1114ms.
[15:17:59.125] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:00.239] <TB3> INFO: Test took 1114ms.
[15:18:00.242] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:01.355] <TB3> INFO: Test took 1113ms.
[15:18:01.357] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:02.470] <TB3> INFO: Test took 1113ms.
[15:18:02.473] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:03.586] <TB3> INFO: Test took 1113ms.
[15:18:03.589] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:04.703] <TB3> INFO: Test took 1114ms.
[15:18:04.706] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:05.820] <TB3> INFO: Test took 1114ms.
[15:18:05.823] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:06.937] <TB3> INFO: Test took 1114ms.
[15:18:06.939] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:08.053] <TB3> INFO: Test took 1114ms.
[15:18:08.055] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:09.169] <TB3> INFO: Test took 1114ms.
[15:18:09.171] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:10.285] <TB3> INFO: Test took 1114ms.
[15:18:10.287] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:11.415] <TB3> INFO: Test took 1128ms.
[15:18:11.418] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:12.532] <TB3> INFO: Test took 1114ms.
[15:18:12.535] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:13.649] <TB3> INFO: Test took 1114ms.
[15:18:13.652] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:14.768] <TB3> INFO: Test took 1117ms.
[15:18:14.771] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:15.885] <TB3> INFO: Test took 1114ms.
[15:18:15.888] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:17.003] <TB3> INFO: Test took 1115ms.
[15:18:17.006] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:18.119] <TB3> INFO: Test took 1114ms.
[15:18:18.121] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:19.234] <TB3> INFO: Test took 1113ms.
[15:18:19.238] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:20.352] <TB3> INFO: Test took 1115ms.
[15:18:20.355] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:21.470] <TB3> INFO: Test took 1115ms.
[15:18:21.473] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:22.586] <TB3> INFO: Test took 1113ms.
[15:18:22.589] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:23.701] <TB3> INFO: Test took 1112ms.
[15:18:23.704] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:24.818] <TB3> INFO: Test took 1114ms.
[15:18:24.820] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:25.934] <TB3> INFO: Test took 1114ms.
[15:18:26.464] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 563 seconds
[15:18:26.464] <TB3> INFO: PH scale (per ROC): 70 65 79 78 77 69 70 78 73 75 72 75 73 79 79 78
[15:18:26.464] <TB3> INFO: PH offset (per ROC): 186 169 165 170 172 174 173 176 171 176 179 175 164 171 182 171
[15:18:26.676] <TB3> INFO: ######################################################################
[15:18:26.676] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[15:18:26.676] <TB3> INFO: ######################################################################
[15:18:26.686] <TB3> INFO: scanning low vcal = 10
[15:18:30.663] <TB3> INFO: Test took 3977ms.
[15:18:30.668] <TB3> INFO: scanning low vcal = 20
[15:18:34.650] <TB3> INFO: Test took 3982ms.
[15:18:34.655] <TB3> INFO: scanning low vcal = 30
[15:18:38.651] <TB3> INFO: Test took 3989ms.
[15:18:38.668] <TB3> INFO: scanning low vcal = 40
[15:18:43.184] <TB3> INFO: Test took 4516ms.
[15:18:43.250] <TB3> INFO: scanning low vcal = 50
[15:18:47.766] <TB3> INFO: Test took 4516ms.
[15:18:47.839] <TB3> INFO: scanning low vcal = 60
[15:18:52.349] <TB3> INFO: Test took 4510ms.
[15:18:52.426] <TB3> INFO: scanning low vcal = 70
[15:18:56.945] <TB3> INFO: Test took 4519ms.
[15:18:57.011] <TB3> INFO: scanning low vcal = 80
[15:19:01.489] <TB3> INFO: Test took 4477ms.
[15:19:01.564] <TB3> INFO: scanning low vcal = 90
[15:19:06.080] <TB3> INFO: Test took 4516ms.
[15:19:06.153] <TB3> INFO: scanning low vcal = 100
[15:19:10.470] <TB3> INFO: Test took 4316ms.
[15:19:10.531] <TB3> INFO: scanning low vcal = 110
[15:19:14.863] <TB3> INFO: Test took 4332ms.
[15:19:14.918] <TB3> INFO: scanning low vcal = 120
[15:19:19.242] <TB3> INFO: Test took 4324ms.
[15:19:19.301] <TB3> INFO: scanning low vcal = 130
[15:19:23.621] <TB3> INFO: Test took 4320ms.
[15:19:23.679] <TB3> INFO: scanning low vcal = 140
[15:19:27.995] <TB3> INFO: Test took 4316ms.
[15:19:28.057] <TB3> INFO: scanning low vcal = 150
[15:19:32.377] <TB3> INFO: Test took 4320ms.
[15:19:32.434] <TB3> INFO: scanning low vcal = 160
[15:19:36.967] <TB3> INFO: Test took 4533ms.
[15:19:37.036] <TB3> INFO: scanning low vcal = 170
[15:19:41.572] <TB3> INFO: Test took 4536ms.
[15:19:41.638] <TB3> INFO: scanning low vcal = 180
[15:19:46.146] <TB3> INFO: Test took 4508ms.
[15:19:46.208] <TB3> INFO: scanning low vcal = 190
[15:19:50.831] <TB3> INFO: Test took 4623ms.
[15:19:50.891] <TB3> INFO: scanning low vcal = 200
[15:19:55.408] <TB3> INFO: Test took 4517ms.
[15:19:55.475] <TB3> INFO: scanning low vcal = 210
[15:19:59.939] <TB3> INFO: Test took 4463ms.
[15:20:00.005] <TB3> INFO: scanning low vcal = 220
[15:20:04.462] <TB3> INFO: Test took 4457ms.
[15:20:04.527] <TB3> INFO: scanning low vcal = 230
[15:20:09.040] <TB3> INFO: Test took 4513ms.
[15:20:09.101] <TB3> INFO: scanning low vcal = 240
[15:20:13.486] <TB3> INFO: Test took 4385ms.
[15:20:13.584] <TB3> INFO: scanning low vcal = 250
[15:20:17.967] <TB3> INFO: Test took 4383ms.
[15:20:18.060] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[15:20:22.443] <TB3> INFO: Test took 4383ms.
[15:20:22.540] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[15:20:26.972] <TB3> INFO: Test took 4432ms.
[15:20:27.070] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[15:20:31.450] <TB3> INFO: Test took 4380ms.
[15:20:31.546] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[15:20:36.017] <TB3> INFO: Test took 4471ms.
[15:20:36.078] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[15:20:40.563] <TB3> INFO: Test took 4485ms.
[15:20:41.139] <TB3> INFO: PixTestGainPedestal::measure() done
[15:21:15.434] <TB3> INFO: PixTestGainPedestal::fit() done
[15:21:15.434] <TB3> INFO: non-linearity mean: 0.958 0.952 0.954 0.957 0.959 0.958 0.956 0.963 0.954 0.958 0.957 0.962 0.957 0.950 0.954 0.955
[15:21:15.434] <TB3> INFO: non-linearity RMS: 0.008 0.007 0.006 0.006 0.006 0.007 0.009 0.006 0.007 0.006 0.007 0.006 0.007 0.007 0.007 0.007
[15:21:15.434] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C0.dat
[15:21:15.453] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C1.dat
[15:21:15.475] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C2.dat
[15:21:15.498] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C3.dat
[15:21:15.523] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C4.dat
[15:21:15.547] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C5.dat
[15:21:15.573] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C6.dat
[15:21:15.592] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C7.dat
[15:21:15.612] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C8.dat
[15:21:15.631] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C9.dat
[15:21:15.653] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C10.dat
[15:21:15.678] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C11.dat
[15:21:15.701] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C12.dat
[15:21:15.721] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C13.dat
[15:21:15.740] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C14.dat
[15:21:15.759] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C15.dat
[15:21:15.784] <TB3> INFO: PixTestGainPedestal::doTest() done, duration: 169 seconds
[15:21:15.791] <TB3> INFO: enter test to run
[15:21:15.793] <TB3> INFO: test: exit no parameter change
[15:21:16.250] <TB3> QUIET: Connection to board 170 closed.
[15:21:16.266] <TB3> INFO: pXar: this is the end, my friend