Test Date: 2015-07-10 12:10
Analysis date: 2016-05-25 21:56
Logfile
LogfileView
[10:23:06.464] <TB1> INFO: *** Welcome to pxar ***
[10:23:06.464] <TB1> INFO: *** Today: 2015/07/10
[10:23:06.464] <TB1> INFO: readRocDacs: /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C15.dat
[10:23:06.465] <TB1> INFO: readTbmDacs: /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//tbmParameters_C0b.dat
[10:23:06.465] <TB1> INFO: readMaskFile: /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//defaultMaskFile.dat
[10:23:06.465] <TB1> INFO: readTrimFile: /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters_C15.dat
[10:23:06.549] <TB1> INFO: clk: 4
[10:23:06.549] <TB1> INFO: ctr: 4
[10:23:06.549] <TB1> INFO: sda: 19
[10:23:06.549] <TB1> INFO: tin: 9
[10:23:06.549] <TB1> INFO: level: 15
[10:23:06.549] <TB1> INFO: triggerdelay: 0
[10:23:06.549] <TB1> QUIET: Instanciating API for pxar v2.2.5+45~gbf85984
[10:23:06.549] <TB1> INFO: Log level: INFO
[10:23:06.557] <TB1> INFO: Found DTB DTB_WXBYFL
[10:23:06.568] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[10:23:06.572] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[10:23:06.575] <TB1> INFO: RPC call hashes of host and DTB match: 447413373
[10:23:08.131] <TB1> INFO: DUT info:
[10:23:08.132] <TB1> INFO: The DUT currently contains the following objects:
[10:23:08.132] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:23:08.132] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:23:08.132] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:23:08.132] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:23:08.132] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.132] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:23:08.533] <TB1> INFO: enter 'restricted' command line mode
[10:23:08.533] <TB1> INFO: enter test to run
[10:23:08.534] <TB1> INFO: test: pretest no parameter change
[10:23:08.534] <TB1> INFO: running: pretest
[10:23:08.543] <TB1> INFO: ######################################################################
[10:23:08.543] <TB1> INFO: PixTestPretest::doTest()
[10:23:08.543] <TB1> INFO: ######################################################################
[10:23:08.545] <TB1> INFO: ----------------------------------------------------------------------
[10:23:08.545] <TB1> INFO: PixTestPretest::programROC()
[10:23:08.545] <TB1> INFO: ----------------------------------------------------------------------
[10:23:26.567] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[10:23:26.567] <TB1> INFO: IA differences per ROC: 18.5 18.5 18.5 20.1 16.1 16.1 16.9 18.5 16.9 19.3 17.7 16.1 18.5 19.3 18.5 16.9
[10:23:26.654] <TB1> INFO: ----------------------------------------------------------------------
[10:23:26.654] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[10:23:26.654] <TB1> INFO: ----------------------------------------------------------------------
[10:23:46.239] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 389.1 mA = 24.3188 mA/ROC
[10:23:46.242] <TB1> INFO: ----------------------------------------------------------------------
[10:23:46.242] <TB1> INFO: PixTestPretest::findWorkingPixel()
[10:23:46.242] <TB1> INFO: ----------------------------------------------------------------------
[10:23:54.638] <TB1> INFO: Test took 8391ms.
[10:23:54.952] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[10:23:55.001] <TB1> INFO: ----------------------------------------------------------------------
[10:23:55.001] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[10:23:55.001] <TB1> INFO: ----------------------------------------------------------------------
[10:24:03.530] <TB1> INFO: Test took 8522ms.
[10:24:03.856] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[10:24:03.856] <TB1> INFO: CalDel: 161 145 162 186 133 155 161 136 130 164 132 152 142 143 138 146
[10:24:03.856] <TB1> INFO: VthrComp: 56 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[10:24:03.860] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C0.dat
[10:24:03.860] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C1.dat
[10:24:03.861] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C2.dat
[10:24:03.861] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C3.dat
[10:24:03.861] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C4.dat
[10:24:03.861] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C5.dat
[10:24:03.861] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C6.dat
[10:24:03.862] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C7.dat
[10:24:03.862] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C8.dat
[10:24:03.862] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C9.dat
[10:24:03.862] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C10.dat
[10:24:03.862] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C11.dat
[10:24:03.862] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C12.dat
[10:24:03.862] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C13.dat
[10:24:03.863] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C14.dat
[10:24:03.863] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters_C15.dat
[10:24:03.863] <TB1> INFO: PixTestPretest::doTest() done, duration: 55 seconds
[10:24:03.959] <TB1> INFO: enter test to run
[10:24:03.959] <TB1> INFO: test: fulltest no parameter change
[10:24:03.959] <TB1> INFO: running: fulltest
[10:24:03.959] <TB1> INFO: ######################################################################
[10:24:03.959] <TB1> INFO: PixTestFullTest::doTest()
[10:24:03.959] <TB1> INFO: ######################################################################
[10:24:03.961] <TB1> INFO: ######################################################################
[10:24:03.961] <TB1> INFO: PixTestAlive::doTest()
[10:24:03.961] <TB1> INFO: ######################################################################
[10:24:03.962] <TB1> INFO: ----------------------------------------------------------------------
[10:24:03.962] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:24:03.962] <TB1> INFO: ----------------------------------------------------------------------
[10:24:07.364] <TB1> INFO: Test took 3399ms.
[10:24:07.383] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:07.629] <TB1> INFO: PixTestAlive::aliveTest() done
[10:24:07.629] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:24:07.631] <TB1> INFO: ----------------------------------------------------------------------
[10:24:07.631] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:24:07.631] <TB1> INFO: ----------------------------------------------------------------------
[10:24:10.347] <TB1> INFO: Test took 2714ms.
[10:24:10.349] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:10.349] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:24:10.588] <TB1> INFO: PixTestAlive::maskTest() done
[10:24:10.588] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:24:10.590] <TB1> INFO: ----------------------------------------------------------------------
[10:24:10.590] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:24:10.590] <TB1> INFO: ----------------------------------------------------------------------
[10:24:14.094] <TB1> INFO: Test took 3502ms.
[10:24:14.115] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:14.357] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[10:24:14.357] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:24:14.357] <TB1> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[10:24:14.366] <TB1> INFO: ######################################################################
[10:24:14.366] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[10:24:14.366] <TB1> INFO: ######################################################################
[10:24:14.370] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[10:24:14.383] <TB1> INFO: dacScan step from 0 .. 29
[10:24:35.245] <TB1> INFO: Test took 20862ms.
[10:24:35.283] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:35.285] <TB1> INFO: dacScan step from 30 .. 59
[10:24:57.662] <TB1> INFO: Test took 22377ms.
[10:24:57.763] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:57.779] <TB1> INFO: dacScan step from 60 .. 89
[10:25:26.868] <TB1> INFO: Test took 29089ms.
[10:25:27.169] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:25:27.242] <TB1> INFO: dacScan step from 90 .. 119
[10:25:56.908] <TB1> INFO: Test took 29666ms.
[10:25:57.240] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:25:57.347] <TB1> INFO: dacScan step from 120 .. 149
[10:26:22.377] <TB1> INFO: Test took 25030ms.
[10:26:22.583] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:26:45.867] <TB1> INFO: PixTestBBMap::doTest() done, duration: 151 seconds
[10:26:45.867] <TB1> INFO: number of dead bumps (per ROC): 2 0 0 0 0 0 0 0 3 6 1 3 3 2 10 22
[10:26:45.867] <TB1> INFO: separation cut (per ROC): 93 95 90 95 78 93 81 103 86 88 95 85 71 86 84 84
[10:26:45.938] <TB1> INFO: ######################################################################
[10:26:45.938] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50
[10:26:45.938] <TB1> INFO: ######################################################################
[10:26:45.938] <TB1> INFO: ----------------------------------------------------------------------
[10:26:45.938] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[10:26:45.938] <TB1> INFO: ----------------------------------------------------------------------
[10:26:45.938] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[10:26:45.946] <TB1> INFO: dacScan step from 0 .. 3
[10:27:04.311] <TB1> INFO: Test took 18365ms.
[10:27:04.338] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:04.338] <TB1> INFO: dacScan step from 4 .. 7
[10:27:22.855] <TB1> INFO: Test took 18517ms.
[10:27:22.883] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:22.883] <TB1> INFO: dacScan step from 8 .. 11
[10:27:41.384] <TB1> INFO: Test took 18501ms.
[10:27:41.413] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:41.413] <TB1> INFO: dacScan step from 12 .. 15
[10:27:59.795] <TB1> INFO: Test took 18382ms.
[10:27:59.822] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:59.823] <TB1> INFO: dacScan step from 16 .. 19
[10:28:17.878] <TB1> INFO: Test took 18055ms.
[10:28:17.905] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:17.905] <TB1> INFO: dacScan step from 20 .. 23
[10:28:35.790] <TB1> INFO: Test took 17885ms.
[10:28:35.817] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:35.817] <TB1> INFO: dacScan step from 24 .. 27
[10:28:54.229] <TB1> INFO: Test took 18412ms.
[10:28:54.261] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:54.261] <TB1> INFO: dacScan step from 28 .. 31
[10:29:12.670] <TB1> INFO: Test took 18409ms.
[10:29:12.696] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:12.696] <TB1> INFO: dacScan step from 32 .. 35
[10:29:31.139] <TB1> INFO: Test took 18443ms.
[10:29:31.167] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:31.167] <TB1> INFO: dacScan step from 36 .. 39
[10:29:49.704] <TB1> INFO: Test took 18537ms.
[10:29:49.733] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:29:49.733] <TB1> INFO: dacScan step from 40 .. 43
[10:30:08.200] <TB1> INFO: Test took 18467ms.
[10:30:08.232] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:08.232] <TB1> INFO: dacScan step from 44 .. 47
[10:30:26.566] <TB1> INFO: Test took 18334ms.
[10:30:26.594] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:26.594] <TB1> INFO: dacScan step from 48 .. 51
[10:30:45.722] <TB1> INFO: Test took 19128ms.
[10:30:45.748] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:45.748] <TB1> INFO: dacScan step from 52 .. 55
[10:31:05.011] <TB1> INFO: Test took 19263ms.
[10:31:05.042] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:31:05.042] <TB1> INFO: dacScan step from 56 .. 59
[10:31:24.077] <TB1> INFO: Test took 19035ms.
[10:31:24.104] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:31:24.104] <TB1> INFO: dacScan step from 60 .. 63
[10:31:43.361] <TB1> INFO: Test took 19257ms.
[10:31:43.392] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:31:43.392] <TB1> INFO: dacScan step from 64 .. 67
[10:32:02.607] <TB1> INFO: Test took 19215ms.
[10:32:02.635] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:32:02.635] <TB1> INFO: dacScan step from 68 .. 71
[10:32:21.938] <TB1> INFO: Test took 19303ms.
[10:32:21.967] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:32:21.967] <TB1> INFO: dacScan step from 72 .. 75
[10:32:41.253] <TB1> INFO: Test took 19286ms.
[10:32:41.297] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:32:41.297] <TB1> INFO: dacScan step from 76 .. 79
[10:33:00.645] <TB1> INFO: Test took 19348ms.
[10:33:00.688] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:00.689] <TB1> INFO: dacScan step from 80 .. 83
[10:33:21.711] <TB1> INFO: Test took 21022ms.
[10:33:21.787] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:21.790] <TB1> INFO: dacScan step from 84 .. 87
[10:33:43.897] <TB1> INFO: Test took 22107ms.
[10:33:44.036] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:44.041] <TB1> INFO: dacScan step from 88 .. 91
[10:34:07.619] <TB1> INFO: Test took 23578ms.
[10:34:07.788] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:07.794] <TB1> INFO: dacScan step from 92 .. 95
[10:34:33.377] <TB1> INFO: Test took 25583ms.
[10:34:33.550] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:33.560] <TB1> INFO: dacScan step from 96 .. 99
[10:35:00.823] <TB1> INFO: Test took 27263ms.
[10:35:01.018] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:01.031] <TB1> INFO: dacScan step from 100 .. 103
[10:35:29.039] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:35:29.039] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:35:29.377] <TB1> INFO: Test took 28346ms.
[10:35:29.590] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:29.599] <TB1> INFO: dacScan step from 104 .. 107
[10:35:57.304] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[10:35:57.304] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[10:35:57.304] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:35:58.246] <TB1> INFO: Test took 28646ms.
[10:35:58.579] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:58.592] <TB1> INFO: dacScan step from 108 .. 111
[10:36:26.132] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[10:36:26.132] <TB1> WARNING: ROC 0: Readback start marker after 32 readouts!

