Test Date: 2015-08-18 11:20
Analysis date: 2016-05-25 21:13
Logfile
LogfileView
[12:09:49.013] <TB1> INFO: *** Welcome to pxar ***
[12:09:49.013] <TB1> INFO: *** Today: 2015/08/18
[12:09:49.013] <TB1> INFO: readRocDacs: /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C15.dat
[12:09:49.015] <TB1> INFO: readTbmDacs: /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//tbmParameters_C0b.dat
[12:09:49.015] <TB1> INFO: readMaskFile: /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//defaultMaskFile.dat
[12:09:49.015] <TB1> INFO: readTrimFile: /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters_C15.dat
[12:09:49.099] <TB1> INFO: clk: 4
[12:09:49.099] <TB1> INFO: ctr: 4
[12:09:49.099] <TB1> INFO: sda: 19
[12:09:49.099] <TB1> INFO: tin: 9
[12:09:49.099] <TB1> INFO: level: 15
[12:09:49.099] <TB1> INFO: triggerdelay: 0
[12:09:49.099] <TB1> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[12:09:49.099] <TB1> INFO: Log level: INFO
[12:09:49.107] <TB1> INFO: Found DTB DTB_WXBYFL
[12:09:49.120] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[12:09:49.123] <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:
------------------------------------------------------
[12:09:49.126] <TB1> INFO: RPC call hashes of host and DTB match: 447413373
[12:09:50.655] <TB1> INFO: DUT info:
[12:09:50.655] <TB1> INFO: The DUT currently contains the following objects:
[12:09:50.655] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:09:50.655] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:09:50.655] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:09:50.655] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:09:50.655] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.655] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.655] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.655] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.655] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.655] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.655] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.656] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.656] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.656] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.656] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.656] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.656] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.656] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.656] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:50.656] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:09:51.057] <TB1> INFO: enter 'restricted' command line mode
[12:09:51.057] <TB1> INFO: enter test to run
[12:09:51.057] <TB1> INFO: test: pretest no parameter change
[12:09:51.057] <TB1> INFO: running: pretest
[12:09:51.064] <TB1> INFO: ######################################################################
[12:09:51.064] <TB1> INFO: PixTestPretest::doTest()
[12:09:51.064] <TB1> INFO: ######################################################################
[12:09:51.066] <TB1> INFO: ----------------------------------------------------------------------
[12:09:51.066] <TB1> INFO: PixTestPretest::programROC()
[12:09:51.066] <TB1> INFO: ----------------------------------------------------------------------
[12:10:09.087] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[12:10:09.087] <TB1> INFO: IA differences per ROC: 19.3 16.1 16.9 16.1 15.3 19.3 20.1 18.5 17.7 20.1 18.5 19.3 19.3 20.9 19.3 19.3
[12:10:09.171] <TB1> INFO: ----------------------------------------------------------------------
[12:10:09.171] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[12:10:09.171] <TB1> INFO: ----------------------------------------------------------------------
[12:10:13.764] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 376.2 mA = 23.5125 mA/ROC
[12:10:13.768] <TB1> INFO: ----------------------------------------------------------------------
[12:10:13.768] <TB1> INFO: PixTestPretest::findWorkingPixel()
[12:10:13.768] <TB1> INFO: ----------------------------------------------------------------------
[12:10:22.119] <TB1> INFO: Test took 8344ms.
[12:10:22.432] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[12:10:22.483] <TB1> INFO: ----------------------------------------------------------------------
[12:10:22.483] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[12:10:22.484] <TB1> INFO: ----------------------------------------------------------------------
[12:10:30.793] <TB1> INFO: Test took 8301ms.
[12:10:31.116] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[12:10:31.116] <TB1> INFO: CalDel: 164 143 143 150 138 143 134 161 127 143 126 138 152 146 129 122
[12:10:31.116] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 55
[12:10:31.121] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C0.dat
[12:10:31.121] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C1.dat
[12:10:31.121] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C2.dat
[12:10:31.121] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C3.dat
[12:10:31.122] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C4.dat
[12:10:31.122] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C5.dat
[12:10:31.122] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C6.dat
[12:10:31.122] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C7.dat
[12:10:31.122] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C8.dat
[12:10:31.123] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C9.dat
[12:10:31.123] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C10.dat
[12:10:31.123] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C11.dat
[12:10:31.123] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C12.dat
[12:10:31.123] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C13.dat
[12:10:31.124] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C14.dat
[12:10:31.124] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C15.dat
[12:10:31.124] <TB1> INFO: PixTestPretest::doTest() done, duration: 40 seconds
[12:10:31.236] <TB1> INFO: enter test to run
[12:10:31.236] <TB1> INFO: test: fulltest no parameter change
[12:10:31.236] <TB1> INFO: running: fulltest
[12:10:31.236] <TB1> INFO: ######################################################################
[12:10:31.236] <TB1> INFO: PixTestFullTest::doTest()
[12:10:31.236] <TB1> INFO: ######################################################################
[12:10:31.237] <TB1> INFO: ######################################################################
[12:10:31.237] <TB1> INFO: PixTestAlive::doTest()
[12:10:31.237] <TB1> INFO: ######################################################################
[12:10:31.239] <TB1> INFO: ----------------------------------------------------------------------
[12:10:31.239] <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)
[12:10:31.239] <TB1> INFO: ----------------------------------------------------------------------
[12:10:34.680] <TB1> INFO: Test took 3439ms.
[12:10:34.707] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:34.947] <TB1> INFO: PixTestAlive::aliveTest() done
[12:10:34.947] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:10:34.949] <TB1> INFO: ----------------------------------------------------------------------
[12:10:34.949] <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)
[12:10:34.949] <TB1> INFO: ----------------------------------------------------------------------
[12:10:37.695] <TB1> INFO: Test took 2742ms.
[12:10:37.698] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:37.699] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[12:10:37.941] <TB1> INFO: PixTestAlive::maskTest() done
[12:10:37.941] <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
[12:10:37.943] <TB1> INFO: ----------------------------------------------------------------------
[12:10:37.943] <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)
[12:10:37.943] <TB1> INFO: ----------------------------------------------------------------------
[12:10:41.372] <TB1> INFO: Test took 3427ms.
[12:10:41.394] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:41.639] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[12:10:41.639] <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
[12:10:41.639] <TB1> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[12:10:41.649] <TB1> INFO: ######################################################################
[12:10:41.649] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[12:10:41.649] <TB1> INFO: ######################################################################
[12:10:41.654] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[12:10:41.665] <TB1> INFO: dacScan step from 0 .. 29
[12:11:03.684] <TB1> INFO: Test took 22018ms.
[12:11:03.744] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:03.749] <TB1> INFO: dacScan step from 30 .. 59
[12:11:29.293] <TB1> INFO: Test took 25544ms.
[12:11:29.465] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:29.492] <TB1> INFO: dacScan step from 60 .. 89
[12:11:58.637] <TB1> INFO: Test took 29145ms.
[12:11:58.881] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:58.959] <TB1> INFO: dacScan step from 90 .. 119
[12:12:28.089] <TB1> INFO: Test took 29130ms.
[12:12:28.366] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:28.448] <TB1> INFO: dacScan step from 120 .. 149
[12:12:53.517] <TB1> INFO: Test took 25069ms.
[12:12:53.695] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:16.617] <TB1> INFO: PixTestBBMap::doTest() done, duration: 154 seconds
[12:13:16.617] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 3 0 0 2 31 5 4 0 0 1 1 0 4
[12:13:16.617] <TB1> INFO: separation cut (per ROC): 120 82 96 62 107 102 77 72 74 76 75 182 82 110 156 96
[12:13:16.703] <TB1> INFO: ######################################################################
[12:13:16.703] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50
[12:13:16.703] <TB1> INFO: ######################################################################
[12:13:16.703] <TB1> INFO: ----------------------------------------------------------------------
[12:13:16.703] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[12:13:16.703] <TB1> INFO: ----------------------------------------------------------------------
[12:13:16.704] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[12:13:16.715] <TB1> INFO: dacScan step from 0 .. 3
[12:13:34.533] <TB1> INFO: Test took 17818ms.
[12:13:34.567] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:34.567] <TB1> INFO: dacScan step from 4 .. 7
[12:13:53.812] <TB1> INFO: Test took 19245ms.
[12:13:53.841] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:53.841] <TB1> INFO: dacScan step from 8 .. 11
[12:14:13.036] <TB1> INFO: Test took 19195ms.
[12:14:13.069] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:13.069] <TB1> INFO: dacScan step from 12 .. 15
[12:14:32.240] <TB1> INFO: Test took 19171ms.
[12:14:32.273] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:32.273] <TB1> INFO: dacScan step from 16 .. 19
[12:14:51.473] <TB1> INFO: Test took 19200ms.
[12:14:51.502] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:51.503] <TB1> INFO: dacScan step from 20 .. 23
[12:15:10.581] <TB1> INFO: Test took 19078ms.
[12:15:10.609] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:10.609] <TB1> INFO: dacScan step from 24 .. 27
[12:15:29.650] <TB1> INFO: Test took 19041ms.
[12:15:29.678] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:29.678] <TB1> INFO: dacScan step from 28 .. 31
[12:15:48.747] <TB1> INFO: Test took 19069ms.
[12:15:48.772] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:48.774] <TB1> INFO: dacScan step from 32 .. 35
[12:16:07.822] <TB1> INFO: Test took 19048ms.
[12:16:07.849] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:07.849] <TB1> INFO: dacScan step from 36 .. 39
[12:16:27.065] <TB1> INFO: Test took 19216ms.
[12:16:27.087] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:27.092] <TB1> INFO: dacScan step from 40 .. 43
[12:16:46.169] <TB1> INFO: Test took 19077ms.
[12:16:46.198] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:46.198] <TB1> INFO: dacScan step from 44 .. 47
[12:17:05.312] <TB1> INFO: Test took 19114ms.
[12:17:05.338] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:05.338] <TB1> INFO: dacScan step from 48 .. 51
[12:17:24.510] <TB1> INFO: Test took 19172ms.
[12:17:24.538] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:24.538] <TB1> INFO: dacScan step from 52 .. 55
[12:17:43.704] <TB1> INFO: Test took 19166ms.
[12:17:43.731] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:43.731] <TB1> INFO: dacScan step from 56 .. 59
[12:18:02.792] <TB1> INFO: Test took 19061ms.
[12:18:02.820] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:02.821] <TB1> INFO: dacScan step from 60 .. 63
[12:18:20.604] <TB1> INFO: Test took 17783ms.
[12:18:20.637] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:20.637] <TB1> INFO: dacScan step from 64 .. 67
[12:18:38.616] <TB1> INFO: Test took 17979ms.
[12:18:38.657] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:38.662] <TB1> INFO: dacScan step from 68 .. 71
[12:18:57.592] <TB1> INFO: Test took 18930ms.
[12:18:57.675] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:57.677] <TB1> INFO: dacScan step from 72 .. 75
[12:19:16.999] <TB1> INFO: Test took 19322ms.
[12:19:17.076] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:17.079] <TB1> INFO: dacScan step from 76 .. 79
[12:19:38.120] <TB1> INFO: Test took 21041ms.
[12:19:38.228] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:38.234] <TB1> INFO: dacScan step from 80 .. 83
[12:20:02.964] <TB1> INFO: Test took 24730ms.
[12:20:03.136] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:03.144] <TB1> INFO: dacScan step from 84 .. 87
[12:20:29.384] <TB1> INFO: Test took 26240ms.
[12:20:29.579] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:29.588] <TB1> INFO: dacScan step from 88 .. 91
[12:20:56.834] <TB1> INFO: Test took 27246ms.
[12:20:57.039] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:57.046] <TB1> INFO: dacScan step from 92 .. 95
[12:21:25.315] <TB1> INFO: Test took 28268ms.
[12:21:25.533] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:25.543] <TB1> INFO: dacScan step from 96 .. 99
[12:21:54.290] <TB1> INFO: Test took 28747ms.
[12:21:54.506] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:54.517] <TB1> INFO: dacScan step from 100 .. 103
[12:22:23.134] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:22:23.134] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:22:23.719] <TB1> INFO: Test took 29202ms.
[12:22:23.947] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:23.958] <TB1> INFO: dacScan step from 104 .. 107
[12:22:52.351] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[12:22:53.281] <TB1> INFO: Test took 29323ms.
[12:22:53.515] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:53.526] <TB1> INFO: dacScan step from 108 .. 111
[12:23:22.838] <TB1> INFO: Test took 29312ms.
[12:23:23.066] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:23.078] <TB1> INFO: dacScan step from 112 .. 115
[12:23:52.594] <TB1> INFO: Test took 29517ms.
[12:23:52.824] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:52.835] <TB1> INFO: dacScan step from 116 .. 119
[12:24:21.004] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:24:21.005] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (140) != TBM ID (141)

