[08:17:16.146] <TB3> INFO: *** Welcome to pxar ***
[08:17:16.146] <TB3> INFO: *** Today: 2015/08/06
[08:17:16.146] <TB3> INFO: readRocDacs: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C15.dat
[08:17:16.147] <TB3> INFO: readTbmDacs: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//tbmParameters_C0b.dat
[08:17:16.147] <TB3> INFO: readMaskFile: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//defaultMaskFile.dat
[08:17:16.147] <TB3> INFO: readTrimFile: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters_C15.dat
[08:17:16.237] <TB3> INFO: clk: 4
[08:17:16.237] <TB3> INFO: ctr: 4
[08:17:16.237] <TB3> INFO: sda: 19
[08:17:16.237] <TB3> INFO: tin: 9
[08:17:16.237] <TB3> INFO: level: 15
[08:17:16.237] <TB3> INFO: triggerdelay: 0
[08:17:16.237] <TB3> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[08:17:16.237] <TB3> INFO: Log level: INFO
[08:17:16.256] <TB3> INFO: Found DTB DTB_WZ4I6J
[08:17:16.269] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[08:17:16.273] <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:
------------------------------------------------------
[08:17:16.276] <TB3> INFO: RPC call hashes of host and DTB match: 447413373
[08:17:17.837] <TB3> INFO: DUT info:
[08:17:17.837] <TB3> INFO: The DUT currently contains the following objects:
[08:17:17.837] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:17:17.837] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:17:17.837] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:17:17.837] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[08:17:17.837] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.837] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.838] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:17.838] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[08:17:18.238] <TB3> INFO: enter 'restricted' command line mode
[08:17:18.238] <TB3> INFO: enter test to run
[08:17:18.239] <TB3> INFO: test: pretest no parameter change
[08:17:18.239] <TB3> INFO: running: pretest
[08:17:18.243] <TB3> INFO: ######################################################################
[08:17:18.243] <TB3> INFO: PixTestPretest::doTest()
[08:17:18.243] <TB3> INFO: ######################################################################
[08:17:18.245] <TB3> INFO: ----------------------------------------------------------------------
[08:17:18.245] <TB3> INFO: PixTestPretest::programROC()
[08:17:18.245] <TB3> INFO: ----------------------------------------------------------------------
[08:17:36.275] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[08:17:36.275] <TB3> INFO: IA differences per ROC: 20.1 17.7 19.3 18.5 17.7 18.5 17.7 17.7 17.7 18.5 17.7 20.1 20.1 16.9 17.7 17.7
[08:17:36.457] <TB3> INFO: ----------------------------------------------------------------------
[08:17:36.457] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[08:17:36.457] <TB3> INFO: ----------------------------------------------------------------------
[08:17:55.980] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 385.1 mA = 24.0688 mA/ROC
[08:17:55.983] <TB3> INFO: ----------------------------------------------------------------------
[08:17:55.983] <TB3> INFO: PixTestPretest::findWorkingPixel()
[08:17:55.983] <TB3> INFO: ----------------------------------------------------------------------
[08:18:04.455] <TB3> INFO: Test took 8469ms.
[08:18:05.055] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[08:18:05.074] <TB3> INFO: ----------------------------------------------------------------------
[08:18:05.075] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[08:18:05.075] <TB3> INFO: ----------------------------------------------------------------------
[08:18:13.484] <TB3> INFO: Test took 8406ms.
[08:18:13.778] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[08:18:13.778] <TB3> INFO: CalDel: 169 169 177 160 155 144 164 159 140 135 135 139 133 150 139 147
[08:18:13.778] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[08:18:13.781] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C0.dat
[08:18:13.781] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C1.dat
[08:18:13.781] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C2.dat
[08:18:13.781] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C3.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C4.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C5.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C6.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C7.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C8.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C9.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C10.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C11.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C12.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C13.dat
[08:18:13.782] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C14.dat
[08:18:13.783] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters_C15.dat
[08:18:13.783] <TB3> INFO: PixTestPretest::doTest() done, duration: 55 seconds
[08:18:13.871] <TB3> INFO: enter test to run
[08:18:13.871] <TB3> INFO: test: fulltest no parameter change
[08:18:13.871] <TB3> INFO: running: fulltest
[08:18:13.871] <TB3> INFO: ######################################################################
[08:18:13.871] <TB3> INFO: PixTestFullTest::doTest()
[08:18:13.871] <TB3> INFO: ######################################################################
[08:18:13.873] <TB3> INFO: ######################################################################
[08:18:13.873] <TB3> INFO: PixTestAlive::doTest()
[08:18:13.873] <TB3> INFO: ######################################################################
[08:18:13.874] <TB3> INFO: ----------------------------------------------------------------------
[08:18:13.874] <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)
[08:18:13.874] <TB3> INFO: ----------------------------------------------------------------------
[08:18:17.311] <TB3> INFO: Test took 3436ms.
[08:18:17.376] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:18:17.603] <TB3> INFO: PixTestAlive::aliveTest() done
[08:18:17.603] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[08:18:17.604] <TB3> INFO: ----------------------------------------------------------------------
[08:18:17.604] <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)
[08:18:17.604] <TB3> INFO: ----------------------------------------------------------------------
[08:18:20.959] <TB3> INFO: Test took 3354ms.
[08:18:20.961] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:18:20.961] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[08:18:21.172] <TB3> INFO: PixTestAlive::maskTest() done
[08:18:21.172] <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
[08:18:21.173] <TB3> INFO: ----------------------------------------------------------------------
[08:18:21.173] <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)
[08:18:21.173] <TB3> INFO: ----------------------------------------------------------------------
[08:18:25.190] <TB3> INFO: Test took 4017ms.
[08:18:25.264] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:18:25.486] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[08:18:25.486] <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
[08:18:25.486] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[08:18:25.494] <TB3> INFO: ######################################################################
[08:18:25.494] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[08:18:25.494] <TB3> INFO: ######################################################################
[08:18:25.496] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[08:18:25.725] <TB3> INFO: dacScan step from 0 .. 29
[08:18:47.670] <TB3> INFO: Test took 21945ms.
[08:18:47.794] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:18:47.794] <TB3> INFO: dacScan step from 30 .. 59
[08:19:12.964] <TB3> INFO: Test took 25170ms.
[08:19:13.121] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:19:13.142] <TB3> INFO: dacScan step from 60 .. 89
[08:19:42.924] <TB3> INFO: Test took 29782ms.
[08:19:43.978] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:19:44.346] <TB3> INFO: dacScan step from 90 .. 119
[08:20:14.180] <TB3> INFO: Test took 29834ms.
[08:20:15.182] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:20:15.580] <TB3> INFO: dacScan step from 120 .. 149
[08:20:41.733] <TB3> INFO: Test took 26153ms.
[08:20:42.438] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:21:20.960] <TB3> INFO: PixTestBBMap::doTest() done, duration: 175 seconds
[08:21:20.960] <TB3> INFO: number of dead bumps (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[08:21:20.960] <TB3> INFO: separation cut (per ROC): 67 65 90 81 92 76 69 76 73 96 83 94 100 75 86 90
[08:21:21.035] <TB3> INFO: ######################################################################
[08:21:21.035] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50
[08:21:21.035] <TB3> INFO: ######################################################################
[08:21:21.035] <TB3> INFO: ----------------------------------------------------------------------
[08:21:21.035] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[08:21:21.035] <TB3> INFO: ----------------------------------------------------------------------
[08:21:21.035] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[08:21:21.043] <TB3> INFO: dacScan step from 0 .. 3
[08:21:40.126] <TB3> INFO: Test took 19083ms.
[08:21:40.157] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:21:40.157] <TB3> INFO: dacScan step from 4 .. 7
[08:22:00.545] <TB3> INFO: Test took 20388ms.
[08:22:00.573] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:22:00.573] <TB3> INFO: dacScan step from 8 .. 11
[08:22:20.545] <TB3> INFO: Test took 19972ms.
[08:22:20.570] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:22:20.570] <TB3> INFO: dacScan step from 12 .. 15
[08:22:39.614] <TB3> INFO: Test took 19044ms.
[08:22:39.642] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:22:39.642] <TB3> INFO: dacScan step from 16 .. 19
[08:22:59.188] <TB3> INFO: Test took 19546ms.
[08:22:59.281] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:22:59.281] <TB3> INFO: dacScan step from 20 .. 23
[08:23:19.107] <TB3> INFO: Test took 19826ms.
[08:23:19.205] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:23:19.205] <TB3> INFO: dacScan step from 24 .. 27
[08:23:38.936] <TB3> INFO: Test took 19731ms.
[08:23:39.045] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:23:39.046] <TB3> INFO: dacScan step from 28 .. 31
[08:23:58.670] <TB3> INFO: Test took 19624ms.
[08:23:58.757] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:23:58.757] <TB3> INFO: dacScan step from 32 .. 35
[08:24:18.329] <TB3> INFO: Test took 19572ms.
[08:24:18.420] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:24:18.420] <TB3> INFO: dacScan step from 36 .. 39
[08:24:38.000] <TB3> INFO: Test took 19579ms.
[08:24:38.025] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:24:38.025] <TB3> INFO: dacScan step from 40 .. 43
[08:24:57.423] <TB3> INFO: Test took 19398ms.
[08:24:57.533] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:24:57.533] <TB3> INFO: dacScan step from 44 .. 47
[08:25:17.754] <TB3> INFO: Test took 20221ms.
[08:25:17.846] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:25:17.846] <TB3> INFO: dacScan step from 48 .. 51
[08:25:37.999] <TB3> INFO: Test took 20153ms.
[08:25:38.034] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:25:38.034] <TB3> INFO: dacScan step from 52 .. 55
[08:25:58.178] <TB3> INFO: Test took 20144ms.
[08:25:58.277] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:25:58.277] <TB3> INFO: dacScan step from 56 .. 59
[08:26:23.677] <TB3> INFO: Test took 25400ms.
[08:26:23.722] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:26:23.722] <TB3> INFO: dacScan step from 60 .. 63
[08:26:43.833] <TB3> INFO: Test took 20110ms.
[08:26:43.863] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:26:43.863] <TB3> INFO: dacScan step from 64 .. 67
[08:27:03.697] <TB3> INFO: Test took 19834ms.
[08:27:03.806] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:27:03.807] <TB3> INFO: dacScan step from 68 .. 71
[08:27:24.487] <TB3> INFO: Test took 20680ms.
[08:27:24.718] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:27:24.720] <TB3> INFO: dacScan step from 72 .. 75
[08:27:45.825] <TB3> INFO: Test took 21105ms.
[08:27:46.080] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:27:46.083] <TB3> INFO: dacScan step from 76 .. 79
[08:28:08.741] <TB3> INFO: Test took 22658ms.
[08:28:09.157] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:28:09.168] <TB3> INFO: dacScan step from 80 .. 83
[08:28:34.713] <TB3> INFO: Test took 25545ms.
[08:28:34.885] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:28:34.894] <TB3> INFO: dacScan step from 84 .. 87
[08:29:02.927] <TB3> INFO: Test took 28033ms.
[08:29:03.149] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:29:03.163] <TB3> INFO: dacScan step from 88 .. 91
[08:29:32.626] <TB3> INFO: Test took 29463ms.
[08:29:32.832] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:29:32.840] <TB3> INFO: dacScan step from 92 .. 95
[08:30:03.151] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (31) != TBM ID (8)
[08:30:03.151] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (1) != Token Chain Length (4)
[08:30:03.151] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (32)
[08:30:03.151] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 31 readouts!
[08:30:03.151] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!
[08:30:03.587] <TB3> INFO: Test took 30747ms.
[08:30:03.863] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:30:03.887] <TB3> INFO: dacScan step from 96 .. 99
[08:30:32.895] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[08:30:32.895] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:30:33.873] <TB3> INFO: Test took 29986ms.
[08:30:34.924] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:30:34.978] <TB3> INFO: dacScan step from 100 .. 103
[08:31:03.813] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[08:31:04.984] <TB3> INFO: Test took 30006ms.
[08:31:05.935] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:31:05.982] <TB3> INFO: dacScan step from 104 .. 107
[08:31:35.057] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[08:31:35.057] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:31:36.326] <TB3> INFO: Test took 30344ms.
[08:31:37.266] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:31:37.313] <TB3> INFO: dacScan step from 108 .. 111
[08:32:07.268] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[08:32:07.268] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:32:08.745] <TB3> INFO: Test took 31432ms.
[08:32:09.827] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:32:09.871] <TB3> INFO: dacScan step from 112 .. 115
[08:32:38.834] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[08:32:38.834] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:32:40.171] <TB3> INFO: Test took 30300ms.
[08:32:41.274] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:32:41.335] <TB3> INFO: dacScan step from 116 .. 119
[08:33:11.497] <TB3> INFO: Test took 30153ms.
[08:33:12.666] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:33:12.732] <TB3> INFO: dacScan step from 120 .. 123
[08:33:43.047] <TB3> INFO: Test took 30315ms.
[08:33:43.310] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:33:43.328] <TB3> INFO: dacScan step from 124 .. 127
[08:34:13.945] <TB3> INFO: Test took 30617ms.
[08:34:14.690] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:34:14.733] <TB3> INFO: dacScan step from 128 .. 131
[08:34:44.503] <TB3> INFO: Test took 29769ms.
[08:34:45.718] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:34:45.803] <TB3> INFO: dacScan step from 132 .. 135
[08:35:15.960] <TB3> INFO: Test took 30157ms.
[08:35:17.079] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:35:17.159] <TB3> INFO: dacScan step from 136 .. 139
[08:35:48.676] <TB3> INFO: Test took 31517ms.
[08:35:48.922] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:35:48.934] <TB3> INFO: dacScan step from 140 .. 143
[08:36:20.072] <TB3> INFO: Test took 31138ms.
[08:36:20.330] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:36:20.342] <TB3> INFO: dacScan step from 144 .. 147
[08:36:51.769] <TB3> INFO: Test took 31427ms.
[08:36:51.993] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:36:52.004] <TB3> INFO: dacScan step from 148 .. 149
[08:37:09.112] <TB3> INFO: Test took 17108ms.
[08:37:09.258] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:37:09.270] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:10.963] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:12.503] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:13.949] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:15.613] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:17.184] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:18.846] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:20.504] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:22.080] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:23.605] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:25.021] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:26.524] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:27.993] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:29.457] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:30.960] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:32.439] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:37:33.977] <TB3> INFO: PixTestScurves::scurves() done
[08:37:33.977] <TB3> INFO: Vcal mean: 78.40 70.12 88.52 82.49 95.99 80.77 86.46 87.52 77.97 98.82 88.45 88.97 89.72 78.30 81.31 83.86
[08:37:33.977] <TB3> INFO: Vcal RMS: 5.18 4.58 5.89 5.17 5.96 4.94 4.91 5.53 4.22 6.01 5.00 5.37 5.94 4.14 4.04 5.34
[08:37:33.977] <TB3> INFO: PixTestScurves::fullTest() done, duration: 972 seconds
[08:37:34.078] <TB3> INFO: ######################################################################
[08:37:34.078] <TB3> INFO: PixTestTrim::doTest()
[08:37:34.078] <TB3> INFO: ######################################################################
[08:37:34.080] <TB3> INFO: ----------------------------------------------------------------------
[08:37:34.080] <TB3> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[08:37:34.080] <TB3> INFO: ----------------------------------------------------------------------
[08:37:34.163] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[08:37:34.163] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[08:37:34.171] <TB3> INFO: dacScan step from 0 .. 19
[08:37:50.018] <TB3> INFO: Test took 15847ms.
[08:37:50.042] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:37:50.042] <TB3> INFO: dacScan step from 20 .. 39
[08:38:05.827] <TB3> INFO: Test took 15785ms.
[08:38:05.854] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:05.854] <TB3> INFO: dacScan step from 40 .. 59
[08:38:21.690] <TB3> INFO: Test took 15836ms.
[08:38:21.712] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:21.712] <TB3> INFO: dacScan step from 60 .. 79
[08:38:37.644] <TB3> INFO: Test took 15932ms.
[08:38:37.670] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:37.670] <TB3> INFO: dacScan step from 80 .. 99
[08:38:54.806] <TB3> INFO: Test took 17136ms.
[08:38:54.880] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:54.890] <TB3> INFO: dacScan step from 100 .. 119
[08:39:15.627] <TB3> INFO: Test took 20737ms.
[08:39:15.799] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:39:15.829] <TB3> INFO: dacScan step from 120 .. 139
[08:39:35.582] <TB3> INFO: Test took 19752ms.
[08:39:35.727] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:39:35.761] <TB3> INFO: dacScan step from 140 .. 159
[08:39:52.658] <TB3> INFO: Test took 16897ms.
[08:39:52.720] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:40:14.757] <TB3> INFO: ROC 0 VthrComp = 79
[08:40:14.758] <TB3> INFO: ROC 1 VthrComp = 75
[08:40:14.758] <TB3> INFO: ROC 2 VthrComp = 92
[08:40:14.758] <TB3> INFO: ROC 3 VthrComp = 87
[08:40:14.758] <TB3> INFO: ROC 4 VthrComp = 97
[08:40:14.758] <TB3> INFO: ROC 5 VthrComp = 86
[08:40:14.758] <TB3> INFO: ROC 6 VthrComp = 88
[08:40:14.758] <TB3> INFO: ROC 7 VthrComp = 89
[08:40:14.758] <TB3> INFO: ROC 8 VthrComp = 80
[08:40:14.758] <TB3> INFO: ROC 9 VthrComp = 99
[08:40:14.758] <TB3> INFO: ROC 10 VthrComp = 94
[08:40:14.758] <TB3> INFO: ROC 11 VthrComp = 98
[08:40:14.758] <TB3> INFO: ROC 12 VthrComp = 98
[08:40:14.759] <TB3> INFO: ROC 13 VthrComp = 84
[08:40:14.759] <TB3> INFO: ROC 14 VthrComp = 89
[08:40:14.759] <TB3> INFO: ROC 15 VthrComp = 88
[08:40:14.759] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[08:40:14.759] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[08:40:14.770] <TB3> INFO: dacScan step from 0 .. 19
[08:40:30.338] <TB3> INFO: Test took 15568ms.
[08:40:30.361] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:40:30.361] <TB3> INFO: dacScan step from 20 .. 39
[08:40:46.554] <TB3> INFO: Test took 16193ms.
[08:40:46.586] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:40:46.589] <TB3> INFO: dacScan step from 40 .. 59
[08:41:06.740] <TB3> INFO: Test took 20151ms.
[08:41:06.899] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:41:06.935] <TB3> INFO: dacScan step from 60 .. 79
[08:41:28.755] <TB3> INFO: Test took 21820ms.
[08:41:28.937] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:41:28.983] <TB3> INFO: dacScan step from 80 .. 99
[08:41:50.641] <TB3> INFO: Test took 21658ms.
[08:41:50.816] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:41:50.860] <TB3> INFO: dacScan step from 100 .. 119
[08:42:12.609] <TB3> INFO: Test took 21749ms.
[08:42:12.787] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:42:12.835] <TB3> INFO: dacScan step from 120 .. 139
[08:42:34.632] <TB3> INFO: Test took 21797ms.
[08:42:34.802] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:42:34.847] <TB3> INFO: dacScan step from 140 .. 159
[08:42:56.385] <TB3> INFO: Test took 21538ms.
[08:42:56.567] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:43:22.478] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 63.7136 for pixel 4/2 mean/min/max = 48.6212/33.4301/63.8124
[08:43:22.478] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 58.1991 for pixel 0/0 mean/min/max = 46.4443/34.6411/58.2475
[08:43:22.478] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 59.7328 for pixel 51/45 mean/min/max = 45.8243/31.8591/59.7894
[08:43:22.478] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 57.9607 for pixel 51/0 mean/min/max = 45.1642/32.0889/58.2394
[08:43:22.479] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 60.0446 for pixel 23/1 mean/min/max = 45.4314/30.6994/60.1634
[08:43:22.479] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 58.6565 for pixel 12/62 mean/min/max = 45.3127/31.7905/58.835
[08:43:22.479] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 60.5576 for pixel 21/0 mean/min/max = 47.3106/33.8534/60.7679
[08:43:22.480] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 60.8475 for pixel 2/6 mean/min/max = 46.8712/32.7818/60.9606
[08:43:22.480] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 57.0276 for pixel 41/65 mean/min/max = 45.2635/33.4519/57.0751
[08:43:22.480] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 61.1885 for pixel 8/71 mean/min/max = 46.5167/31.5974/61.4359
[08:43:22.481] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 57.3539 for pixel 3/2 mean/min/max = 44.4145/31.4527/57.3763
[08:43:22.481] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 58.1559 for pixel 9/76 mean/min/max = 45.182/31.956/58.408
[08:43:22.481] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 58.9186 for pixel 0/77 mean/min/max = 45.043/31.1213/58.9647
[08:43:22.482] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 56.5886 for pixel 0/37 mean/min/max = 44.6476/32.6461/56.6491
[08:43:22.482] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 55.9926 for pixel 23/38 mean/min/max = 44.5775/33.1185/56.0366
[08:43:22.483] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 60.0523 for pixel 18/53 mean/min/max = 46.201/32.3171/60.0849
[08:43:22.483] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:45:02.140] <TB3> INFO: Test took 99657ms.
[08:45:03.667] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[08:45:03.676] <TB3> INFO: dacScan step from 0 .. 19
[08:45:27.963] <TB3> INFO: Test took 24286ms.
[08:45:28.008] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:45:28.010] <TB3> INFO: dacScan step from 20 .. 39
[08:45:58.927] <TB3> INFO: Test took 30917ms.
[08:45:59.168] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:45:59.199] <TB3> INFO: dacScan step from 40 .. 59
[08:46:33.407] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[08:46:33.407] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:46:34.678] <TB3> INFO: Test took 35479ms.
[08:46:34.967] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:46:35.012] <TB3> INFO: dacScan step from 60 .. 79
[08:47:08.055] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[08:47:08.055] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:47:09.483] <TB3> INFO: Test took 34471ms.
[08:47:09.794] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:47:09.833] <TB3> INFO: dacScan step from 80 .. 99
[08:47:43.599] <TB3> INFO: Test took 33766ms.
[08:47:43.877] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:47:43.922] <TB3> INFO: dacScan step from 100 .. 119
[08:48:18.307] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[08:48:18.307] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:48:19.787] <TB3> INFO: Test took 35865ms.
[08:48:20.069] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:48:20.109] <TB3> INFO: dacScan step from 120 .. 139
[08:48:54.699] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (202) != TBM ID (8)
[08:48:54.700] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[08:48:54.700] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (203)
[08:48:56.165] <TB3> INFO: Test took 36056ms.
[08:48:56.453] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:48:56.499] <TB3> INFO: dacScan step from 140 .. 159
[08:49:32.756] <TB3> INFO: Test took 36257ms.
[08:49:33.034] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:49:33.069] <TB3> INFO: dacScan step from 160 .. 179
[08:50:07.988] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[08:50:07.988] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:50:09.353] <TB3> INFO: Test took 36284ms.
[08:50:09.664] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:50:09.707] <TB3> INFO: dacScan step from 180 .. 199
[08:50:43.051] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[08:50:43.052] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[08:50:44.305] <TB3> INFO: Test took 34598ms.
[08:50:44.567] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:51:08.918] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 0.099338 .. 255.000000
[08:51:08.996] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[08:51:09.004] <TB3> INFO: dacScan step from 0 .. 19
[08:51:22.372] <TB3> INFO: Test took 13368ms.
[08:51:22.391] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:51:22.391] <TB3> INFO: dacScan step from 20 .. 39
[08:51:37.912] <TB3> INFO: Test took 15521ms.
[08:51:37.990] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:51:38.006] <TB3> INFO: dacScan step from 40 .. 59
[08:51:57.001] <TB3> INFO: Test took 18995ms.
[08:51:57.147] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:51:57.189] <TB3> INFO: dacScan step from 60 .. 79
[08:52:15.933] <TB3> INFO: Test took 18744ms.
[08:52:16.084] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:52:16.133] <TB3> INFO: dacScan step from 80 .. 99
[08:52:33.959] <TB3> INFO: Test took 17826ms.
[08:52:34.189] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:52:34.295] <TB3> INFO: dacScan step from 100 .. 119
[08:52:51.998] <TB3> INFO: Test took 17702ms.
[08:52:52.140] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:52:52.198] <TB3> INFO: dacScan step from 120 .. 139
[08:53:09.921] <TB3> INFO: Test took 17723ms.
[08:53:10.099] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:53:10.168] <TB3> INFO: dacScan step from 140 .. 159
[08:53:27.825] <TB3> INFO: Test took 17657ms.
[08:53:27.973] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:53:28.031] <TB3> INFO: dacScan step from 160 .. 179
[08:53:45.731] <TB3> INFO: Test took 17699ms.
[08:53:45.867] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:53:45.943] <TB3> INFO: dacScan step from 180 .. 199
[08:54:05.388] <TB3> INFO: Test took 19445ms.
[08:54:05.526] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:54:05.572] <TB3> INFO: dacScan step from 200 .. 219
[08:54:24.177] <TB3> INFO: Test took 18605ms.
[08:54:24.316] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:54:24.362] <TB3> INFO: dacScan step from 220 .. 239
[08:54:43.373] <TB3> INFO: Test took 19011ms.
[08:54:43.525] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:54:43.574] <TB3> INFO: dacScan step from 240 .. 255
[08:54:59.541] <TB3> INFO: Test took 15967ms.
[08:54:59.654] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:55:33.596] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 13.868201 .. 80.096457
[08:55:33.681] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 3 .. 90 (20) hits flags = 16 (plus default)
[08:55:33.689] <TB3> INFO: dacScan step from 3 .. 22
[08:55:47.710] <TB3> INFO: Test took 14021ms.
[08:55:47.737] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:55:47.737] <TB3> INFO: dacScan step from 23 .. 42
[08:56:03.760] <TB3> INFO: Test took 16023ms.
[08:56:03.874] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:03.897] <TB3> INFO: dacScan step from 43 .. 62
[08:56:22.574] <TB3> INFO: Test took 18677ms.
[08:56:22.713] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:22.761] <TB3> INFO: dacScan step from 63 .. 82
[08:56:40.151] <TB3> INFO: Test took 17390ms.
[08:56:40.290] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:40.346] <TB3> INFO: dacScan step from 83 .. 90
[08:56:49.536] <TB3> INFO: Test took 9190ms.
[08:56:49.595] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:57:11.254] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 18.994399 .. 61.158247
[08:57:11.333] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 8 .. 71 (20) hits flags = 16 (plus default)
[08:57:11.342] <TB3> INFO: dacScan step from 8 .. 27
[08:57:25.477] <TB3> INFO: Test took 14135ms.
[08:57:25.501] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:57:25.501] <TB3> INFO: dacScan step from 28 .. 47
[08:57:42.568] <TB3> INFO: Test took 17067ms.
[08:57:42.705] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:57:42.736] <TB3> INFO: dacScan step from 48 .. 67
[08:58:01.566] <TB3> INFO: Test took 18830ms.
[08:58:01.712] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:58:01.762] <TB3> INFO: dacScan step from 68 .. 71
[08:58:07.875] <TB3> INFO: Test took 6113ms.
[08:58:07.915] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:58:28.838] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 8.500000 .. 58.147067
[08:58:28.929] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 8 .. 68 (20) hits flags = 16 (plus default)
[08:58:28.937] <TB3> INFO: dacScan step from 8 .. 27
[08:58:43.114] <TB3> INFO: Test took 14177ms.
[08:58:43.139] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:58:43.139] <TB3> INFO: dacScan step from 28 .. 47
[08:59:00.358] <TB3> INFO: Test took 17219ms.
[08:59:00.504] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:59:00.535] <TB3> INFO: dacScan step from 48 .. 67
[08:59:19.377] <TB3> INFO: Test took 18842ms.
[08:59:19.523] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:59:19.566] <TB3> INFO: dacScan step from 68 .. 68
[08:59:23.224] <TB3> INFO: Test took 3657ms.
[08:59:23.238] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:59:41.796] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[08:59:41.796] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[08:59:41.804] <TB3> INFO: dacScan step from 15 .. 34
[09:00:06.405] <TB3> INFO: Test took 24600ms.
[09:00:06.487] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:00:06.496] <TB3> INFO: dacScan step from 35 .. 54
[09:00:40.278] <TB3> INFO: Test took 33782ms.
[09:00:40.558] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:00:40.602] <TB3> INFO: dacScan step from 55 .. 55
[09:00:44.901] <TB3> INFO: Test took 4299ms.
[09:00:44.915] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:00:58.809] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C0.dat
[09:00:58.809] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C1.dat
[09:00:58.809] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C2.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C3.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C4.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C5.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C6.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C7.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C8.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C9.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C10.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C11.dat
[09:00:58.810] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C12.dat
[09:00:58.811] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C13.dat
[09:00:58.811] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C14.dat
[09:00:58.811] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C15.dat
[09:00:58.811] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C0.dat
[09:00:58.819] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C1.dat
[09:00:58.826] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C2.dat
[09:00:58.833] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C3.dat
[09:00:58.839] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C4.dat
[09:00:58.845] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C5.dat
[09:00:58.852] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C6.dat
[09:00:58.859] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C7.dat
[09:00:58.865] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C8.dat
[09:00:58.871] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C9.dat
[09:00:58.878] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C10.dat
[09:00:58.884] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C11.dat
[09:00:58.890] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C12.dat
[09:00:58.896] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C13.dat
[09:00:58.902] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C14.dat
[09:00:58.908] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//trimParameters35_C15.dat
[09:00:58.914] <TB3> INFO: PixTestTrim::trimTest() done
[09:00:58.914] <TB3> INFO: vtrim: 109 91 101 101 116 113 106 101 99 143 110 114 123 100 105 110
[09:00:58.914] <TB3> INFO: vthrcomp: 79 75 92 87 97 86 88 89 80 99 94 98 98 84 89 88
[09:00:58.914] <TB3> INFO: vcal mean: 35.06 35.08 35.03 35.04 35.02 35.02 35.09 35.05 35.00 35.04 35.04 35.05 35.00 35.00 35.03 35.04
[09:00:58.914] <TB3> INFO: vcal RMS: 1.05 1.02 1.14 1.01 1.26 1.14 1.16 1.07 1.00 1.07 1.04 1.01 1.05 0.96 0.96 1.03
[09:00:58.914] <TB3> INFO: bits mean: 9.12 9.26 9.58 9.44 10.27 10.11 9.12 9.60 10.19 9.94 10.11 10.00 10.05 10.11 10.29 9.63
[09:00:58.914] <TB3> INFO: bits RMS: 2.45 2.42 2.66 2.73 2.36 2.43 2.51 2.52 2.24 2.48 2.55 2.50 2.61 2.42 2.25 2.59
[09:00:58.920] <TB3> INFO: ----------------------------------------------------------------------
[09:00:58.920] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[09:00:58.920] <TB3> INFO: ----------------------------------------------------------------------
[09:00:58.922] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[09:00:58.930] <TB3> INFO: dacScan step from 0 .. 19
[09:01:22.401] <TB3> INFO: Test took 23471ms.
[09:01:22.435] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:01:22.435] <TB3> INFO: dacScan step from 20 .. 39
[09:01:44.915] <TB3> INFO: Test took 22479ms.
[09:01:44.947] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:01:44.947] <TB3> INFO: dacScan step from 40 .. 59
[09:02:09.035] <TB3> INFO: Test took 24088ms.
[09:02:09.075] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:02:09.075] <TB3> INFO: dacScan step from 60 .. 79
[09:02:33.092] <TB3> INFO: Test took 24017ms.
[09:02:33.126] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:02:33.126] <TB3> INFO: dacScan step from 80 .. 99
[09:02:57.987] <TB3> INFO: Test took 24861ms.
[09:02:58.058] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:02:58.062] <TB3> INFO: dacScan step from 100 .. 119
[09:03:29.769] <TB3> INFO: Test took 31707ms.
[09:03:30.040] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:03:30.064] <TB3> INFO: dacScan step from 120 .. 139
[09:04:06.180] <TB3> INFO: Test took 36116ms.
[09:04:06.490] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:04:06.533] <TB3> INFO: dacScan step from 140 .. 159
[09:04:41.346] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[09:04:41.346] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[09:04:42.872] <TB3> INFO: Test took 36339ms.
[09:04:43.167] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:04:43.214] <TB3> INFO: dacScan step from 160 .. 179
[09:05:19.393] <TB3> INFO: Test took 36179ms.
[09:05:19.648] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:05:19.691] <TB3> INFO: dacScan step from 180 .. 199
[09:05:56.404] <TB3> INFO: Test took 36712ms.
[09:05:56.692] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:06:24.055] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 171 (20) hits flags = 16 (plus default)
[09:06:24.063] <TB3> INFO: dacScan step from 0 .. 19
[09:06:46.276] <TB3> INFO: Test took 22213ms.
[09:06:46.309] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:06:46.309] <TB3> INFO: dacScan step from 20 .. 39
[09:07:08.593] <TB3> INFO: Test took 22284ms.
[09:07:08.629] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:08.629] <TB3> INFO: dacScan step from 40 .. 59
[09:07:33.085] <TB3> INFO: Test took 24456ms.
[09:07:33.122] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:33.122] <TB3> INFO: dacScan step from 60 .. 79
[09:07:55.832] <TB3> INFO: Test took 22710ms.
[09:07:55.871] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:55.871] <TB3> INFO: dacScan step from 80 .. 99
[09:08:20.994] <TB3> INFO: Test took 25123ms.
[09:08:21.129] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:08:21.143] <TB3> INFO: dacScan step from 100 .. 119
[09:08:56.108] <TB3> INFO: Test took 34965ms.
[09:08:56.376] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:08:56.408] <TB3> INFO: dacScan step from 120 .. 139
[09:09:27.724] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[09:09:27.724] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[09:09:28.972] <TB3> INFO: Test took 32564ms.
[09:09:29.249] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:09:29.291] <TB3> INFO: dacScan step from 140 .. 159
[09:10:05.171] <TB3> INFO: Test took 35880ms.
[09:10:05.429] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:10:05.467] <TB3> INFO: dacScan step from 160 .. 171
[09:10:26.990] <TB3> INFO: Test took 21523ms.
[09:10:27.144] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:10:50.256] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 160 (20) hits flags = 16 (plus default)
[09:10:50.265] <TB3> INFO: dacScan step from 0 .. 19
[09:11:14.104] <TB3> INFO: Test took 23839ms.
[09:11:14.137] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:11:14.137] <TB3> INFO: dacScan step from 20 .. 39
[09:11:38.523] <TB3> INFO: Test took 24386ms.
[09:11:38.558] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:11:38.558] <TB3> INFO: dacScan step from 40 .. 59
[09:12:02.400] <TB3> INFO: Test took 23842ms.
[09:12:02.438] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:12:02.438] <TB3> INFO: dacScan step from 60 .. 79
[09:12:25.611] <TB3> INFO: Test took 23173ms.
[09:12:25.649] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:12:25.650] <TB3> INFO: dacScan step from 80 .. 99
[09:12:52.748] <TB3> INFO: Test took 27098ms.
[09:12:52.929] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:12:52.949] <TB3> INFO: dacScan step from 100 .. 119
[09:13:25.492] <TB3> INFO: Test took 32543ms.
[09:13:25.757] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:13:25.788] <TB3> INFO: dacScan step from 120 .. 139
[09:14:00.308] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[09:14:00.309] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (150) != TBM ID (151)
[09:14:00.309] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[09:14:00.309] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[09:14:00.309] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[09:14:01.755] <TB3> INFO: Test took 35967ms.
[09:14:02.034] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:02.075] <TB3> INFO: dacScan step from 140 .. 159
[09:14:37.945] <TB3> INFO: Test took 35870ms.
[09:14:38.201] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:38.239] <TB3> INFO: dacScan step from 160 .. 160
[09:14:42.726] <TB3> INFO: Test took 4487ms.
[09:14:42.748] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:08.604] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 160 (20) hits flags = 16 (plus default)
[09:15:08.612] <TB3> INFO: dacScan step from 0 .. 19
[09:15:37.825] <TB3> INFO: Test took 29212ms.
[09:15:37.862] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:37.862] <TB3> INFO: dacScan step from 20 .. 39
[09:16:02.141] <TB3> INFO: Test took 24279ms.
[09:16:02.181] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:02.181] <TB3> INFO: dacScan step from 40 .. 59
[09:16:26.495] <TB3> INFO: Test took 24314ms.
[09:16:26.528] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:26.528] <TB3> INFO: dacScan step from 60 .. 79
[09:16:50.950] <TB3> INFO: Test took 24422ms.
[09:16:50.995] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:50.996] <TB3> INFO: dacScan step from 80 .. 99
[09:17:18.491] <TB3> INFO: Test took 27495ms.
[09:17:18.636] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:18.652] <TB3> INFO: dacScan step from 100 .. 119
[09:17:53.538] <TB3> INFO: Test took 34886ms.
[09:17:53.796] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:53.827] <TB3> INFO: dacScan step from 120 .. 139
[09:18:27.610] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[09:18:27.610] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[09:18:28.858] <TB3> INFO: Test took 35031ms.
[09:18:29.182] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:18:29.233] <TB3> INFO: dacScan step from 140 .. 159
[09:19:02.362] <TB3> INFO: Test took 33129ms.
[09:19:02.686] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:02.735] <TB3> INFO: dacScan step from 160 .. 160
[09:19:07.073] <TB3> INFO: Test took 4338ms.
[09:19:07.086] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:30.380] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 160 (20) hits flags = 16 (plus default)
[09:19:30.388] <TB3> INFO: dacScan step from 0 .. 19
[09:19:54.556] <TB3> INFO: Test took 24167ms.
[09:19:54.594] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:54.594] <TB3> INFO: dacScan step from 20 .. 39
[09:20:17.617] <TB3> INFO: Test took 23023ms.
[09:20:17.661] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:17.661] <TB3> INFO: dacScan step from 40 .. 59
[09:20:41.640] <TB3> INFO: Test took 23979ms.
[09:20:41.681] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:41.681] <TB3> INFO: dacScan step from 60 .. 79
[09:21:05.955] <TB3> INFO: Test took 24274ms.
[09:21:06.001] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:06.002] <TB3> INFO: dacScan step from 80 .. 99
[09:21:32.366] <TB3> INFO: Test took 26364ms.
[09:21:32.500] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:32.512] <TB3> INFO: dacScan step from 100 .. 119
[09:22:07.420] <TB3> INFO: Test took 34908ms.
[09:22:07.696] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:07.736] <TB3> INFO: dacScan step from 120 .. 139
[09:22:39.961] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[09:22:39.961] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[09:22:41.202] <TB3> INFO: Test took 33466ms.
[09:22:41.549] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:41.621] <TB3> INFO: dacScan step from 140 .. 159
[09:23:14.559] <TB3> INFO: Test took 32938ms.
[09:23:14.943] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:15.001] <TB3> INFO: dacScan step from 160 .. 160
[09:23:19.373] <TB3> INFO: Test took 4372ms.
[09:23:19.386] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:41.868] <TB3> INFO: PixTestTrim::trimBitTest() done
[09:23:41.870] <TB3> INFO: PixTestTrim::doTest() done, duration: 2767 seconds
[09:23:42.625] <TB3> INFO: ######################################################################
[09:23:42.625] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[09:23:42.625] <TB3> INFO: ######################################################################
[09:23:46.098] <TB3> INFO: Test took 3472ms.
[09:23:46.128] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:49.814] <TB3> INFO: Test took 3468ms.
[09:23:49.875] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:53.285] <TB3> INFO: Test took 3401ms.
[09:23:53.350] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:53.357] <TB3> INFO: The DUT currently contains the following objects:
[09:23:53.357] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:23:53.357] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:23:53.357] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:23:53.357] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:23:53.357] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:53.357] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.470] <TB3> INFO: Test took 1113ms.
[09:23:54.471] <TB3> INFO: The DUT currently contains the following objects:
[09:23:54.471] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:23:54.471] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:23:54.471] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:23:54.471] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:23:54.471] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:54.472] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.584] <TB3> INFO: Test took 1112ms.
[09:23:55.586] <TB3> INFO: The DUT currently contains the following objects:
[09:23:55.586] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:23:55.586] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:23:55.586] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:23:55.586] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:23:55.586] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.586] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:55.587] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.698] <TB3> INFO: Test took 1111ms.
[09:23:56.699] <TB3> INFO: The DUT currently contains the following objects:
[09:23:56.699] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:23:56.699] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:23:56.699] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:23:56.700] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:23:56.700] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:56.700] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.812] <TB3> INFO: Test took 1112ms.
[09:23:57.813] <TB3> INFO: The DUT currently contains the following objects:
[09:23:57.824] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:23:57.824] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:23:57.824] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:23:57.824] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:23:57.824] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.824] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.824] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.824] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.824] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.824] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.824] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.824] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.824] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.824] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.825] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.825] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.825] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.825] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.825] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:57.825] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.920] <TB3> INFO: Test took 1095ms.
[09:23:58.921] <TB3> INFO: The DUT currently contains the following objects:
[09:23:58.921] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:23:58.921] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:23:58.921] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:23:58.921] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:23:58.921] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.921] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.921] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.921] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.921] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.921] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.921] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.921] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.922] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.922] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.922] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.922] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.922] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.922] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.922] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:23:58.922] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.028] <TB3> INFO: Test took 1106ms.
[09:24:00.029] <TB3> INFO: The DUT currently contains the following objects:
[09:24:00.029] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:00.029] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:00.029] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:00.029] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:00.029] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:00.029] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.142] <TB3> INFO: Test took 1113ms.
[09:24:01.143] <TB3> INFO: The DUT currently contains the following objects:
[09:24:01.143] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:01.143] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:01.143] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:01.143] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:01.143] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.143] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.143] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:01.144] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.256] <TB3> INFO: Test took 1112ms.
[09:24:02.258] <TB3> INFO: The DUT currently contains the following objects:
[09:24:02.258] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:02.258] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:02.258] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:02.258] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:02.258] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:02.258] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.371] <TB3> INFO: Test took 1113ms.
[09:24:03.373] <TB3> INFO: The DUT currently contains the following objects:
[09:24:03.373] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:03.373] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:03.373] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:03.373] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:03.373] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.373] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.373] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.373] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.373] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.373] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.373] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.373] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.373] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.374] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.374] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.374] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.374] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.374] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.374] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:03.374] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.484] <TB3> INFO: Test took 1110ms.
[09:24:04.485] <TB3> INFO: The DUT currently contains the following objects:
[09:24:04.485] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:04.485] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:04.485] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:04.485] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:04.485] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.485] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.486] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.486] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.486] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.486] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:04.486] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.600] <TB3> INFO: Test took 1114ms.
[09:24:05.601] <TB3> INFO: The DUT currently contains the following objects:
[09:24:05.613] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:05.613] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:05.613] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:05.613] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:05.613] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.613] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.614] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:05.614] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.714] <TB3> INFO: Test took 1100ms.
[09:24:06.715] <TB3> INFO: The DUT currently contains the following objects:
[09:24:06.716] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:06.716] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:06.716] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:06.716] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:06.716] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.716] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:06.717] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.828] <TB3> INFO: Test took 1111ms.
[09:24:07.830] <TB3> INFO: The DUT currently contains the following objects:
[09:24:07.830] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:07.830] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:07.830] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:07.830] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:07.830] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.830] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.831] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:07.831] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.944] <TB3> INFO: Test took 1113ms.
[09:24:08.945] <TB3> INFO: The DUT currently contains the following objects:
[09:24:08.945] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:08.945] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:08.945] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:08.945] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:08.946] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:08.946] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.058] <TB3> INFO: Test took 1112ms.
[09:24:10.059] <TB3> INFO: The DUT currently contains the following objects:
[09:24:10.059] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:24:10.060] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:24:10.060] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:24:10.060] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:24:10.060] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:10.060] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:24:11.174] <TB3> INFO: Test took 1114ms.
[09:24:11.176] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:28:14.743] <TB3> INFO: Test took 243567ms.
[09:28:16.567] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:15.465] <TB3> INFO: Test took 238898ms.
[09:32:17.083] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.090] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.098] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.124] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[09:32:17.130] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[09:32:17.138] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[09:32:17.145] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[09:32:17.151] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[09:32:17.159] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.168] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.175] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.182] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.188] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.196] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.204] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.211] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.217] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.224] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.231] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.237] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.243] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[09:32:17.267] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C0.dat
[09:32:17.271] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C1.dat
[09:32:17.271] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C2.dat
[09:32:17.271] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C3.dat
[09:32:17.271] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C4.dat
[09:32:17.272] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C5.dat
[09:32:17.272] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C6.dat
[09:32:17.272] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C7.dat
[09:32:17.272] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C8.dat
[09:32:17.273] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C9.dat
[09:32:17.273] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C10.dat
[09:32:17.273] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C11.dat
[09:32:17.273] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C12.dat
[09:32:17.274] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C13.dat
[09:32:17.274] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C14.dat
[09:32:17.274] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//dacParameters35_C15.dat
[09:32:20.878] <TB3> INFO: Test took 3602ms.
[09:32:24.803] <TB3> INFO: Test took 3642ms.
[09:32:28.735] <TB3> INFO: Test took 3660ms.
[09:32:29.023] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:29.946] <TB3> INFO: Test took 923ms.
[09:32:29.948] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:31.061] <TB3> INFO: Test took 1113ms.
[09:32:31.066] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:32.177] <TB3> INFO: Test took 1111ms.
[09:32:32.180] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:33.293] <TB3> INFO: Test took 1113ms.
[09:32:33.296] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:34.409] <TB3> INFO: Test took 1113ms.
[09:32:34.412] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:35.526] <TB3> INFO: Test took 1114ms.
[09:32:35.529] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:36.643] <TB3> INFO: Test took 1114ms.
[09:32:36.647] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:37.761] <TB3> INFO: Test took 1115ms.
[09:32:37.764] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:38.877] <TB3> INFO: Test took 1113ms.
[09:32:38.879] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:39.986] <TB3> INFO: Test took 1107ms.
[09:32:39.988] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:41.102] <TB3> INFO: Test took 1114ms.
[09:32:41.105] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:42.218] <TB3> INFO: Test took 1113ms.
[09:32:42.221] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:43.334] <TB3> INFO: Test took 1114ms.
[09:32:43.338] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:44.452] <TB3> INFO: Test took 1114ms.
[09:32:44.456] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:45.568] <TB3> INFO: Test took 1113ms.
[09:32:45.571] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:46.684] <TB3> INFO: Test took 1113ms.
[09:32:46.686] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:47.798] <TB3> INFO: Test took 1112ms.
[09:32:47.801] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:48.914] <TB3> INFO: Test took 1113ms.
[09:32:48.917] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:50.030] <TB3> INFO: Test took 1113ms.
[09:32:50.033] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:51.146] <TB3> INFO: Test took 1113ms.
[09:32:51.148] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:52.261] <TB3> INFO: Test took 1113ms.
[09:32:52.264] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:53.379] <TB3> INFO: Test took 1115ms.
[09:32:53.382] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:54.496] <TB3> INFO: Test took 1114ms.
[09:32:54.498] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:55.612] <TB3> INFO: Test took 1114ms.
[09:32:55.614] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:56.727] <TB3> INFO: Test took 1113ms.
[09:32:56.730] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:57.844] <TB3> INFO: Test took 1114ms.
[09:32:57.847] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:32:58.961] <TB3> INFO: Test took 1114ms.
[09:32:58.964] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:33:00.078] <TB3> INFO: Test took 1114ms.
[09:33:00.082] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:33:01.198] <TB3> INFO: Test took 1116ms.
[09:33:01.201] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:33:02.313] <TB3> INFO: Test took 1113ms.
[09:33:02.316] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:33:03.430] <TB3> INFO: Test took 1114ms.
[09:33:03.433] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:33:04.546] <TB3> INFO: Test took 1113ms.
[09:33:05.088] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 562 seconds
[09:33:05.088] <TB3> INFO: PH scale (per ROC): 80 77 93 90 84 79 80 87 82 80 84 81 80 92 89 87
[09:33:05.088] <TB3> INFO: PH offset (per ROC): 165 146 144 145 153 154 153 158 149 159 160 156 144 147 163 150
[09:33:05.275] <TB3> INFO: ######################################################################
[09:33:05.275] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[09:33:05.275] <TB3> INFO: ######################################################################
[09:33:05.284] <TB3> INFO: scanning low vcal = 10
[09:33:09.285] <TB3> INFO: Test took 4001ms.
[09:33:09.289] <TB3> INFO: scanning low vcal = 20
[09:33:13.317] <TB3> INFO: Test took 4027ms.
[09:33:13.323] <TB3> INFO: scanning low vcal = 30
[09:33:17.285] <TB3> INFO: Test took 3962ms.
[09:33:17.298] <TB3> INFO: scanning low vcal = 40
[09:33:21.792] <TB3> INFO: Test took 4494ms.
[09:33:21.863] <TB3> INFO: scanning low vcal = 50
[09:33:26.351] <TB3> INFO: Test took 4488ms.
[09:33:26.422] <TB3> INFO: scanning low vcal = 60
[09:33:30.940] <TB3> INFO: Test took 4518ms.
[09:33:31.010] <TB3> INFO: scanning low vcal = 70
[09:33:35.519] <TB3> INFO: Test took 4509ms.
[09:33:35.582] <TB3> INFO: scanning low vcal = 80
[09:33:40.097] <TB3> INFO: Test took 4515ms.
[09:33:40.159] <TB3> INFO: scanning low vcal = 90
[09:33:44.628] <TB3> INFO: Test took 4469ms.
[09:33:44.690] <TB3> INFO: scanning low vcal = 100
[09:33:49.204] <TB3> INFO: Test took 4513ms.
[09:33:49.267] <TB3> INFO: scanning low vcal = 110
[09:33:53.795] <TB3> INFO: Test took 4528ms.
[09:33:53.874] <TB3> INFO: scanning low vcal = 120
[09:33:58.422] <TB3> INFO: Test took 4548ms.
[09:33:58.502] <TB3> INFO: scanning low vcal = 130
[09:34:03.030] <TB3> INFO: Test took 4528ms.
[09:34:03.101] <TB3> INFO: scanning low vcal = 140
[09:34:07.614] <TB3> INFO: Test took 4513ms.
[09:34:07.684] <TB3> INFO: scanning low vcal = 150
[09:34:12.191] <TB3> INFO: Test took 4507ms.
[09:34:12.260] <TB3> INFO: scanning low vcal = 160
[09:34:16.758] <TB3> INFO: Test took 4498ms.
[09:34:16.820] <TB3> INFO: scanning low vcal = 170
[09:34:21.331] <TB3> INFO: Test took 4511ms.
[09:34:21.392] <TB3> INFO: scanning low vcal = 180
[09:34:25.929] <TB3> INFO: Test took 4537ms.
[09:34:25.998] <TB3> INFO: scanning low vcal = 190
[09:34:30.621] <TB3> INFO: Test took 4623ms.
[09:34:30.687] <TB3> INFO: scanning low vcal = 200
[09:34:35.209] <TB3> INFO: Test took 4522ms.
[09:34:35.293] <TB3> INFO: scanning low vcal = 210
[09:34:39.818] <TB3> INFO: Test took 4525ms.
[09:34:39.884] <TB3> INFO: scanning low vcal = 220
[09:34:44.241] <TB3> INFO: Test took 4357ms.
[09:34:44.301] <TB3> INFO: scanning low vcal = 230
[09:34:48.712] <TB3> INFO: Test took 4411ms.
[09:34:48.782] <TB3> INFO: scanning low vcal = 240
[09:34:53.137] <TB3> INFO: Test took 4355ms.
[09:34:53.203] <TB3> INFO: scanning low vcal = 250
[09:34:57.515] <TB3> INFO: Test took 4312ms.
[09:34:57.592] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[09:35:01.907] <TB3> INFO: Test took 4315ms.
[09:35:01.965] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[09:35:06.543] <TB3> INFO: Test took 4578ms.
[09:35:06.614] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[09:35:11.129] <TB3> INFO: Test took 4515ms.
[09:35:11.209] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[09:35:15.724] <TB3> INFO: Test took 4515ms.
[09:35:15.795] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[09:35:20.323] <TB3> INFO: Test took 4528ms.
[09:35:20.905] <TB3> INFO: PixTestGainPedestal::measure() done
[09:35:55.325] <TB3> INFO: PixTestGainPedestal::fit() done
[09:35:55.326] <TB3> INFO: non-linearity mean: 0.955 0.951 0.962 0.956 0.958 0.956 0.959 0.962 0.953 0.951 0.959 0.958 0.955 0.950 0.952 0.952
[09:35:55.326] <TB3> INFO: non-linearity RMS: 0.007 0.006 0.004 0.006 0.008 0.006 0.006 0.005 0.006 0.006 0.005 0.006 0.006 0.006 0.006 0.006
[09:35:55.337] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[09:35:55.363] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[09:35:55.391] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[09:35:55.413] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[09:35:55.432] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[09:35:55.455] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[09:35:55.474] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[09:35:55.492] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[09:35:55.510] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[09:35:55.528] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[09:35:55.546] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[09:35:55.572] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[09:35:55.595] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[09:35:55.613] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[09:35:55.637] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[09:35:55.662] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//000_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[09:35:55.689] <TB3> INFO: PixTestGainPedestal::doTest() done, duration: 170 seconds
[09:35:55.697] <TB3> INFO: enter test to run
[09:35:55.699] <TB3> INFO: test: exit no parameter change
[09:35:56.163] <TB3> QUIET: Connection to board 170 closed.
[09:35:56.188] <TB3> INFO: pXar: this is the end, my friend