[10:36:26.132] <TB1> WARNING: ROC 2: Readback start marker after 31 readouts!

[10:36:26.132] <TB1> WARNING: ROC 3: Readback start marker after 31 readouts!

[10:36:27.328] <TB1> INFO: Test took 28736ms.
[10:36:27.589] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:27.600] <TB1> INFO: dacScan step from 112 .. 115
[10:36:57.052] <TB1> INFO: Test took 29452ms.
[10:36:57.294] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:36:57.305] <TB1> INFO: dacScan step from 116 .. 119
[10:37:25.440] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:37:25.440] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:37:26.686] <TB1> INFO: Test took 29381ms.
[10:37:26.921] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:26.932] <TB1> INFO: dacScan step from 120 .. 123
[10:37:55.263] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:37:55.263] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:37:56.559] <TB1> INFO: Test took 29627ms.
[10:37:56.778] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:37:56.792] <TB1> INFO: dacScan step from 124 .. 127
[10:38:24.760] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (200) != TBM ID (0)

[10:38:24.761] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:38:24.761] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (1) != TBM ID (201)

[10:38:24.761] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:38:26.121] <TB1> INFO: Test took 29328ms.
[10:38:26.343] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:26.354] <TB1> INFO: dacScan step from 128 .. 131
[10:38:54.023] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:38:54.023] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:38:55.293] <TB1> INFO: Test took 28939ms.
[10:38:55.593] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:38:55.605] <TB1> INFO: dacScan step from 132 .. 135
[10:39:24.728] <TB1> INFO: Test took 29123ms.
[10:39:24.950] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:24.961] <TB1> INFO: dacScan step from 136 .. 139
[10:39:53.976] <TB1> INFO: Test took 29015ms.
[10:39:54.210] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:39:54.221] <TB1> INFO: dacScan step from 140 .. 143
[10:40:23.354] <TB1> INFO: Test took 29133ms.
[10:40:23.600] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:23.613] <TB1> INFO: dacScan step from 144 .. 147
[10:40:52.372] <TB1> INFO: Test took 28759ms.
[10:40:52.608] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:40:52.618] <TB1> INFO: dacScan step from 148 .. 149
[10:41:08.188] <TB1> INFO: Test took 15570ms.
[10:41:08.297] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:08.304] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:09.849] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:11.268] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:12.969] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:14.632] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:16.195] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:17.796] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:19.269] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:20.723] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:22.384] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:23.969] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:25.464] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:26.823] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:28.179] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:29.549] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:30.932] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[10:41:32.335] <TB1> INFO: PixTestScurves::scurves() done
[10:41:32.335] <TB1> INFO: Vcal mean: 106.16 89.14 94.49 111.24 82.20 96.10 91.43 97.41 90.33 98.85 97.15 88.07 93.43 88.19 83.99 100.50
[10:41:32.335] <TB1> INFO: Vcal RMS: 6.12 5.51 5.35 5.46 5.11 6.24 6.01 6.36 5.51 5.63 5.81 5.12 6.00 5.86 4.81 5.98
[10:41:32.335] <TB1> INFO: PixTestScurves::fullTest() done, duration: 886 seconds
[10:41:32.406] <TB1> INFO: ######################################################################
[10:41:32.406] <TB1> INFO: PixTestTrim::doTest()
[10:41:32.406] <TB1> INFO: ######################################################################
[10:41:32.408] <TB1> INFO: ----------------------------------------------------------------------
[10:41:32.408] <TB1> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[10:41:32.408] <TB1> INFO: ----------------------------------------------------------------------
[10:41:32.497] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[10:41:32.497] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[10:41:32.505] <TB1> INFO: dacScan step from 0 .. 19
[10:41:47.396] <TB1> INFO: Test took 14891ms.
[10:41:47.417] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:41:47.417] <TB1> INFO: dacScan step from 20 .. 39
[10:42:02.445] <TB1> INFO: Test took 15028ms.
[10:42:02.469] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:02.469] <TB1> INFO: dacScan step from 40 .. 59
[10:42:17.335] <TB1> INFO: Test took 14866ms.
[10:42:17.356] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:17.356] <TB1> INFO: dacScan step from 60 .. 79
[10:42:32.446] <TB1> INFO: Test took 15089ms.
[10:42:32.468] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:32.468] <TB1> INFO: dacScan step from 80 .. 99
[10:42:47.756] <TB1> INFO: Test took 15288ms.
[10:42:47.796] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:42:47.800] <TB1> INFO: dacScan step from 100 .. 119
[10:43:05.258] <TB1> INFO: Test took 17458ms.
[10:43:05.397] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:05.423] <TB1> INFO: dacScan step from 120 .. 139
[10:43:24.385] <TB1> INFO: Test took 18962ms.
[10:43:24.542] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:43:24.570] <TB1> INFO: dacScan step from 140 .. 159
[10:43:41.394] <TB1> INFO: Test took 16824ms.
[10:43:41.465] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:05.602] <TB1> INFO: ROC 0 VthrComp = 102
[10:44:05.603] <TB1> INFO: ROC 1 VthrComp = 93
[10:44:05.603] <TB1> INFO: ROC 2 VthrComp = 96
[10:44:05.603] <TB1> INFO: ROC 3 VthrComp = 105
[10:44:05.603] <TB1> INFO: ROC 4 VthrComp = 83
[10:44:05.603] <TB1> INFO: ROC 5 VthrComp = 94
[10:44:05.603] <TB1> INFO: ROC 6 VthrComp = 89
[10:44:05.603] <TB1> INFO: ROC 7 VthrComp = 98
[10:44:05.603] <TB1> INFO: ROC 8 VthrComp = 95
[10:44:05.604] <TB1> INFO: ROC 9 VthrComp = 100
[10:44:05.604] <TB1> INFO: ROC 10 VthrComp = 98
[10:44:05.604] <TB1> INFO: ROC 11 VthrComp = 90
[10:44:05.605] <TB1> INFO: ROC 12 VthrComp = 91
[10:44:05.605] <TB1> INFO: ROC 13 VthrComp = 92
[10:44:05.605] <TB1> INFO: ROC 14 VthrComp = 89
[10:44:05.605] <TB1> INFO: ROC 15 VthrComp = 100
[10:44:05.606] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[10:44:05.606] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[10:44:05.618] <TB1> INFO: dacScan step from 0 .. 19
[10:44:20.683] <TB1> INFO: Test took 15065ms.
[10:44:20.710] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:20.710] <TB1> INFO: dacScan step from 20 .. 39
[10:44:35.942] <TB1> INFO: Test took 15232ms.
[10:44:35.972] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:35.975] <TB1> INFO: dacScan step from 40 .. 59
[10:44:54.544] <TB1> INFO: Test took 18569ms.
[10:44:54.695] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:44:54.728] <TB1> INFO: dacScan step from 60 .. 79
[10:45:15.050] <TB1> INFO: Test took 20322ms.
[10:45:15.223] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:15.286] <TB1> INFO: dacScan step from 80 .. 99
[10:45:35.672] <TB1> INFO: Test took 20386ms.
[10:45:35.860] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:35.918] <TB1> INFO: dacScan step from 100 .. 119
[10:45:55.116] <TB1> INFO: Test took 19198ms.
[10:45:55.295] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:55.342] <TB1> INFO: dacScan step from 120 .. 139
[10:46:15.960] <TB1> INFO: Test took 20618ms.
[10:46:16.211] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:16.263] <TB1> INFO: dacScan step from 140 .. 159
[10:46:37.231] <TB1> INFO: Test took 20968ms.
[10:46:37.391] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:02.652] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 65.9436 for pixel 1/1 mean/min/max = 49.1747/32.3517/65.9977
[10:47:02.652] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 59.0748 for pixel 51/66 mean/min/max = 45.4588/31.7939/59.1238
[10:47:02.652] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 59.9583 for pixel 0/11 mean/min/max = 46.1188/32.2193/60.0183
[10:47:02.652] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 65.1653 for pixel 20/71 mean/min/max = 49.5163/33.7448/65.2879
[10:47:02.653] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 59.8322 for pixel 10/4 mean/min/max = 46.136/32.2503/60.0217
[10:47:02.653] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 63.1156 for pixel 3/0 mean/min/max = 47.5887/32.0304/63.147
[10:47:02.653] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 62.8414 for pixel 0/7 mean/min/max = 47.841/32.7338/62.9482
[10:47:02.653] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 62.1678 for pixel 20/77 mean/min/max = 47.0261/31.8457/62.2066
[10:47:02.654] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 59.1768 for pixel 21/76 mean/min/max = 45.2482/31.2976/59.1989
[10:47:02.654] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 60.562 for pixel 51/79 mean/min/max = 46.3109/31.9928/60.6291
[10:47:02.654] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 61.316 for pixel 51/74 mean/min/max = 46.6515/31.613/61.6901
[10:47:02.654] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 59.3936 for pixel 23/0 mean/min/max = 45.9966/32.58/59.4133
[10:47:02.655] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 64.6487 for pixel 20/44 mean/min/max = 49.2272/33.7957/64.6587
[10:47:02.655] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 59.9164 for pixel 0/64 mean/min/max = 46.1373/32.2105/60.064
[10:47:02.655] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 57.2452 for pixel 0/73 mean/min/max = 45.1297/33.005/57.2544
[10:47:02.655] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 61.8308 for pixel 30/76 mean/min/max = 46.7169/31.5619/61.8718
[10:47:02.655] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:48:38.022] <TB1> INFO: Test took 95367ms.
[10:48:39.454] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[10:48:39.462] <TB1> INFO: dacScan step from 0 .. 19
[10:49:02.670] <TB1> INFO: Test took 23208ms.
[10:49:02.722] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:02.724] <TB1> INFO: dacScan step from 20 .. 39
[10:49:32.012] <TB1> INFO: Test took 29288ms.
[10:49:32.233] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:49:32.261] <TB1> INFO: dacScan step from 40 .. 59
[10:50:05.249] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (8) != Token Chain Length (4)