[12:24:21.005] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[12:24:21.005] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[12:24:21.005] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:24:22.281] <TB1> INFO: Test took 29446ms.
[12:24:22.521] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:22.534] <TB1> INFO: dacScan step from 120 .. 123
[12:24:50.890] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:24:50.890] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:24:52.236] <TB1> INFO: Test took 29702ms.
[12:24:52.473] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:52.485] <TB1> INFO: dacScan step from 124 .. 127
[12:25:20.663] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (204) != TBM ID (0)

[12:25:20.663] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[12:25:20.663] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (205)

[12:25:21.929] <TB1> INFO: Test took 29444ms.
[12:25:22.168] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:22.180] <TB1> INFO: dacScan step from 128 .. 131
[12:25:50.429] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:25:50.429] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:25:51.689] <TB1> INFO: Test took 29509ms.
[12:25:51.932] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:51.945] <TB1> INFO: dacScan step from 132 .. 135
[12:26:21.373] <TB1> INFO: Test took 29428ms.
[12:26:21.622] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:21.635] <TB1> INFO: dacScan step from 136 .. 139
[12:26:51.115] <TB1> INFO: Test took 29480ms.
[12:26:51.353] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:51.365] <TB1> INFO: dacScan step from 140 .. 143
[12:27:20.743] <TB1> INFO: Test took 29378ms.
[12:27:21.002] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:21.015] <TB1> INFO: dacScan step from 144 .. 147
[12:27:50.458] <TB1> INFO: Test took 29443ms.
[12:27:50.689] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:50.702] <TB1> INFO: dacScan step from 148 .. 149
[12:28:06.677] <TB1> INFO: Test took 15975ms.
[12:28:06.798] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:06.805] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:08.286] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:09.790] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:11.314] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:12.897] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:14.376] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:15.885] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:17.424] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:18.851] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:20.346] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:21.775] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:23.245] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:24.704] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:26.145] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:27.580] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:28.975] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:28:30.388] <TB1> INFO: PixTestScurves::scurves() done
[12:28:30.388] <TB1> INFO: Vcal mean: 83.50 90.55 72.67 69.72 92.37 78.04 76.86 81.75 84.18 79.41 86.81 98.95 89.46 78.89 84.96 102.90
[12:28:30.388] <TB1> INFO: Vcal RMS: 5.00 6.08 4.54 4.96 6.45 4.35 4.52 4.60 5.61 4.73 5.42 6.38 6.24 4.35 5.41 6.27
[12:28:30.388] <TB1> INFO: PixTestScurves::fullTest() done, duration: 913 seconds
[12:28:30.465] <TB1> INFO: ######################################################################
[12:28:30.465] <TB1> INFO: PixTestTrim::doTest()
[12:28:30.465] <TB1> INFO: ######################################################################
[12:28:30.467] <TB1> INFO: ----------------------------------------------------------------------
[12:28:30.467] <TB1> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[12:28:30.467] <TB1> INFO: ----------------------------------------------------------------------
[12:28:30.548] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:28:30.548] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[12:28:30.556] <TB1> INFO: dacScan step from 0 .. 19
[12:28:45.675] <TB1> INFO: Test took 15118ms.
[12:28:45.702] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:45.702] <TB1> INFO: dacScan step from 20 .. 39
[12:29:00.878] <TB1> INFO: Test took 15175ms.
[12:29:00.901] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:00.902] <TB1> INFO: dacScan step from 40 .. 59
[12:29:16.052] <TB1> INFO: Test took 15150ms.
[12:29:16.080] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:16.080] <TB1> INFO: dacScan step from 60 .. 79
[12:29:31.309] <TB1> INFO: Test took 15229ms.
[12:29:31.335] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:31.335] <TB1> INFO: dacScan step from 80 .. 99
[12:29:47.819] <TB1> INFO: Test took 16484ms.
[12:29:47.899] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:47.910] <TB1> INFO: dacScan step from 100 .. 119
[12:30:06.146] <TB1> INFO: Test took 18235ms.
[12:30:06.316] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:06.354] <TB1> INFO: dacScan step from 120 .. 139
[12:30:23.488] <TB1> INFO: Test took 17134ms.
[12:30:23.626] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:23.650] <TB1> INFO: dacScan step from 140 .. 159
[12:30:39.528] <TB1> INFO: Test took 15878ms.
[12:30:39.589] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:01.672] <TB1> INFO: ROC 0 VthrComp = 89
[12:31:01.673] <TB1> INFO: ROC 1 VthrComp = 93
[12:31:01.673] <TB1> INFO: ROC 2 VthrComp = 77
[12:31:01.673] <TB1> INFO: ROC 3 VthrComp = 74
[12:31:01.673] <TB1> INFO: ROC 4 VthrComp = 88
[12:31:01.673] <TB1> INFO: ROC 5 VthrComp = 82
[12:31:01.673] <TB1> INFO: ROC 6 VthrComp = 83
[12:31:01.674] <TB1> INFO: ROC 7 VthrComp = 85
[12:31:01.674] <TB1> INFO: ROC 8 VthrComp = 86
[12:31:01.674] <TB1> INFO: ROC 9 VthrComp = 85
[12:31:01.674] <TB1> INFO: ROC 10 VthrComp = 86
[12:31:01.675] <TB1> INFO: ROC 11 VthrComp = 98
[12:31:01.675] <TB1> INFO: ROC 12 VthrComp = 93
[12:31:01.675] <TB1> INFO: ROC 13 VthrComp = 84
[12:31:01.675] <TB1> INFO: ROC 14 VthrComp = 87
[12:31:01.675] <TB1> INFO: ROC 15 VthrComp = 104
[12:31:01.676] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:31:01.676] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[12:31:01.686] <TB1> INFO: dacScan step from 0 .. 19
[12:31:16.819] <TB1> INFO: Test took 15133ms.
[12:31:16.844] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:16.844] <TB1> INFO: dacScan step from 20 .. 39
[12:31:32.038] <TB1> INFO: Test took 15194ms.
[12:31:32.071] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:32.074] <TB1> INFO: dacScan step from 40 .. 59
[12:31:50.830] <TB1> INFO: Test took 18756ms.
[12:31:50.992] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:51.029] <TB1> INFO: dacScan step from 60 .. 79
[12:32:11.292] <TB1> INFO: Test took 20263ms.
[12:32:11.459] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:11.508] <TB1> INFO: dacScan step from 80 .. 99
[12:32:30.846] <TB1> INFO: Test took 19338ms.
[12:32:30.996] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:31.046] <TB1> INFO: dacScan step from 100 .. 119
[12:32:50.072] <TB1> INFO: Test took 19025ms.
[12:32:50.227] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:50.279] <TB1> INFO: dacScan step from 120 .. 139
[12:33:10.589] <TB1> INFO: Test took 20310ms.
[12:33:10.765] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:10.815] <TB1> INFO: dacScan step from 140 .. 159
[12:33:31.125] <TB1> INFO: Test took 20309ms.
[12:33:31.323] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:55.826] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 59.0299 for pixel 6/16 mean/min/max = 45.818/32.5628/59.0733
[12:33:55.826] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 61.8387 for pixel 18/7 mean/min/max = 46.5478/31.1705/61.9251
[12:33:55.827] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 58.9746 for pixel 0/15 mean/min/max = 46.9761/34.9119/59.0403
[12:33:55.827] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 57.9912 for pixel 0/37 mean/min/max = 46.727/35.3769/58.0771
[12:33:55.827] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 64.9387 for pixel 23/79 mean/min/max = 48.793/32.2238/65.3621
[12:33:55.827] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 58.2332 for pixel 37/0 mean/min/max = 45.2966/32.3223/58.2709
[12:33:55.828] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 57.5534 for pixel 0/2 mean/min/max = 44.8442/32.1256/57.5628
[12:33:55.828] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 57.8131 for pixel 0/79 mean/min/max = 44.8807/31.8955/57.866
[12:33:55.828] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 61.1775 for pixel 5/79 mean/min/max = 46.184/31.0824/61.2856
[12:33:55.828] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 59.0341 for pixel 47/79 mean/min/max = 45.5845/32.1337/59.0353
[12:33:55.829] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 60.1942 for pixel 0/15 mean/min/max = 46.1124/32.028/60.1969
[12:33:55.829] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 64.8939 for pixel 7/79 mean/min/max = 47.8053/30.6509/64.9597
[12:33:55.829] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 61.7717 for pixel 24/79 mean/min/max = 46.8579/31.6939/62.0219
[12:33:55.830] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 57.6713 for pixel 28/5 mean/min/max = 44.9759/32.1723/57.7795
[12:33:55.830] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 60.5832 for pixel 38/4 mean/min/max = 45.9269/31.2103/60.6436
[12:33:55.830] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 65.5832 for pixel 0/13 mean/min/max = 49.1828/32.7642/65.6013
[12:33:55.830] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:35:30.717] <TB1> INFO: Test took 94887ms.
[12:35:32.252] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:35:32.261] <TB1> INFO: dacScan step from 0 .. 19
[12:35:53.699] <TB1> INFO: Test took 21438ms.
[12:35:53.758] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:53.760] <TB1> INFO: dacScan step from 20 .. 39
[12:36:22.376] <TB1> INFO: Test took 28616ms.
[12:36:22.620] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:22.653] <TB1> INFO: dacScan step from 40 .. 59
[12:36:54.928] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:36:54.928] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:36:56.162] <TB1> INFO: Test took 33508ms.
[12:36:56.430] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:56.482] <TB1> INFO: dacScan step from 60 .. 79
[12:37:29.983] <TB1> INFO: Test took 33501ms.
[12:37:30.285] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:30.335] <TB1> INFO: dacScan step from 80 .. 99
[12:38:02.301] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:38:02.301] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 31 readouts!