[10:50:05.249] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (155) != TBM ID (156)

[10:50:05.249] <TB1> WARNING: ROC 0: Readback start marker after 15 readouts!

[10:50:05.249] <TB1> WARNING: ROC 1: Readback start marker after 15 readouts!

[10:50:05.249] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[10:50:05.249] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:50:06.531] <TB1> INFO: Test took 34270ms.
[10:50:06.813] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:06.856] <TB1> INFO: dacScan step from 60 .. 79
[10:50:40.656] <TB1> INFO: Test took 33800ms.
[10:50:40.934] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:41.004] <TB1> INFO: dacScan step from 80 .. 99
[10:51:13.441] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:51:13.441] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:51:14.688] <TB1> INFO: Test took 33684ms.
[10:51:15.014] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:15.061] <TB1> INFO: dacScan step from 100 .. 119
[10:51:45.344] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (209) != TBM ID (0)

[10:51:45.344] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:51:45.344] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (1) != TBM ID (210)

[10:51:45.344] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:51:46.445] <TB1> INFO: Test took 31384ms.
[10:51:46.712] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:46.763] <TB1> INFO: dacScan step from 120 .. 139
[10:52:19.138] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[10:52:19.138] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[10:52:19.138] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:52:20.415] <TB1> INFO: Test took 33652ms.
[10:52:20.701] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:20.749] <TB1> INFO: dacScan step from 140 .. 159
[10:52:52.673] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (210) != TBM ID (0)

[10:52:52.673] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:52:52.673] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (1) != TBM ID (211)

[10:52:52.673] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:52:53.981] <TB1> INFO: Test took 33232ms.
[10:52:54.398] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:54.456] <TB1> INFO: dacScan step from 160 .. 179
[10:53:27.970] <TB1> INFO: Test took 33514ms.
[10:53:28.269] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:28.332] <TB1> INFO: dacScan step from 180 .. 199
[10:54:01.338] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:54:01.338] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:54:02.607] <TB1> INFO: Test took 34275ms.
[10:54:02.875] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:29.777] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.002767 .. 255.000000
[10:54:29.858] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[10:54:29.866] <TB1> INFO: dacScan step from 0 .. 19
[10:54:43.543] <TB1> INFO: Test took 13676ms.
[10:54:43.567] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:43.567] <TB1> INFO: dacScan step from 20 .. 39
[10:54:58.432] <TB1> INFO: Test took 14865ms.
[10:54:58.519] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:54:58.537] <TB1> INFO: dacScan step from 40 .. 59
[10:55:16.396] <TB1> INFO: Test took 17859ms.
[10:55:16.552] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:16.606] <TB1> INFO: dacScan step from 60 .. 79
[10:55:34.221] <TB1> INFO: Test took 17615ms.
[10:55:34.402] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:34.468] <TB1> INFO: dacScan step from 80 .. 99
[10:55:52.433] <TB1> INFO: Test took 17966ms.
[10:55:52.649] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:55:52.706] <TB1> INFO: dacScan step from 100 .. 119
[10:56:10.450] <TB1> INFO: Test took 17744ms.
[10:56:10.627] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:56:10.677] <TB1> INFO: dacScan step from 120 .. 139
[10:56:28.426] <TB1> INFO: Test took 17749ms.
[10:56:28.577] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:56:28.625] <TB1> INFO: dacScan step from 140 .. 159
[10:56:46.675] <TB1> INFO: Test took 18050ms.
[10:56:46.819] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:56:46.877] <TB1> INFO: dacScan step from 160 .. 179
[10:57:05.109] <TB1> INFO: Test took 18232ms.
[10:57:05.272] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:57:05.325] <TB1> INFO: dacScan step from 180 .. 199
[10:57:24.204] <TB1> INFO: Test took 18879ms.
[10:57:24.345] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:57:24.396] <TB1> INFO: dacScan step from 200 .. 219
[10:57:42.396] <TB1> INFO: Test took 18000ms.
[10:57:42.572] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:57:42.626] <TB1> INFO: dacScan step from 220 .. 239
[10:58:00.525] <TB1> INFO: Test took 17898ms.
[10:58:00.688] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:58:00.741] <TB1> INFO: dacScan step from 240 .. 255
[10:58:15.334] <TB1> INFO: Test took 14593ms.
[10:58:15.446] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:58:48.704] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 1.792665 .. 57.125605
[10:58:48.785] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 1 .. 67 (20) hits flags = 16 (plus default)
[10:58:48.793] <TB1> INFO: dacScan step from 1 .. 20
[10:59:02.430] <TB1> INFO: Test took 13637ms.
[10:59:02.456] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:02.456] <TB1> INFO: dacScan step from 21 .. 40
[10:59:17.750] <TB1> INFO: Test took 15294ms.
[10:59:17.844] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:17.863] <TB1> INFO: dacScan step from 41 .. 60
[10:59:35.987] <TB1> INFO: Test took 18124ms.
[10:59:36.179] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:36.226] <TB1> INFO: dacScan step from 61 .. 67
[10:59:44.025] <TB1> INFO: Test took 7799ms.
[10:59:44.075] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:01.967] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 18.954319 .. 57.125605
[11:00:02.071] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 8 .. 67 (20) hits flags = 16 (plus default)
[11:00:02.079] <TB1> INFO: dacScan step from 8 .. 27
[11:00:15.841] <TB1> INFO: Test took 13762ms.
[11:00:15.866] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:15.866] <TB1> INFO: dacScan step from 28 .. 47
[11:00:32.561] <TB1> INFO: Test took 16695ms.
[11:00:32.707] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:00:32.743] <TB1> INFO: dacScan step from 48 .. 67
[11:00:50.753] <TB1> INFO: Test took 18010ms.
[11:00:50.900] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:08.262] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 1.904543 .. 57.125605
[11:01:08.343] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 67 (20) hits flags = 16 (plus default)
[11:01:08.351] <TB1> INFO: dacScan step from 1 .. 20
[11:01:21.964] <TB1> INFO: Test took 13613ms.
[11:01:21.999] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:21.999] <TB1> INFO: dacScan step from 21 .. 40
[11:01:37.135] <TB1> INFO: Test took 15136ms.
[11:01:37.215] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:37.233] <TB1> INFO: dacScan step from 41 .. 60
[11:01:55.330] <TB1> INFO: Test took 18097ms.
[11:01:55.487] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:55.545] <TB1> INFO: dacScan step from 61 .. 67
[11:02:03.719] <TB1> INFO: Test took 8174ms.
[11:02:03.794] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:21.081] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[11:02:21.081] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[11:02:21.090] <TB1> INFO: dacScan step from 15 .. 34
[11:02:44.743] <TB1> INFO: Test took 23653ms.
[11:02:44.814] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:02:44.824] <TB1> INFO: dacScan step from 35 .. 54
[11:03:17.427] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (237) != TBM ID (0)