[12:38:02.301] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[12:38:03.562] <TB1> INFO: Test took 33227ms.
[12:38:03.867] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:03.921] <TB1> INFO: dacScan step from 100 .. 119
[12:38:35.935] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:38:35.935] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:38:37.117] <TB1> INFO: Test took 33196ms.
[12:38:37.386] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:37.445] <TB1> INFO: dacScan step from 120 .. 139
[12:39:09.463] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (234) != TBM ID (0)

[12:39:09.463] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[12:39:09.463] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (235)

[12:39:10.710] <TB1> INFO: Test took 33265ms.
[12:39:10.974] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:11.025] <TB1> INFO: dacScan step from 140 .. 159
[12:39:43.203] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:39:43.203] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (235) != TBM ID (236)

[12:39:43.203] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[12:39:43.203] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[12:39:43.203] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:39:44.474] <TB1> INFO: Test took 33449ms.
[12:39:44.753] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:44.803] <TB1> INFO: dacScan step from 160 .. 179
[12:40:17.058] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:40:17.059] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:40:18.383] <TB1> INFO: Test took 33580ms.
[12:40:18.652] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:18.706] <TB1> INFO: dacScan step from 180 .. 199
[12:40:51.698] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 32 readouts!

[12:40:53.014] <TB1> INFO: Test took 34308ms.
[12:40:53.308] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:19.915] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.007548 .. 255.000000
[12:41:19.995] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[12:41:20.004] <TB1> INFO: dacScan step from 0 .. 19
[12:41:33.610] <TB1> INFO: Test took 13606ms.
[12:41:33.639] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:33.639] <TB1> INFO: dacScan step from 20 .. 39
[12:41:48.540] <TB1> INFO: Test took 14901ms.
[12:41:48.628] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:48.643] <TB1> INFO: dacScan step from 40 .. 59
[12:42:06.494] <TB1> INFO: Test took 17851ms.
[12:42:06.654] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:06.704] <TB1> INFO: dacScan step from 60 .. 79
[12:42:24.522] <TB1> INFO: Test took 17818ms.
[12:42:24.686] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:24.741] <TB1> INFO: dacScan step from 80 .. 99
[12:42:42.638] <TB1> INFO: Test took 17896ms.
[12:42:42.777] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:42.829] <TB1> INFO: dacScan step from 100 .. 119
[12:43:00.545] <TB1> INFO: Test took 17716ms.
[12:43:00.704] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:00.758] <TB1> INFO: dacScan step from 120 .. 139
[12:43:18.617] <TB1> INFO: Test took 17859ms.
[12:43:18.772] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:18.824] <TB1> INFO: dacScan step from 140 .. 159
[12:43:35.630] <TB1> INFO: Test took 16806ms.
[12:43:35.775] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:35.832] <TB1> INFO: dacScan step from 160 .. 179
[12:43:52.558] <TB1> INFO: Test took 16725ms.
[12:43:52.697] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:52.752] <TB1> INFO: dacScan step from 180 .. 199
[12:44:11.367] <TB1> INFO: Test took 18615ms.
[12:44:11.514] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:11.584] <TB1> INFO: dacScan step from 200 .. 219
[12:44:29.380] <TB1> INFO: Test took 17796ms.
[12:44:29.527] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:29.577] <TB1> INFO: dacScan step from 220 .. 239
[12:44:47.338] <TB1> INFO: Test took 17761ms.
[12:44:47.491] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:47.544] <TB1> INFO: dacScan step from 240 .. 255
[12:45:02.293] <TB1> INFO: Test took 14749ms.
[12:45:02.420] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:41.545] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 15.895569 .. 46.653109
[12:45:41.988] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 5 .. 56 (20) hits flags = 16 (plus default)
[12:45:42.025] <TB1> INFO: dacScan step from 5 .. 24
[12:45:55.918] <TB1> INFO: Test took 13893ms.
[12:45:55.989] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:55.989] <TB1> INFO: dacScan step from 25 .. 44
[12:46:12.390] <TB1> INFO: Test took 16401ms.
[12:46:12.876] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:13.065] <TB1> INFO: dacScan step from 45 .. 56
[12:46:24.978] <TB1> INFO: Test took 11913ms.
[12:46:25.086] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:41.441] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 1.173922 .. 43.867329
[12:46:41.517] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 53 (20) hits flags = 16 (plus default)
[12:46:41.526] <TB1> INFO: dacScan step from 1 .. 20
[12:46:54.903] <TB1> INFO: Test took 13377ms.
[12:46:54.973] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:54.973] <TB1> INFO: dacScan step from 21 .. 40
[12:47:10.159] <TB1> INFO: Test took 15186ms.
[12:47:10.549] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:10.706] <TB1> INFO: dacScan step from 41 .. 53
[12:47:23.474] <TB1> INFO: Test took 12760ms.
[12:47:23.839] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:50.481] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 0.361685 .. 43.237123
[12:47:50.585] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 53 (20) hits flags = 16 (plus default)
[12:47:50.595] <TB1> INFO: dacScan step from 0 .. 19
[12:48:03.874] <TB1> INFO: Test took 13278ms.
[12:48:03.962] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:03.962] <TB1> INFO: dacScan step from 20 .. 39
[12:48:18.867] <TB1> INFO: Test took 14905ms.
[12:48:19.090] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:19.174] <TB1> INFO: dacScan step from 40 .. 53
[12:48:32.247] <TB1> INFO: Test took 13072ms.
[12:48:32.475] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:04.178] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:49:04.178] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[12:49:04.187] <TB1> INFO: dacScan step from 15 .. 34
[12:49:26.137] <TB1> INFO: Test took 21950ms.
[12:49:26.233] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:26.244] <TB1> INFO: dacScan step from 35 .. 54
[12:49:56.161] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[12:49:56.796] <TB1> INFO: Test took 30552ms.
[12:49:57.269] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:57.350] <TB1> INFO: dacScan step from 55 .. 55
[12:50:01.716] <TB1> INFO: Test took 4366ms.
[12:50:01.737] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:20.259] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:50:20.259] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:50:20.259] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:50:20.259] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:50:20.259] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:50:20.259] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:50:20.259] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:50:20.260] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:50:20.260] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:50:20.260] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:50:20.260] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:50:20.260] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:50:20.260] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:50:20.261] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:50:20.261] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:50:20.261] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:50:20.261] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C0.dat
[12:50:20.273] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C1.dat
[12:50:20.280] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C2.dat
[12:50:20.287] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C3.dat
[12:50:20.294] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C4.dat
[12:50:20.301] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C5.dat
[12:50:20.308] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C6.dat
[12:50:20.315] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C7.dat
[12:50:20.322] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C8.dat
[12:50:20.329] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C9.dat
[12:50:20.336] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C10.dat
[12:50:20.343] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C11.dat
[12:50:20.350] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C12.dat
[12:50:20.357] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C13.dat
[12:50:20.364] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C14.dat
[12:50:20.370] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C15.dat
[12:50:20.377] <TB1> INFO: PixTestTrim::trimTest() done
[12:50:20.377] <TB1> INFO: vtrim: 103 118 106 102 109 109 98 93 113 112 113 115 112 104 115 144
[12:50:20.377] <TB1> INFO: vthrcomp: 89 93 77 74 88 82 83 85 86 85 86 98 93 84 87 104
[12:50:20.377] <TB1> INFO: vcal mean: 35.02 35.04 35.08 35.06 35.08 35.04 35.02 35.04 35.06 35.07 35.05 35.06 35.02 35.03 35.00 35.15
[12:50:20.377] <TB1> INFO: vcal RMS: 0.94 1.18 0.94 0.96 1.15 0.97 1.08 1.02 1.09 0.98 1.07 1.06 1.06 0.99 1.02 1.07
[12:50:20.377] <TB1> INFO: bits mean: 9.60 9.68 8.96 8.74 8.99 9.58 9.68 9.68 10.19 9.97 9.75 9.69 9.37 9.89 9.58 8.99
[12:50:20.377] <TB1> INFO: bits RMS: 2.56 2.68 2.46 2.53 2.67 2.69 2.67 2.70 2.46 2.46 2.55 2.61 2.69 2.53 2.73 2.57
[12:50:20.387] <TB1> INFO: ----------------------------------------------------------------------
[12:50:20.387] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[12:50:20.387] <TB1> INFO: ----------------------------------------------------------------------
[12:50:20.392] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:50:20.401] <TB1> INFO: dacScan step from 0 .. 19
[12:50:42.725] <TB1> INFO: Test took 22324ms.
[12:50:42.768] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:42.768] <TB1> INFO: dacScan step from 20 .. 39
[12:51:04.136] <TB1> INFO: Test took 21367ms.
[12:51:04.174] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:04.174] <TB1> INFO: dacScan step from 40 .. 59
[12:51:27.048] <TB1> INFO: Test took 22873ms.
[12:51:27.088] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:27.088] <TB1> INFO: dacScan step from 60 .. 79
[12:51:49.903] <TB1> INFO: Test took 22815ms.
[12:51:49.939] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:49.939] <TB1> INFO: dacScan step from 80 .. 99
[12:52:13.050] <TB1> INFO: Test took 23111ms.
[12:52:13.133] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:13.141] <TB1> INFO: dacScan step from 100 .. 119
[12:52:41.838] <TB1> INFO: Test took 28697ms.
[12:52:42.068] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:42.095] <TB1> INFO: dacScan step from 120 .. 139
[12:53:13.983] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:53:13.983] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (144) != TBM ID (145)