[11:03:17.427] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[11:03:17.427] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (1) != TBM ID (238)

[11:03:17.427] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:03:18.087] <TB1> INFO: Test took 33263ms.
[11:03:18.509] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:18.567] <TB1> INFO: dacScan step from 55 .. 55
[11:03:23.047] <TB1> INFO: Test took 4480ms.
[11:03:23.071] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:03:38.814] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C0.dat
[11:03:38.814] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C1.dat
[11:03:38.814] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C2.dat
[11:03:38.814] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C3.dat
[11:03:38.814] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C4.dat
[11:03:38.814] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C5.dat
[11:03:38.814] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C6.dat
[11:03:38.815] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C7.dat
[11:03:38.815] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C8.dat
[11:03:38.815] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C9.dat
[11:03:38.815] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C10.dat
[11:03:38.815] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C11.dat
[11:03:38.815] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C12.dat
[11:03:38.815] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C13.dat
[11:03:38.816] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C14.dat
[11:03:38.816] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C15.dat
[11:03:38.816] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C0.dat
[11:03:38.824] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C1.dat
[11:03:38.830] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C2.dat
[11:03:38.836] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C3.dat
[11:03:38.842] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C4.dat
[11:03:38.848] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C5.dat
[11:03:38.854] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C6.dat
[11:03:38.859] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C7.dat
[11:03:38.865] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C8.dat
[11:03:38.871] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C9.dat
[11:03:38.877] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C10.dat
[11:03:38.883] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C11.dat
[11:03:38.888] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C12.dat
[11:03:38.894] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C13.dat
[11:03:38.900] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C14.dat
[11:03:38.906] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//trimParameters35_C15.dat
[11:03:38.912] <TB1> INFO: PixTestTrim::trimTest() done
[11:03:38.912] <TB1> INFO: vtrim: 79 115 110 129 106 117 106 186 99 83 112 99 145 114 103 119
[11:03:38.912] <TB1> INFO: vthrcomp: 102 93 96 105 83 94 89 98 95 100 98 90 91 92 89 100
[11:03:38.912] <TB1> INFO: vcal mean: 34.91 35.00 35.02 35.03 35.02 35.12 35.04 34.99 35.09 35.06 35.04 35.06 35.06 35.03 34.99 35.03
[11:03:38.912] <TB1> INFO: vcal RMS: 1.72 1.01 1.02 1.27 1.04 1.18 1.41 4.04 1.03 1.08 1.01 0.97 1.06 0.99 0.95 1.09
[11:03:38.912] <TB1> INFO: bits mean: 5.72 9.94 9.43 9.20 9.96 9.83 9.29 11.56 9.77 8.17 9.42 9.00 8.98 9.61 9.68 9.73
[11:03:38.912] <TB1> INFO: bits RMS: 3.42 2.50 2.67 2.37 2.45 2.42 2.56 1.66 2.67 3.19 2.69 2.72 2.31 2.54 2.48 2.58
[11:03:38.917] <TB1> INFO: ----------------------------------------------------------------------
[11:03:38.917] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 240 150 100
[11:03:38.917] <TB1> INFO: ----------------------------------------------------------------------
[11:03:38.921] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[11:03:38.931] <TB1> INFO: dacScan step from 0 .. 19
[11:04:01.764] <TB1> INFO: Test took 22833ms.
[11:04:01.799] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:01.799] <TB1> INFO: dacScan step from 20 .. 39
[11:04:23.640] <TB1> INFO: Test took 21841ms.
[11:04:23.690] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:23.693] <TB1> INFO: dacScan step from 40 .. 59
[11:04:52.767] <TB1> INFO: Test took 29074ms.
[11:04:53.102] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:04:53.146] <TB1> INFO: dacScan step from 60 .. 79
[11:05:25.838] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (216) != TBM ID (0)

[11:05:25.838] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[11:05:25.838] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (1) != TBM ID (217)

[11:05:25.838] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:05:27.121] <TB1> INFO: Test took 33975ms.
[11:05:27.394] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:05:27.442] <TB1> INFO: dacScan step from 80 .. 99
[11:06:00.164] <TB1> INFO: Test took 32722ms.
[11:06:00.427] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:06:00.482] <TB1> INFO: dacScan step from 100 .. 119
[11:06:32.551] <TB1> INFO: Test took 32069ms.
[11:06:32.920] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:06:32.983] <TB1> INFO: dacScan step from 120 .. 139
[11:07:06.642] <TB1> INFO: Test took 33659ms.
[11:07:06.901] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:07:06.947] <TB1> INFO: dacScan step from 140 .. 159
[11:07:37.722] <TB1> INFO: Test took 30775ms.
[11:07:37.982] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:07:38.029] <TB1> INFO: dacScan step from 160 .. 179
[11:08:12.141] <TB1> INFO: Test took 34112ms.
[11:08:12.398] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:12.444] <TB1> INFO: dacScan step from 180 .. 199
[11:08:46.331] <TB1> INFO: Test took 33887ms.
[11:08:46.691] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:10.854] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 82 (20) hits flags = 16 (plus default)
[11:09:10.862] <TB1> INFO: dacScan step from 0 .. 19
[11:09:33.877] <TB1> INFO: Test took 23015ms.
[11:09:33.916] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:33.916] <TB1> INFO: dacScan step from 20 .. 39
[11:09:57.801] <TB1> INFO: Test took 23885ms.
[11:09:57.885] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:09:57.893] <TB1> INFO: dacScan step from 40 .. 59
[11:10:28.382] <TB1> INFO: Test took 30489ms.
[11:10:28.640] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:10:28.677] <TB1> INFO: dacScan step from 60 .. 79
[11:11:00.884] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[11:11:00.884] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[11:11:00.884] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:11:02.264] <TB1> INFO: Test took 33587ms.
[11:11:02.541] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:11:02.586] <TB1> INFO: dacScan step from 80 .. 82
[11:11:10.122] <TB1> INFO: Test took 7536ms.
[11:11:10.168] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:11:26.656] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 78 (20) hits flags = 16 (plus default)
[11:11:26.663] <TB1> INFO: dacScan step from 0 .. 19
[11:11:49.902] <TB1> INFO: Test took 23238ms.
[11:11:49.946] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:11:49.946] <TB1> INFO: dacScan step from 20 .. 39
[11:12:15.676] <TB1> INFO: Test took 25730ms.
[11:12:15.853] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:12:15.868] <TB1> INFO: dacScan step from 40 .. 59
[11:12:48.720] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[11:12:48.720] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:12:49.502] <TB1> INFO: Test took 33634ms.
[11:12:49.935] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:12:49.993] <TB1> INFO: dacScan step from 60 .. 78
[11:13:21.722] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[11:13:21.722] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[11:13:21.723] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:13:21.943] <TB1> INFO: Test took 31950ms.
[11:13:22.207] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:13:37.612] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 72 (20) hits flags = 16 (plus default)
[11:13:37.620] <TB1> INFO: dacScan step from 0 .. 19
[11:14:00.914] <TB1> INFO: Test took 23294ms.
[11:14:00.954] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:14:00.955] <TB1> INFO: dacScan step from 20 .. 39
[11:14:27.497] <TB1> INFO: Test took 26542ms.
[11:14:27.694] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:14:27.712] <TB1> INFO: dacScan step from 40 .. 59
[11:15:01.346] <TB1> INFO: Test took 33634ms.
[11:15:01.631] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:15:01.673] <TB1> INFO: dacScan step from 60 .. 72
[11:15:24.660] <TB1> INFO: Test took 22987ms.
[11:15:24.866] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:15:39.846] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[11:15:39.853] <TB1> INFO: dacScan step from 0 .. 19
[11:16:03.223] <TB1> INFO: Test took 23370ms.
[11:16:03.266] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:03.268] <TB1> INFO: dacScan step from 20 .. 39
[11:16:29.371] <TB1> INFO: Test took 26103ms.
[11:16:29.595] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:16:29.620] <TB1> INFO: dacScan step from 40 .. 59
[11:17:02.433] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[11:17:02.433] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[11:17:02.433] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:17:03.735] <TB1> INFO: Test took 34115ms.
[11:17:04.103] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:04.141] <TB1> INFO: dacScan step from 60 .. 79
[11:17:36.988] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (195) != TBM ID (0)

[11:17:36.988] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[11:17:36.988] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (1) != TBM ID (196)

[11:17:36.988] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:17:38.350] <TB1> INFO: Test took 34209ms.
[11:17:38.817] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:17:38.874] <TB1> INFO: dacScan step from 80 .. 99
[11:18:12.054] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[11:18:12.055] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[11:18:12.055] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:18:13.431] <TB1> INFO: Test took 34557ms.
[11:18:13.726] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:13.769] <TB1> INFO: dacScan step from 100 .. 119
[11:18:46.345] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[11:18:46.345] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[11:18:46.345] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:18:47.695] <TB1> INFO: Test took 33926ms.
[11:18:48.096] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:18:48.148] <TB1> INFO: dacScan step from 120 .. 139
[11:19:22.213] <TB1> INFO: Test took 34064ms.
[11:19:22.531] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:19:22.583] <TB1> INFO: dacScan step from 140 .. 159
[11:19:56.962] <TB1> INFO: Test took 34379ms.
[11:19:57.258] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:19:57.302] <TB1> INFO: dacScan step from 160 .. 179
[11:20:29.723] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (8) != Token Chain Length (4)

[11:20:29.723] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (196) != TBM ID (197)

[11:20:29.723] <TB1> WARNING: ROC 0: Readback start marker after 15 readouts!

[11:20:29.723] <TB1> WARNING: ROC 1: Readback start marker after 15 readouts!