[12:53:13.983] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[12:53:13.983] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[12:53:13.983] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:53:14.197] <TB1> INFO: Test took 32102ms.
[12:53:14.478] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:14.527] <TB1> INFO: dacScan step from 140 .. 159
[12:53:46.834] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (53) != TBM ID (0)

[12:53:46.834] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[12:53:46.834] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (54)

[12:53:48.111] <TB1> INFO: Test took 33583ms.
[12:53:48.415] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:48.473] <TB1> INFO: dacScan step from 160 .. 179
[12:54:20.693] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[12:54:21.970] <TB1> INFO: Test took 33497ms.
[12:54:22.283] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:22.339] <TB1> INFO: dacScan step from 180 .. 199
[12:54:56.602] <TB1> INFO: Test took 34263ms.
[12:54:56.868] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:23.071] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 182 (20) hits flags = 16 (plus default)
[12:55:23.080] <TB1> INFO: dacScan step from 0 .. 19
[12:55:45.941] <TB1> INFO: Test took 22861ms.
[12:55:45.978] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:45.978] <TB1> INFO: dacScan step from 20 .. 39
[12:56:08.731] <TB1> INFO: Test took 22753ms.
[12:56:08.768] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:08.768] <TB1> INFO: dacScan step from 40 .. 59
[12:56:31.644] <TB1> INFO: Test took 22876ms.
[12:56:31.682] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:31.682] <TB1> INFO: dacScan step from 60 .. 79
[12:56:54.643] <TB1> INFO: Test took 22961ms.
[12:56:54.684] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:54.684] <TB1> INFO: dacScan step from 80 .. 99
[12:57:20.174] <TB1> INFO: Test took 25490ms.
[12:57:20.373] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:20.396] <TB1> INFO: dacScan step from 100 .. 119
[12:57:49.710] <TB1> INFO: Test took 29314ms.
[12:57:49.959] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:49.994] <TB1> INFO: dacScan step from 120 .. 139
[12:58:22.432] <TB1> INFO: Test took 32438ms.
[12:58:22.696] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:22.756] <TB1> INFO: dacScan step from 140 .. 159
[12:58:54.663] <TB1> INFO: Test took 31907ms.
[12:58:54.964] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:55.017] <TB1> INFO: dacScan step from 160 .. 179
[12:59:27.039] <TB1> INFO: Test took 32022ms.
[12:59:27.325] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:27.376] <TB1> INFO: dacScan step from 180 .. 182
[12:59:34.772] <TB1> INFO: Test took 7395ms.
[12:59:34.823] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:03.337] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 170 (20) hits flags = 16 (plus default)
[13:00:03.345] <TB1> INFO: dacScan step from 0 .. 19
[13:00:26.083] <TB1> INFO: Test took 22738ms.
[13:00:26.123] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:26.124] <TB1> INFO: dacScan step from 20 .. 39
[13:00:48.848] <TB1> INFO: Test took 22724ms.
[13:00:48.891] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:48.891] <TB1> INFO: dacScan step from 40 .. 59
[13:01:11.594] <TB1> INFO: Test took 22703ms.
[13:01:11.727] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:11.727] <TB1> INFO: dacScan step from 60 .. 79
[13:01:34.819] <TB1> INFO: Test took 23092ms.
[13:01:34.868] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:34.869] <TB1> INFO: dacScan step from 80 .. 99
[13:01:59.578] <TB1> INFO: Test took 24709ms.
[13:01:59.736] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:59.750] <TB1> INFO: dacScan step from 100 .. 119
[13:02:30.292] <TB1> INFO: Test took 30542ms.
[13:02:31.320] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:31.514] <TB1> INFO: dacScan step from 120 .. 139
[13:03:03.334] <TB1> INFO: Test took 31820ms.
[13:03:04.646] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:04.967] <TB1> INFO: dacScan step from 140 .. 159
[13:03:37.518] <TB1> INFO: Test took 32552ms.
[13:03:37.807] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:37.861] <TB1> INFO: dacScan step from 160 .. 170
[13:03:56.586] <TB1> INFO: Test took 18725ms.
[13:03:57.500] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:40.090] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 170 (20) hits flags = 16 (plus default)
[13:04:40.099] <TB1> INFO: dacScan step from 0 .. 19
[13:05:02.684] <TB1> INFO: Test took 22584ms.
[13:05:02.727] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:02.727] <TB1> INFO: dacScan step from 20 .. 39
[13:05:25.240] <TB1> INFO: Test took 22513ms.
[13:05:25.292] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:25.292] <TB1> INFO: dacScan step from 40 .. 59
[13:05:47.464] <TB1> INFO: Test took 22171ms.
[13:05:47.503] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:47.503] <TB1> INFO: dacScan step from 60 .. 79
[13:06:09.747] <TB1> INFO: Test took 22244ms.
[13:06:09.787] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:09.787] <TB1> INFO: dacScan step from 80 .. 99
[13:06:34.868] <TB1> INFO: Test took 25081ms.
[13:06:35.015] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:35.030] <TB1> INFO: dacScan step from 100 .. 119
[13:07:03.852] <TB1> INFO: Test took 28821ms.
[13:07:04.141] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:04.181] <TB1> INFO: dacScan step from 120 .. 139
[13:07:34.993] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[13:07:36.177] <TB1> INFO: Test took 31996ms.
[13:07:36.474] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:36.527] <TB1> INFO: dacScan step from 140 .. 159
[13:08:08.760] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[13:08:08.760] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[13:08:10.016] <TB1> INFO: Test took 33489ms.
[13:08:10.307] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:10.359] <TB1> INFO: dacScan step from 160 .. 170
[13:08:30.018] <TB1> INFO: Test took 19659ms.
[13:08:30.204] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:57.709] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 170 (20) hits flags = 16 (plus default)
[13:08:57.719] <TB1> INFO: dacScan step from 0 .. 19
[13:09:20.674] <TB1> INFO: Test took 22955ms.
[13:09:20.710] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:20.710] <TB1> INFO: dacScan step from 20 .. 39
[13:09:43.605] <TB1> INFO: Test took 22895ms.
[13:09:43.649] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:43.649] <TB1> INFO: dacScan step from 40 .. 59
[13:10:06.455] <TB1> INFO: Test took 22806ms.
[13:10:06.498] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:06.499] <TB1> INFO: dacScan step from 60 .. 79
[13:10:27.939] <TB1> INFO: Test took 21440ms.
[13:10:27.977] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:27.977] <TB1> INFO: dacScan step from 80 .. 99
[13:10:54.019] <TB1> INFO: Test took 26042ms.
[13:10:54.184] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:54.214] <TB1> INFO: dacScan step from 100 .. 119
[13:11:25.538] <TB1> INFO: Test took 31324ms.
[13:11:25.814] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:25.853] <TB1> INFO: dacScan step from 120 .. 139
[13:11:56.360] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[13:11:57.520] <TB1> INFO: Test took 31667ms.
[13:11:57.852] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:11:57.904] <TB1> INFO: dacScan step from 140 .. 159
[13:12:30.128] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[13:12:31.415] <TB1> INFO: Test took 33511ms.
[13:12:31.714] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:12:31.769] <TB1> INFO: dacScan step from 160 .. 170
[13:12:51.388] <TB1> INFO: Test took 19619ms.
[13:12:51.558] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:18.895] <TB1> INFO: PixTestTrim::trimBitTest() done
[13:13:18.897] <TB1> INFO: PixTestTrim::doTest() done, duration: 2688 seconds
[13:13:19.663] <TB1> INFO: ######################################################################
[13:13:19.663] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[13:13:19.663] <TB1> INFO: ######################################################################
[13:13:23.116] <TB1> INFO: Test took 3451ms.
[13:13:23.139] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:26.818] <TB1> INFO: Test took 3480ms.
[13:13:26.888] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:30.371] <TB1> INFO: Test took 3468ms.
[13:13:30.441] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:13:30.448] <TB1> INFO: The DUT currently contains the following objects:
[13:13:30.448] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:30.448] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:30.448] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:30.448] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:30.448] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.448] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.448] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.448] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:30.449] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.561] <TB1> INFO: Test took 1113ms.
[13:13:31.563] <TB1> INFO: The DUT currently contains the following objects:
[13:13:31.563] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:31.563] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:31.563] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:31.563] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:31.563] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.563] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.563] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.563] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.563] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.563] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.563] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.563] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.564] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.564] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.564] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.564] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.564] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.564] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.564] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:31.564] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.674] <TB1> INFO: Test took 1110ms.
[13:13:32.675] <TB1> INFO: The DUT currently contains the following objects:
[13:13:32.675] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:32.675] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:32.675] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:32.675] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:32.675] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.675] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.675] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.675] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.675] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:32.676] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.786] <TB1> INFO: Test took 1111ms.
[13:13:33.788] <TB1> INFO: The DUT currently contains the following objects:
[13:13:33.788] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:33.788] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:33.788] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:33.788] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:33.788] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.788] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.789] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.789] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.789] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:33.789] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.899] <TB1> INFO: Test took 1110ms.
[13:13:34.900] <TB1> INFO: The DUT currently contains the following objects:
[13:13:34.900] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:34.900] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:34.900] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:34.900] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:34.900] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:34.901] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.013] <TB1> INFO: Test took 1112ms.
[13:13:36.014] <TB1> INFO: The DUT currently contains the following objects:
[13:13:36.014] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:36.015] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:36.015] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:36.015] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:36.015] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.015] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.016] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:36.016] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.126] <TB1> INFO: Test took 1110ms.
[13:13:37.128] <TB1> INFO: The DUT currently contains the following objects:
[13:13:37.128] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:37.128] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:37.128] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:37.128] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:37.128] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.128] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.129] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.129] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:37.129] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.234] <TB1> INFO: Test took 1105ms.
[13:13:38.235] <TB1> INFO: The DUT currently contains the following objects:
[13:13:38.235] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:38.235] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:38.235] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:38.235] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:38.235] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:38.235] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.340] <TB1> INFO: Test took 1105ms.
[13:13:39.341] <TB1> INFO: The DUT currently contains the following objects:
[13:13:39.341] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:39.341] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:39.341] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:39.341] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:39.341] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:39.342] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.455] <TB1> INFO: Test took 1113ms.
[13:13:40.456] <TB1> INFO: The DUT currently contains the following objects:
[13:13:40.457] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:40.457] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:40.457] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:40.457] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:40.457] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.457] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.458] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.458] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.458] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:40.458] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.567] <TB1> INFO: Test took 1109ms.
[13:13:41.569] <TB1> INFO: The DUT currently contains the following objects:
[13:13:41.569] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:41.569] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:41.569] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:41.569] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:41.569] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.569] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:41.570] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.680] <TB1> INFO: Test took 1110ms.
[13:13:42.681] <TB1> INFO: The DUT currently contains the following objects:
[13:13:42.681] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:42.681] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:42.681] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:42.681] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:42.681] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.681] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.681] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.681] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.681] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.681] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.681] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.682] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.682] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.682] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.682] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.682] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.682] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.682] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.682] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:42.682] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.795] <TB1> INFO: Test took 1113ms.
[13:13:43.796] <TB1> INFO: The DUT currently contains the following objects:
[13:13:43.796] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:43.796] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:43.796] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:43.796] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:43.796] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.796] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.796] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.796] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.796] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.796] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.796] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.796] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.796] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.797] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.797] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.797] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.797] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.797] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.797] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:43.797] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.907] <TB1> INFO: Test took 1110ms.
[13:13:44.908] <TB1> INFO: The DUT currently contains the following objects:
[13:13:44.908] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:44.909] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:44.909] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:44.909] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:44.909] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:44.909] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.022] <TB1> INFO: Test took 1112ms.
[13:13:46.024] <TB1> INFO: The DUT currently contains the following objects:
[13:13:46.024] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:46.024] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:46.024] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:46.024] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:46.024] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.024] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.024] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.024] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.024] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.024] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.024] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.024] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.024] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.025] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.025] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.025] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.025] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.025] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.025] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:46.025] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.136] <TB1> INFO: Test took 1111ms.
[13:13:47.137] <TB1> INFO: The DUT currently contains the following objects:
[13:13:47.137] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:13:47.137] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:13:47.137] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:13:47.137] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:13:47.137] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.137] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.138] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.138] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.138] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.138] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:47.138] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:13:48.250] <TB1> INFO: Test took 1112ms.
[13:13:48.256] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:32.498] <TB1> INFO: Test took 224242ms.
[13:17:34.153] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:13.506] <TB1> INFO: Test took 219353ms.
[13:21:15.345] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.353] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.362] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.371] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.379] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.387] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[13:21:15.395] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[13:21:15.403] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.410] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.417] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.424] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.430] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.439] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.447] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.456] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.464] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.472] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.480] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:21:15.550] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C0.dat
[13:21:15.551] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C1.dat
[13:21:15.553] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C2.dat
[13:21:15.553] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C3.dat
[13:21:15.557] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C4.dat
[13:21:15.557] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C5.dat
[13:21:15.557] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C6.dat
[13:21:15.558] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C7.dat
[13:21:15.560] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C8.dat
[13:21:15.560] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C9.dat
[13:21:15.568] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C10.dat
[13:21:15.568] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C11.dat
[13:21:15.568] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C12.dat
[13:21:15.569] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C13.dat
[13:21:15.594] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C14.dat
[13:21:15.594] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C15.dat
[13:21:19.033] <TB1> INFO: Test took 3434ms.
[13:21:22.749] <TB1> INFO: Test took 3397ms.
[13:21:26.348] <TB1> INFO: Test took 3302ms.
[13:21:26.643] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:27.560] <TB1> INFO: Test took 917ms.
[13:21:27.563] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:28.667] <TB1> INFO: Test took 1104ms.
[13:21:28.670] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:29.774] <TB1> INFO: Test took 1104ms.
[13:21:29.778] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:30.880] <TB1> INFO: Test took 1102ms.
[13:21:30.883] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:31.990] <TB1> INFO: Test took 1107ms.
[13:21:31.994] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:33.097] <TB1> INFO: Test took 1103ms.
[13:21:33.100] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:34.203] <TB1> INFO: Test took 1103ms.
[13:21:34.206] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:35.309] <TB1> INFO: Test took 1103ms.
[13:21:35.313] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:36.416] <TB1> INFO: Test took 1104ms.
[13:21:36.419] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:37.528] <TB1> INFO: Test took 1109ms.
[13:21:37.532] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:38.636] <TB1> INFO: Test took 1104ms.
[13:21:38.639] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:39.743] <TB1> INFO: Test took 1104ms.
[13:21:39.747] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:40.850] <TB1> INFO: Test took 1103ms.
[13:21:40.853] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:41.957] <TB1> INFO: Test took 1104ms.
[13:21:41.960] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:43.064] <TB1> INFO: Test took 1104ms.
[13:21:43.067] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:44.172] <TB1> INFO: Test took 1105ms.
[13:21:44.175] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:45.279] <TB1> INFO: Test took 1105ms.
[13:21:45.283] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:46.386] <TB1> INFO: Test took 1103ms.
[13:21:46.390] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:47.493] <TB1> INFO: Test took 1103ms.
[13:21:47.496] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:48.600] <TB1> INFO: Test took 1104ms.
[13:21:48.604] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:49.707] <TB1> INFO: Test took 1103ms.
[13:21:49.712] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:50.814] <TB1> INFO: Test took 1103ms.
[13:21:50.817] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:51.921] <TB1> INFO: Test took 1104ms.
[13:21:51.925] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:53.029] <TB1> INFO: Test took 1105ms.
[13:21:53.032] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:54.136] <TB1> INFO: Test took 1104ms.
[13:21:54.139] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:55.250] <TB1> INFO: Test took 1111ms.
[13:21:55.254] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:56.369] <TB1> INFO: Test took 1115ms.
[13:21:56.374] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:57.487] <TB1> INFO: Test took 1114ms.
[13:21:57.491] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:58.604] <TB1> INFO: Test took 1113ms.
[13:21:58.608] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:21:59.715] <TB1> INFO: Test took 1108ms.
[13:21:59.718] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:22:00.831] <TB1> INFO: Test took 1113ms.
[13:22:00.835] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:22:01.944] <TB1> INFO: Test took 1109ms.
[13:22:02.532] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 522 seconds
[13:22:02.532] <TB1> INFO: PH scale (per ROC): 80 84 82 89 80 81 80 86 87 83 84 75 84 82 70 74
[13:22:02.532] <TB1> INFO: PH offset (per ROC): 155 151 148 139 169 157 145 158 161 175 151 171 162 141 162 170
[13:22:02.723] <TB1> INFO: ######################################################################
[13:22:02.723] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[13:22:02.723] <TB1> INFO: ######################################################################
[13:22:02.734] <TB1> INFO: scanning low vcal = 10
[13:22:06.601] <TB1> INFO: Test took 3867ms.
[13:22:06.607] <TB1> INFO: scanning low vcal = 20
[13:22:10.457] <TB1> INFO: Test took 3850ms.
[13:22:10.464] <TB1> INFO: scanning low vcal = 30
[13:22:14.358] <TB1> INFO: Test took 3889ms.
[13:22:14.370] <TB1> INFO: scanning low vcal = 40
[13:22:18.746] <TB1> INFO: Test took 4376ms.
[13:22:18.810] <TB1> INFO: scanning low vcal = 50
[13:22:23.191] <TB1> INFO: Test took 4380ms.
[13:22:23.249] <TB1> INFO: scanning low vcal = 60
[13:22:27.647] <TB1> INFO: Test took 4398ms.
[13:22:27.728] <TB1> INFO: scanning low vcal = 70
[13:22:32.110] <TB1> INFO: Test took 4382ms.
[13:22:32.198] <TB1> INFO: scanning low vcal = 80
[13:22:36.604] <TB1> INFO: Test took 4406ms.
[13:22:36.690] <TB1> INFO: scanning low vcal = 90
[13:22:41.070] <TB1> INFO: Test took 4380ms.
[13:22:41.157] <TB1> INFO: scanning low vcal = 100
[13:22:45.532] <TB1> INFO: Test took 4375ms.
[13:22:45.596] <TB1> INFO: scanning low vcal = 110
[13:22:49.974] <TB1> INFO: Test took 4378ms.
[13:22:50.062] <TB1> INFO: scanning low vcal = 120
[13:22:54.451] <TB1> INFO: Test took 4389ms.
[13:22:54.519] <TB1> INFO: scanning low vcal = 130
[13:22:58.907] <TB1> INFO: Test took 4388ms.
[13:22:58.974] <TB1> INFO: scanning low vcal = 140
[13:23:03.382] <TB1> INFO: Test took 4408ms.
[13:23:03.445] <TB1> INFO: scanning low vcal = 150
[13:23:07.826] <TB1> INFO: Test took 4381ms.
[13:23:07.892] <TB1> INFO: scanning low vcal = 160
[13:23:12.294] <TB1> INFO: Test took 4402ms.
[13:23:12.365] <TB1> INFO: scanning low vcal = 170
[13:23:16.761] <TB1> INFO: Test took 4396ms.
[13:23:16.821] <TB1> INFO: scanning low vcal = 180
[13:23:21.198] <TB1> INFO: Test took 4377ms.
[13:23:21.258] <TB1> INFO: scanning low vcal = 190
[13:23:25.738] <TB1> INFO: Test took 4480ms.
[13:23:25.827] <TB1> INFO: scanning low vcal = 200
[13:23:30.230] <TB1> INFO: Test took 4403ms.
[13:23:30.289] <TB1> INFO: scanning low vcal = 210
[13:23:34.686] <TB1> INFO: Test took 4397ms.
[13:23:34.751] <TB1> INFO: scanning low vcal = 220
[13:23:39.130] <TB1> INFO: Test took 4379ms.
[13:23:39.210] <TB1> INFO: scanning low vcal = 230
[13:23:43.626] <TB1> INFO: Test took 4416ms.
[13:23:43.716] <TB1> INFO: scanning low vcal = 240
[13:23:48.149] <TB1> INFO: Test took 4433ms.
[13:23:48.232] <TB1> INFO: scanning low vcal = 250
[13:23:52.641] <TB1> INFO: Test took 4409ms.
[13:23:52.713] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[13:23:57.101] <TB1> INFO: Test took 4388ms.
[13:23:57.185] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[13:24:01.587] <TB1> INFO: Test took 4402ms.
[13:24:01.650] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[13:24:06.033] <TB1> INFO: Test took 4383ms.
[13:24:06.098] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[13:24:10.509] <TB1> INFO: Test took 4411ms.
[13:24:10.590] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[13:24:14.987] <TB1> INFO: Test took 4397ms.
[13:24:15.543] <TB1> INFO: PixTestGainPedestal::measure() done
[13:24:47.604] <TB1> INFO: PixTestGainPedestal::fit() done
[13:24:47.604] <TB1> INFO: non-linearity mean: 0.959 0.959 0.958 0.958 0.961 0.957 0.954 0.959 0.960 0.951 0.957 0.951 0.961 0.954 0.948 0.956
[13:24:47.604] <TB1> INFO: non-linearity RMS: 0.006 0.006 0.005 0.005 0.005 0.006 0.005 0.006 0.006 0.006 0.006 0.007 0.006 0.005 0.008 0.006
[13:24:47.604] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[13:24:47.624] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[13:24:47.645] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[13:24:47.667] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[13:24:47.688] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[13:24:47.709] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[13:24:47.730] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[13:24:47.751] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[13:24:47.772] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[13:24:47.793] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[13:24:47.815] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[13:24:47.836] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[13:24:47.857] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[13:24:47.878] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[13:24:47.899] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[13:24:47.920] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2028_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[13:24:47.941] <TB1> INFO: PixTestGainPedestal::doTest() done, duration: 165 seconds
[13:24:47.948] <TB1> INFO: enter test to run
[13:24:47.948] <TB1> INFO: test: exit no parameter change
[13:24:48.475] <TB1> QUIET: Connection to board 153 closed.
[13:24:48.555] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master