[11:20:29.723] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[11:20:29.723] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:20:31.035] <TB1> INFO: Test took 33733ms.
[11:20:31.298] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:31.343] <TB1> INFO: dacScan step from 180 .. 199
[11:21:05.140] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[11:21:05.140] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[11:21:05.140] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:21:06.403] <TB1> INFO: Test took 35060ms.
[11:21:06.662] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:06.704] <TB1> INFO: dacScan step from 200 .. 219
[11:21:38.862] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (8) != Token Chain Length (4)

[11:21:38.862] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (197) != TBM ID (198)

[11:21:38.862] <TB1> WARNING: ROC 0: Readback start marker after 15 readouts!

[11:21:38.862] <TB1> WARNING: ROC 1: Readback start marker after 15 readouts!

[11:21:38.862] <TB1> WARNING: ROC 2: Readback start marker after 15 readouts!

[11:21:38.862] <TB1> WARNING: ROC 3: Readback start marker after 15 readouts!

[11:21:39.991] <TB1> INFO: Test took 33287ms.
[11:21:40.252] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:40.299] <TB1> INFO: dacScan step from 220 .. 239
[11:22:13.574] <TB1> INFO: Test took 33275ms.
[11:22:13.839] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:22:13.884] <TB1> INFO: dacScan step from 240 .. 255
[11:22:41.462] <TB1> INFO: Test took 27577ms.
[11:22:41.688] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:07.343] <TB1> INFO: PixTestTrim::trimBitTest() done
[11:23:07.345] <TB1> INFO: PixTestTrim::doTest() done, duration: 2494 seconds
[11:23:08.050] <TB1> INFO: ######################################################################
[11:23:08.050] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[11:23:08.050] <TB1> INFO: ######################################################################
[11:23:11.581] <TB1> INFO: Test took 3530ms.
[11:23:11.611] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:15.310] <TB1> INFO: Test took 3498ms.
[11:23:15.420] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:18.899] <TB1> INFO: Test took 3462ms.
[11:23:18.971] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:18.979] <TB1> INFO: The DUT currently contains the following objects:
[11:23:18.979] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:18.979] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:18.979] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:18.979] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:18.979] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:18.979] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.089] <TB1> INFO: Test took 1110ms.
[11:23:20.091] <TB1> INFO: The DUT currently contains the following objects:
[11:23:20.091] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:20.091] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:20.091] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:20.091] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:20.091] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:20.091] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.205] <TB1> INFO: Test took 1114ms.
[11:23:21.207] <TB1> INFO: The DUT currently contains the following objects:
[11:23:21.207] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:21.207] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:21.207] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:21.207] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:21.207] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.207] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.208] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:21.208] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.320] <TB1> INFO: Test took 1112ms.
[11:23:22.322] <TB1> INFO: The DUT currently contains the following objects:
[11:23:22.322] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:22.322] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:22.322] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:22.322] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:22.322] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.322] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.322] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.322] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.322] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.322] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.322] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.322] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.323] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.323] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.323] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.323] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.323] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.323] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.323] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:22.323] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.451] <TB1> INFO: Test took 1128ms.
[11:23:23.453] <TB1> INFO: The DUT currently contains the following objects:
[11:23:23.453] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:23.453] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:23.453] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:23.453] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:23.453] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.453] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.453] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.453] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.453] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.453] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:23.454] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.563] <TB1> INFO: Test took 1109ms.
[11:23:24.565] <TB1> INFO: The DUT currently contains the following objects:
[11:23:24.568] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:24.568] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:24.568] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:24.568] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:24.568] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:24.568] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.675] <TB1> INFO: Test took 1107ms.
[11:23:25.676] <TB1> INFO: The DUT currently contains the following objects:
[11:23:25.676] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:25.676] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:25.676] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:25.676] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:25.676] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.676] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.676] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:25.677] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.786] <TB1> INFO: Test took 1109ms.
[11:23:26.787] <TB1> INFO: The DUT currently contains the following objects:
[11:23:26.787] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:26.787] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:26.788] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:26.788] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:26.788] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:26.788] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.899] <TB1> INFO: Test took 1111ms.
[11:23:27.900] <TB1> INFO: The DUT currently contains the following objects:
[11:23:27.900] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:27.900] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:27.900] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:27.900] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:27.900] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.900] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.901] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.901] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.901] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.901] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:27.901] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.010] <TB1> INFO: Test took 1109ms.
[11:23:29.011] <TB1> INFO: The DUT currently contains the following objects:
[11:23:29.011] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:29.011] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:29.011] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:29.011] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:29.011] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.011] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.011] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.011] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.011] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.011] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.011] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.011] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.012] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.012] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.012] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.012] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.012] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.012] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.012] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:29.012] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.119] <TB1> INFO: Test took 1107ms.
[11:23:30.120] <TB1> INFO: The DUT currently contains the following objects:
[11:23:30.120] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:30.120] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:30.120] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:30.120] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:30.120] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:30.120] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.230] <TB1> INFO: Test took 1110ms.
[11:23:31.231] <TB1> INFO: The DUT currently contains the following objects:
[11:23:31.231] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:31.231] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:31.231] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:31.231] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:31.231] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:31.231] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.346] <TB1> INFO: Test took 1115ms.
[11:23:32.348] <TB1> INFO: The DUT currently contains the following objects:
[11:23:32.348] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:32.348] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:32.348] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:32.348] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:32.348] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.348] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.349] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:32.349] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.464] <TB1> INFO: Test took 1115ms.
[11:23:33.466] <TB1> INFO: The DUT currently contains the following objects:
[11:23:33.466] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:33.466] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:33.466] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:33.466] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:33.466] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.466] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.467] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:33.467] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.580] <TB1> INFO: Test took 1113ms.
[11:23:34.581] <TB1> INFO: The DUT currently contains the following objects:
[11:23:34.581] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:34.582] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:34.582] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:34.582] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:34.582] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:34.582] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.692] <TB1> INFO: Test took 1110ms.
[11:23:35.693] <TB1> INFO: The DUT currently contains the following objects:
[11:23:35.693] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:23:35.693] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:23:35.693] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:23:35.693] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[11:23:35.693] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.693] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.693] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.693] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.693] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.693] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.693] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.693] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.694] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.694] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.694] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.694] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.694] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.694] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.694] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:35.694] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[11:23:36.805] <TB1> INFO: Test took 1111ms.
[11:23:36.811] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:27:28.987] <TB1> INFO: Test took 232176ms.
[11:27:30.598] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:22.260] <TB1> INFO: Test took 231662ms.
[11:31:23.843] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.849] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.856] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.862] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.869] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.875] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.883] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.890] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.897] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.903] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.910] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.916] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.923] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.930] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.936] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.943] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:31:23.949] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[11:31:23.956] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[11:31:24.011] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C0.dat
[11:31:24.032] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C1.dat
[11:31:24.032] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C2.dat
[11:31:24.033] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C3.dat
[11:31:24.033] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C4.dat
[11:31:24.033] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C5.dat
[11:31:24.033] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C6.dat
[11:31:24.033] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C7.dat
[11:31:24.034] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C8.dat
[11:31:24.034] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C9.dat
[11:31:24.034] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C10.dat
[11:31:24.034] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C11.dat
[11:31:24.034] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C12.dat
[11:31:24.035] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C13.dat
[11:31:24.035] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C14.dat
[11:31:24.035] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//dacParameters35_C15.dat
[11:31:27.462] <TB1> INFO: Test took 3421ms.
[11:31:31.307] <TB1> INFO: Test took 3565ms.
[11:31:35.192] <TB1> INFO: Test took 3559ms.
[11:31:35.482] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:36.408] <TB1> INFO: Test took 926ms.
[11:31:36.412] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:37.540] <TB1> INFO: Test took 1128ms.
[11:31:37.545] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:38.659] <TB1> INFO: Test took 1114ms.
[11:31:38.663] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:39.777] <TB1> INFO: Test took 1114ms.
[11:31:39.782] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:40.896] <TB1> INFO: Test took 1114ms.
[11:31:40.901] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:42.012] <TB1> INFO: Test took 1111ms.
[11:31:42.017] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:43.146] <TB1> INFO: Test took 1130ms.
[11:31:43.151] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:44.263] <TB1> INFO: Test took 1114ms.
[11:31:44.268] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:45.397] <TB1> INFO: Test took 1129ms.
[11:31:45.402] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:46.513] <TB1> INFO: Test took 1112ms.
[11:31:46.517] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:47.631] <TB1> INFO: Test took 1114ms.
[11:31:47.636] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:48.746] <TB1> INFO: Test took 1111ms.
[11:31:48.750] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:49.862] <TB1> INFO: Test took 1112ms.
[11:31:49.867] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:50.981] <TB1> INFO: Test took 1114ms.
[11:31:50.986] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:52.096] <TB1> INFO: Test took 1110ms.
[11:31:52.100] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:53.209] <TB1> INFO: Test took 1110ms.
[11:31:53.213] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:54.323] <TB1> INFO: Test took 1110ms.
[11:31:54.326] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:55.435] <TB1> INFO: Test took 1109ms.
[11:31:55.439] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:56.548] <TB1> INFO: Test took 1109ms.
[11:31:56.552] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:57.662] <TB1> INFO: Test took 1110ms.
[11:31:57.666] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:58.775] <TB1> INFO: Test took 1109ms.
[11:31:58.779] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:59.889] <TB1> INFO: Test took 1110ms.
[11:31:59.893] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:01.007] <TB1> INFO: Test took 1114ms.
[11:32:01.011] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:02.120] <TB1> INFO: Test took 1109ms.
[11:32:02.125] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:03.250] <TB1> INFO: Test took 1125ms.
[11:32:03.254] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:04.365] <TB1> INFO: Test took 1111ms.
[11:32:04.369] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:05.478] <TB1> INFO: Test took 1109ms.
[11:32:05.482] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:06.591] <TB1> INFO: Test took 1109ms.
[11:32:06.595] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:07.700] <TB1> INFO: Test took 1105ms.
[11:32:07.703] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:08.811] <TB1> INFO: Test took 1109ms.
[11:32:08.815] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:09.924] <TB1> INFO: Test took 1109ms.
[11:32:09.928] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:32:11.037] <TB1> INFO: Test took 1109ms.
[11:32:11.625] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 543 seconds
[11:32:11.625] <TB1> INFO: PH scale (per ROC): 73 81 85 77 79 80 71 73 84 67 86 79 76 80 86 80
[11:32:11.625] <TB1> INFO: PH offset (per ROC): 178 160 141 159 154 154 162 157 155 153 155 159 156 149 149 169
[11:32:11.797] <TB1> INFO: ######################################################################
[11:32:11.797] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[11:32:11.797] <TB1> INFO: ######################################################################
[11:32:11.807] <TB1> INFO: scanning low vcal = 50
[11:32:16.186] <TB1> INFO: Test took 4379ms.
[11:32:16.243] <TB1> INFO: scanning low vcal = 100
[11:32:20.681] <TB1> INFO: Test took 4438ms.
[11:32:20.758] <TB1> INFO: scanning low vcal = 150
[11:32:25.237] <TB1> INFO: Test took 4479ms.
[11:32:25.300] <TB1> INFO: scanning low vcal = 200
[11:32:29.822] <TB1> INFO: Test took 4522ms.
[11:32:29.897] <TB1> INFO: scanning low vcal = 250
[11:32:34.324] <TB1> INFO: Test took 4427ms.
[11:32:34.388] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[11:32:38.764] <TB1> INFO: Test took 4376ms.
[11:32:38.825] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[11:32:43.243] <TB1> INFO: Test took 4418ms.
[11:32:43.304] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[11:32:47.671] <TB1> INFO: Test took 4367ms.
[11:32:47.732] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[11:32:52.172] <TB1> INFO: Test took 4440ms.
[11:32:52.277] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[11:32:56.714] <TB1> INFO: Test took 4437ms.
[11:32:57.094] <TB1> INFO: PixTestGainPedestal::measure() done
[11:33:22.153] <TB1> INFO: PixTestGainPedestal::fit() done
[11:33:22.153] <TB1> INFO: non-linearity mean: 0.958 0.947 0.951 0.963 0.948 0.961 0.955 0.953 0.958 0.949 0.950 0.951 0.966 0.957 0.951 0.955
[11:33:22.153] <TB1> INFO: non-linearity RMS: 0.006 0.007 0.006 0.006 0.006 0.005 0.010 0.006 0.005 0.007 0.007 0.007 0.005 0.005 0.006 0.007
[11:33:22.153] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[11:33:22.174] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[11:33:22.192] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[11:33:22.210] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[11:33:22.228] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[11:33:22.247] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[11:33:22.265] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[11:33:22.284] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[11:33:22.302] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[11:33:22.321] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[11:33:22.339] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[11:33:22.357] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[11:33:22.375] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[11:33:22.393] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[11:33:22.411] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[11:33:22.429] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2035_FullQualification_2015-07-10_12h10m_1436523044//000_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[11:33:22.448] <TB1> INFO: PixTestGainPedestal::doTest() done, duration: 70 seconds
[11:33:22.454] <TB1> INFO: enter test to run
[11:33:22.454] <TB1> INFO: test: exit no parameter change
[11:33:22.948] <TB1> QUIET: Connection to board 153 closed.
[11:33:23.028] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master