Test Date: 2015-07-08 10:58
Analysis date: 2016-05-25 22:23
Logfile
LogfileView
[09:13:07.610] <TB3> INFO: *** Welcome to pxar ***
[09:13:07.610] <TB3> INFO: *** Today: 2015/07/08
[09:13:07.610] <TB3> INFO: readRocDacs: /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C15.dat
[09:13:07.611] <TB3> INFO: readTbmDacs: /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//tbmParameters_C0b.dat
[09:13:07.611] <TB3> INFO: readMaskFile: /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//defaultMaskFile.dat
[09:13:07.611] <TB3> INFO: readTrimFile: /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters_C15.dat
[09:13:07.691] <TB3> INFO: clk: 4
[09:13:07.691] <TB3> INFO: ctr: 4
[09:13:07.691] <TB3> INFO: sda: 19
[09:13:07.691] <TB3> INFO: tin: 9
[09:13:07.691] <TB3> INFO: level: 15
[09:13:07.691] <TB3> INFO: triggerdelay: 0
[09:13:07.691] <TB3> QUIET: Instanciating API for pxar v2.2.5+45~gbf85984
[09:13:07.691] <TB3> INFO: Log level: INFO
[09:13:07.699] <TB3> INFO: Found DTB DTB_WZ4I6J
[09:13:07.707] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[09:13:07.710] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 170
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WZ4I6J
MAC address: 40D8551180AA
Hostname: pixelDTB170
Comment:
------------------------------------------------------
[09:13:07.713] <TB3> INFO: RPC call hashes of host and DTB match: 447413373
[09:13:09.281] <TB3> INFO: DUT info:
[09:13:09.281] <TB3> INFO: The DUT currently contains the following objects:
[09:13:09.281] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[09:13:09.282] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:13:09.282] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:13:09.282] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:13:09.282] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.282] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:13:09.683] <TB3> INFO: enter 'restricted' command line mode
[09:13:09.683] <TB3> INFO: enter test to run
[09:13:09.683] <TB3> INFO: test: pretest no parameter change
[09:13:09.683] <TB3> INFO: running: pretest
[09:13:09.690] <TB3> INFO: ######################################################################
[09:13:09.690] <TB3> INFO: PixTestPretest::doTest()
[09:13:09.690] <TB3> INFO: ######################################################################
[09:13:09.691] <TB3> INFO: ----------------------------------------------------------------------
[09:13:09.691] <TB3> INFO: PixTestPretest::programROC()
[09:13:09.691] <TB3> INFO: ----------------------------------------------------------------------
[09:13:27.709] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[09:13:27.709] <TB3> INFO: IA differences per ROC: 19.3 18.5 16.9 19.3 16.9 20.9 19.3 17.7 19.3 18.5 18.5 17.7 19.3 19.3 20.9 18.5
[09:13:27.771] <TB3> INFO: ----------------------------------------------------------------------
[09:13:27.772] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[09:13:27.772] <TB3> INFO: ----------------------------------------------------------------------
[09:13:47.328] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 379.4 mA = 23.7125 mA/ROC
[09:13:47.332] <TB3> INFO: ----------------------------------------------------------------------
[09:13:47.332] <TB3> INFO: PixTestPretest::findWorkingPixel()
[09:13:47.332] <TB3> INFO: ----------------------------------------------------------------------
[09:13:55.488] <TB3> INFO: Test took 8153ms.
[09:13:55.779] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[09:13:55.818] <TB3> INFO: ----------------------------------------------------------------------
[09:13:55.819] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[09:13:55.819] <TB3> INFO: ----------------------------------------------------------------------
[09:14:04.052] <TB3> INFO: Test took 8228ms.
[09:14:04.376] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[09:14:04.376] <TB3> INFO: CalDel: 142 127 144 156 144 162 126 136 139 136 134 131 148 137 139 140
[09:14:04.376] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[09:14:04.380] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C0.dat
[09:14:04.380] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C1.dat
[09:14:04.380] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C2.dat
[09:14:04.380] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C3.dat
[09:14:04.381] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C4.dat
[09:14:04.381] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C5.dat
[09:14:04.381] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C6.dat
[09:14:04.381] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C7.dat
[09:14:04.381] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C8.dat
[09:14:04.382] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C9.dat
[09:14:04.382] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C10.dat
[09:14:04.382] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C11.dat
[09:14:04.382] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C12.dat
[09:14:04.382] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C13.dat
[09:14:04.383] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C14.dat
[09:14:04.383] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters_C15.dat
[09:14:04.383] <TB3> INFO: PixTestPretest::doTest() done, duration: 54 seconds
[09:14:04.501] <TB3> INFO: enter test to run
[09:14:04.501] <TB3> INFO: test: fulltest no parameter change
[09:14:04.501] <TB3> INFO: running: fulltest
[09:14:04.501] <TB3> INFO: ######################################################################
[09:14:04.501] <TB3> INFO: PixTestFullTest::doTest()
[09:14:04.501] <TB3> INFO: ######################################################################
[09:14:04.503] <TB3> INFO: ######################################################################
[09:14:04.503] <TB3> INFO: PixTestAlive::doTest()
[09:14:04.503] <TB3> INFO: ######################################################################
[09:14:04.504] <TB3> INFO: ----------------------------------------------------------------------
[09:14:04.504] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:14:04.504] <TB3> INFO: ----------------------------------------------------------------------
[09:14:07.918] <TB3> INFO: Test took 3413ms.
[09:14:07.948] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:08.178] <TB3> INFO: PixTestAlive::aliveTest() done
[09:14:08.178] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:14:08.180] <TB3> INFO: ----------------------------------------------------------------------
[09:14:08.180] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:14:08.180] <TB3> INFO: ----------------------------------------------------------------------
[09:14:10.901] <TB3> INFO: Test took 2719ms.
[09:14:10.905] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:10.906] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[09:14:11.132] <TB3> INFO: PixTestAlive::maskTest() done
[09:14:11.132] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:14:11.134] <TB3> INFO: ----------------------------------------------------------------------
[09:14:11.134] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:14:11.134] <TB3> INFO: ----------------------------------------------------------------------
[09:14:14.602] <TB3> INFO: Test took 3466ms.
[09:14:14.630] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:14.862] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[09:14:14.862] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:14:14.862] <TB3> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[09:14:14.871] <TB3> INFO: ######################################################################
[09:14:14.871] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[09:14:14.871] <TB3> INFO: ######################################################################
[09:14:14.873] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[09:14:14.884] <TB3> INFO: dacScan step from 0 .. 29
[09:14:36.284] <TB3> INFO: Test took 21400ms.
[09:14:36.312] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:36.315] <TB3> INFO: dacScan step from 30 .. 59
[09:15:00.246] <TB3> INFO: Test took 23931ms.
[09:15:00.400] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:00.422] <TB3> INFO: dacScan step from 60 .. 89
[09:15:29.408] <TB3> INFO: Test took 28986ms.
[09:15:29.664] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:29.750] <TB3> INFO: dacScan step from 90 .. 119
[09:15:56.498] <TB3> INFO: Test took 26748ms.
[09:15:56.748] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:56.829] <TB3> INFO: dacScan step from 120 .. 149
[09:16:20.465] <TB3> INFO: Test took 23636ms.
[09:16:20.660] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:45.133] <TB3> INFO: PixTestBBMap::doTest() done, duration: 150 seconds
[09:16:45.133] <TB3> INFO: number of dead bumps (per ROC): 4 0 0 0 0 0 0 0 0 0 0 8 4 0 5 11
[09:16:45.133] <TB3> INFO: separation cut (per ROC): 91 73 69 74 75 81 88 74 78 70 89 81 88 87 90 82
[09:16:45.210] <TB3> INFO: ######################################################################
[09:16:45.210] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50
[09:16:45.210] <TB3> INFO: ######################################################################
[09:16:45.210] <TB3> INFO: ----------------------------------------------------------------------
[09:16:45.210] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[09:16:45.210] <TB3> INFO: ----------------------------------------------------------------------
[09:16:45.210] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[09:16:45.218] <TB3> INFO: dacScan step from 0 .. 3
[09:17:03.389] <TB3> INFO: Test took 18171ms.
[09:17:03.414] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:03.414] <TB3> INFO: dacScan step from 4 .. 7
[09:17:22.206] <TB3> INFO: Test took 18792ms.
[09:17:22.232] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:22.232] <TB3> INFO: dacScan step from 8 .. 11
[09:17:41.123] <TB3> INFO: Test took 18891ms.
[09:17:41.152] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:41.152] <TB3> INFO: dacScan step from 12 .. 15
[09:17:59.946] <TB3> INFO: Test took 18794ms.
[09:17:59.974] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:59.974] <TB3> INFO: dacScan step from 16 .. 19
[09:18:18.823] <TB3> INFO: Test took 18849ms.
[09:18:18.851] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:18:18.851] <TB3> INFO: dacScan step from 20 .. 23
[09:18:37.779] <TB3> INFO: Test took 18928ms.
[09:18:37.804] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:18:37.804] <TB3> INFO: dacScan step from 24 .. 27
[09:18:56.734] <TB3> INFO: Test took 18930ms.
[09:18:56.767] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:18:56.767] <TB3> INFO: dacScan step from 28 .. 31
[09:19:15.415] <TB3> INFO: Test took 18648ms.
[09:19:15.443] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:15.443] <TB3> INFO: dacScan step from 32 .. 35
[09:19:34.109] <TB3> INFO: Test took 18666ms.
[09:19:34.134] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:34.134] <TB3> INFO: dacScan step from 36 .. 39
[09:19:52.934] <TB3> INFO: Test took 18799ms.
[09:19:52.961] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:52.961] <TB3> INFO: dacScan step from 40 .. 43
[09:20:11.750] <TB3> INFO: Test took 18789ms.
[09:20:11.780] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:11.780] <TB3> INFO: dacScan step from 44 .. 47
[09:20:30.474] <TB3> INFO: Test took 18694ms.
[09:20:30.502] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:30.502] <TB3> INFO: dacScan step from 48 .. 51
[09:20:49.415] <TB3> INFO: Test took 18913ms.
[09:20:49.444] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:49.444] <TB3> INFO: dacScan step from 52 .. 55
[09:21:08.178] <TB3> INFO: Test took 18734ms.
[09:21:08.204] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:08.204] <TB3> INFO: dacScan step from 56 .. 59
[09:21:27.067] <TB3> INFO: Test took 18863ms.
[09:21:27.094] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:27.094] <TB3> INFO: dacScan step from 60 .. 63
[09:21:45.997] <TB3> INFO: Test took 18903ms.
[09:21:46.026] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:46.027] <TB3> INFO: dacScan step from 64 .. 67
[09:22:05.182] <TB3> INFO: Test took 19155ms.
[09:22:05.219] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:05.219] <TB3> INFO: dacScan step from 68 .. 71
[09:22:24.724] <TB3> INFO: Test took 19505ms.
[09:22:24.776] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:24.778] <TB3> INFO: dacScan step from 72 .. 75
[09:22:45.341] <TB3> INFO: Test took 20563ms.
[09:22:45.414] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:45.417] <TB3> INFO: dacScan step from 76 .. 79
[09:23:07.660] <TB3> INFO: Test took 22243ms.
[09:23:07.770] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:07.779] <TB3> INFO: dacScan step from 80 .. 83
[09:23:33.383] <TB3> INFO: Test took 25604ms.
[09:23:33.566] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:33.574] <TB3> INFO: dacScan step from 84 .. 87
[09:24:00.954] <TB3> INFO: Test took 27380ms.
[09:24:01.185] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:01.197] <TB3> INFO: dacScan step from 88 .. 91
[09:24:28.793] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:24:28.793] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:24:28.794] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:24:29.019] <TB3> INFO: Test took 27822ms.
[09:24:29.266] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:29.277] <TB3> INFO: dacScan step from 92 .. 95
[09:24:57.068] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:24:57.068] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:24:57.068] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:24:58.031] <TB3> INFO: Test took 28753ms.
[09:24:58.271] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:58.283] <TB3> INFO: dacScan step from 96 .. 99
[09:25:26.003] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:25:26.003] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:25:26.003] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:25:27.137] <TB3> INFO: Test took 28854ms.
[09:25:27.394] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:25:27.406] <TB3> INFO: dacScan step from 100 .. 103
[09:25:55.272] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:25:55.272] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:25:55.272] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:25:56.560] <TB3> INFO: Test took 29154ms.
[09:25:56.809] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:25:56.822] <TB3> INFO: dacScan step from 104 .. 107
[09:26:24.691] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:26:24.691] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:26:24.691] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:26:25.927] <TB3> INFO: Test took 29105ms.
[09:26:26.169] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:26:26.181] <TB3> INFO: dacScan step from 108 .. 111
[09:26:54.042] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[09:26:54.042] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:26:55.344] <TB3> INFO: Test took 29162ms.
[09:26:55.573] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:26:55.585] <TB3> INFO: dacScan step from 112 .. 115
[09:27:23.345] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:27:23.345] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:27:23.345] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:27:24.583] <TB3> INFO: Test took 28997ms.
[09:27:24.833] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:27:24.848] <TB3> INFO: dacScan step from 116 .. 119
[09:27:52.667] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[09:27:52.667] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:27:53.940] <TB3> INFO: Test took 29092ms.
[09:27:54.158] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:27:54.170] <TB3> INFO: dacScan step from 120 .. 123
[09:28:22.902] <TB3> INFO: Test took 28732ms.
[09:28:23.161] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:23.173] <TB3> INFO: dacScan step from 124 .. 127
[09:28:52.039] <TB3> INFO: Test took 28866ms.
[09:28:52.271] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:52.283] <TB3> INFO: dacScan step from 128 .. 131
[09:29:20.889] <TB3> INFO: Test took 28606ms.
[09:29:21.130] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:29:21.142] <TB3> INFO: dacScan step from 132 .. 135
[09:29:50.022] <TB3> INFO: Test took 28880ms.
[09:29:50.252] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:29:50.265] <TB3> INFO: dacScan step from 136 .. 139
[09:30:19.078] <TB3> INFO: Test took 28813ms.
[09:30:19.322] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:19.336] <TB3> INFO: dacScan step from 140 .. 143
[09:30:48.345] <TB3> INFO: Test took 29009ms.
[09:30:48.587] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:48.600] <TB3> INFO: dacScan step from 144 .. 147
[09:31:14.870] <TB3> INFO: Test took 26271ms.
[09:31:15.110] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:31:15.123] <TB3> INFO: dacScan step from 148 .. 149
[09:31:29.722] <TB3> INFO: Test took 14599ms.
[09:31:29.914] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:31:29.925] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:31.556] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:33.150] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:34.671] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:36.202] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:37.588] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:38.956] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:40.336] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:41.922] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:43.348] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:44.751] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:46.276] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:47.888] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:49.738] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:51.363] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:52.832] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[09:31:54.340] <TB3> INFO: PixTestScurves::scurves() done
[09:31:54.340] <TB3> INFO: Vcal mean: 87.17 76.10 73.10 84.48 82.26 91.06 85.73 83.13 76.60 78.46 87.34 80.18 82.93 82.26 86.21 87.61
[09:31:54.340] <TB3> INFO: Vcal RMS: 6.15 4.11 4.50 6.86 4.62 7.40 5.14 5.00 4.64 4.26 6.07 4.85 5.28 5.45 5.20 5.74
[09:31:54.340] <TB3> INFO: PixTestScurves::fullTest() done, duration: 909 seconds
[09:31:54.424] <TB3> INFO: ######################################################################
[09:31:54.424] <TB3> INFO: PixTestTrim::doTest()
[09:31:54.424] <TB3> INFO: ######################################################################
[09:31:54.425] <TB3> INFO: ----------------------------------------------------------------------
[09:31:54.426] <TB3> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[09:31:54.426] <TB3> INFO: ----------------------------------------------------------------------
[09:31:54.509] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[09:31:54.509] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[09:31:54.517] <TB3> INFO: dacScan step from 0 .. 19
[09:32:09.541] <TB3> INFO: Test took 15024ms.
[09:32:09.566] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:09.566] <TB3> INFO: dacScan step from 20 .. 39
[09:32:24.584] <TB3> INFO: Test took 15018ms.
[09:32:24.608] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:24.608] <TB3> INFO: dacScan step from 40 .. 59
[09:32:39.672] <TB3> INFO: Test took 15064ms.
[09:32:39.697] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:39.697] <TB3> INFO: dacScan step from 60 .. 79
[09:32:54.731] <TB3> INFO: Test took 15034ms.
[09:32:54.754] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:54.754] <TB3> INFO: dacScan step from 80 .. 99
[09:33:11.019] <TB3> INFO: Test took 16264ms.
[09:33:11.098] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:11.112] <TB3> INFO: dacScan step from 100 .. 119
[09:33:30.429] <TB3> INFO: Test took 19316ms.
[09:33:30.600] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:30.645] <TB3> INFO: dacScan step from 120 .. 139
[09:33:47.949] <TB3> INFO: Test took 17303ms.
[09:33:48.110] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:48.145] <TB3> INFO: dacScan step from 140 .. 159
[09:34:03.008] <TB3> INFO: Test took 14864ms.
[09:34:03.060] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:25.064] <TB3> INFO: ROC 0 VthrComp = 92
[09:34:25.064] <TB3> INFO: ROC 1 VthrComp = 83
[09:34:25.064] <TB3> INFO: ROC 2 VthrComp = 79
[09:34:25.064] <TB3> INFO: ROC 3 VthrComp = 84
[09:34:25.064] <TB3> INFO: ROC 4 VthrComp = 88
[09:34:25.064] <TB3> INFO: ROC 5 VthrComp = 92
[09:34:25.064] <TB3> INFO: ROC 6 VthrComp = 94
[09:34:25.064] <TB3> INFO: ROC 7 VthrComp = 88
[09:34:25.065] <TB3> INFO: ROC 8 VthrComp = 83
[09:34:25.065] <TB3> INFO: ROC 9 VthrComp = 82
[09:34:25.065] <TB3> INFO: ROC 10 VthrComp = 90
[09:34:25.065] <TB3> INFO: ROC 11 VthrComp = 84
[09:34:25.065] <TB3> INFO: ROC 12 VthrComp = 88
[09:34:25.065] <TB3> INFO: ROC 13 VthrComp = 87
[09:34:25.065] <TB3> INFO: ROC 14 VthrComp = 92
[09:34:25.065] <TB3> INFO: ROC 15 VthrComp = 91
[09:34:25.066] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[09:34:25.066] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[09:34:25.073] <TB3> INFO: dacScan step from 0 .. 19
[09:34:39.556] <TB3> INFO: Test took 14483ms.
[09:34:39.577] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:39.577] <TB3> INFO: dacScan step from 20 .. 39
[09:34:54.065] <TB3> INFO: Test took 14488ms.
[09:34:54.096] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:54.098] <TB3> INFO: dacScan step from 40 .. 59
[09:35:12.996] <TB3> INFO: Test took 18897ms.
[09:35:13.161] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:13.199] <TB3> INFO: dacScan step from 60 .. 79
[09:35:33.279] <TB3> INFO: Test took 20080ms.
[09:35:33.495] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:33.562] <TB3> INFO: dacScan step from 80 .. 99
[09:35:53.609] <TB3> INFO: Test took 20047ms.
[09:35:53.769] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:53.824] <TB3> INFO: dacScan step from 100 .. 119
[09:36:13.912] <TB3> INFO: Test took 20088ms.
[09:36:14.135] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:14.201] <TB3> INFO: dacScan step from 120 .. 139
[09:36:32.998] <TB3> INFO: Test took 18797ms.
[09:36:33.159] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:33.217] <TB3> INFO: dacScan step from 140 .. 159
[09:36:52.023] <TB3> INFO: Test took 18806ms.
[09:36:52.183] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:16.354] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 61.3101 for pixel 1/2 mean/min/max = 46.2459/31.161/61.3307
[09:37:16.354] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 55.6777 for pixel 20/79 mean/min/max = 43.8911/32.0558/55.7264
[09:37:16.354] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 58.1275 for pixel 11/3 mean/min/max = 46.4327/34.7311/58.1343
[09:37:16.354] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 63.3605 for pixel 18/0 mean/min/max = 47.055/30.7124/63.3976
[09:37:16.354] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 57.4033 for pixel 11/77 mean/min/max = 45.0874/32.7072/57.4676
[09:37:16.355] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 63.7818 for pixel 11/1 mean/min/max = 47.1636/30.0925/64.2348
[09:37:16.355] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 56.4315 for pixel 7/1 mean/min/max = 44.1642/31.8452/56.4832
[09:37:16.355] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 59.0567 for pixel 19/74 mean/min/max = 45.9151/32.7633/59.0669
[09:37:16.355] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 57.7874 for pixel 11/79 mean/min/max = 44.8561/31.7372/57.975
[09:37:16.356] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 57.4334 for pixel 21/0 mean/min/max = 45.0652/32.6927/57.4376
[09:37:16.356] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 61.9056 for pixel 1/68 mean/min/max = 46.9586/31.8231/62.0942
[09:37:16.356] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 59.1131 for pixel 0/5 mean/min/max = 45.4892/31.7367/59.2417
[09:37:16.356] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 60.5928 for pixel 17/79 mean/min/max = 46.6433/32.6763/60.6103
[09:37:16.357] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 60.362 for pixel 6/79 mean/min/max = 45.5907/30.7741/60.4073
[09:37:16.357] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 58.5741 for pixel 0/9 mean/min/max = 45.1994/31.799/58.5998
[09:37:16.357] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 60.8257 for pixel 18/58 mean/min/max = 46.1797/31.2947/61.0647
[09:37:16.357] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:38:50.053] <TB3> INFO: Test took 93696ms.
[09:38:51.577] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[09:38:51.585] <TB3> INFO: dacScan step from 0 .. 19
[09:39:14.142] <TB3> INFO: Test took 22557ms.
[09:39:14.189] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:14.190] <TB3> INFO: dacScan step from 20 .. 39
[09:39:42.432] <TB3> INFO: Test took 28242ms.
[09:39:42.668] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:42.700] <TB3> INFO: dacScan step from 40 .. 59
[09:40:14.448] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:40:14.448] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:40:14.448] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:40:15.659] <TB3> INFO: Test took 32959ms.
[09:40:15.937] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:15.991] <TB3> INFO: dacScan step from 60 .. 79
[09:40:46.936] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[09:40:46.936] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:40:48.045] <TB3> INFO: Test took 32054ms.
[09:40:48.426] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:48.495] <TB3> INFO: dacScan step from 80 .. 99
[09:41:18.927] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (207) != TBM ID (8)

[09:41:18.927] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[09:41:18.927] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (9) != TBM ID (208)

[09:41:18.927] <TB3> WARNING: ROC 3: Readback start marker after 31 readouts!

[09:41:20.142] <TB3> INFO: Test took 31647ms.
[09:41:20.501] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:20.562] <TB3> INFO: dacScan step from 100 .. 119
[09:41:53.535] <TB3> INFO: Test took 32973ms.
[09:41:53.810] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:53.865] <TB3> INFO: dacScan step from 120 .. 139
[09:42:25.691] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:42:25.691] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:42:25.691] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:42:26.898] <TB3> INFO: Test took 33033ms.
[09:42:27.170] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:27.227] <TB3> INFO: dacScan step from 140 .. 159
[09:42:58.894] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:42:58.894] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:42:58.894] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:43:00.012] <TB3> INFO: Test took 32785ms.
[09:43:00.359] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:43:00.423] <TB3> INFO: dacScan step from 160 .. 179
[09:43:32.342] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:43:32.342] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:43:32.342] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:43:33.585] <TB3> INFO: Test took 33162ms.
[09:43:33.864] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:43:33.918] <TB3> INFO: dacScan step from 180 .. 199
[09:44:04.258] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (211) != TBM ID (8)

[09:44:04.258] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[09:44:04.258] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (9) != TBM ID (212)

[09:44:04.259] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:44:05.300] <TB3> INFO: Test took 31382ms.
[09:44:05.587] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:30.907] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 0.028705 .. 255.000000
[09:44:30.988] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[09:44:30.996] <TB3> INFO: dacScan step from 0 .. 19
[09:44:44.515] <TB3> INFO: Test took 13519ms.
[09:44:44.542] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:44.542] <TB3> INFO: dacScan step from 20 .. 39
[09:44:59.357] <TB3> INFO: Test took 14815ms.
[09:44:59.436] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:59.452] <TB3> INFO: dacScan step from 40 .. 59
[09:45:16.883] <TB3> INFO: Test took 17431ms.
[09:45:17.032] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:17.086] <TB3> INFO: dacScan step from 60 .. 79
[09:45:34.586] <TB3> INFO: Test took 17500ms.
[09:45:34.734] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:34.791] <TB3> INFO: dacScan step from 80 .. 99
[09:45:52.287] <TB3> INFO: Test took 17496ms.
[09:45:52.492] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:52.583] <TB3> INFO: dacScan step from 100 .. 119
[09:46:10.122] <TB3> INFO: Test took 17539ms.
[09:46:10.267] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:10.334] <TB3> INFO: dacScan step from 120 .. 139
[09:46:27.919] <TB3> INFO: Test took 17585ms.
[09:46:28.093] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:28.151] <TB3> INFO: dacScan step from 140 .. 159
[09:46:45.850] <TB3> INFO: Test took 17698ms.
[09:46:45.998] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:46.055] <TB3> INFO: dacScan step from 160 .. 179
[09:47:03.794] <TB3> INFO: Test took 17738ms.
[09:47:03.939] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:03.997] <TB3> INFO: dacScan step from 180 .. 199
[09:47:22.525] <TB3> INFO: Test took 18528ms.
[09:47:22.674] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:22.747] <TB3> INFO: dacScan step from 200 .. 219
[09:47:40.286] <TB3> INFO: Test took 17539ms.
[09:47:40.424] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:40.493] <TB3> INFO: dacScan step from 220 .. 239
[09:47:56.941] <TB3> INFO: Test took 16448ms.
[09:47:57.075] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:57.150] <TB3> INFO: dacScan step from 240 .. 255
[09:48:10.932] <TB3> INFO: Test took 13782ms.
[09:48:11.046] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:46.262] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 12.160956 .. 47.868164
[09:48:46.342] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 2 .. 57 (20) hits flags = 16 (plus default)
[09:48:46.350] <TB3> INFO: dacScan step from 2 .. 21
[09:48:59.858] <TB3> INFO: Test took 13508ms.
[09:48:59.877] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:59.877] <TB3> INFO: dacScan step from 22 .. 41
[09:49:14.337] <TB3> INFO: Test took 14459ms.
[09:49:14.428] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:14.451] <TB3> INFO: dacScan step from 42 .. 57
[09:49:28.249] <TB3> INFO: Test took 13798ms.
[09:49:28.363] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:46.148] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 20.136455 .. 45.644788
[09:49:46.247] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 10 .. 55 (20) hits flags = 16 (plus default)
[09:49:46.257] <TB3> INFO: dacScan step from 10 .. 29
[09:49:59.789] <TB3> INFO: Test took 13532ms.
[09:49:59.815] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:59.816] <TB3> INFO: dacScan step from 30 .. 49
[09:50:15.516] <TB3> INFO: Test took 15700ms.
[09:50:15.659] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:15.705] <TB3> INFO: dacScan step from 50 .. 55
[09:50:22.643] <TB3> INFO: Test took 6938ms.
[09:50:22.685] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:40.483] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 2.799947 .. 45.427366
[09:50:40.564] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 2 .. 55 (20) hits flags = 16 (plus default)
[09:50:40.572] <TB3> INFO: dacScan step from 2 .. 21
[09:50:54.135] <TB3> INFO: Test took 13563ms.
[09:50:54.163] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:54.163] <TB3> INFO: dacScan step from 22 .. 41
[09:51:08.556] <TB3> INFO: Test took 14393ms.
[09:51:08.663] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:08.687] <TB3> INFO: dacScan step from 42 .. 55
[09:51:21.123] <TB3> INFO: Test took 12436ms.
[09:51:21.241] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:39.067] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[09:51:39.067] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[09:51:39.075] <TB3> INFO: dacScan step from 15 .. 34
[09:52:02.063] <TB3> INFO: Test took 22988ms.
[09:52:02.135] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:02.144] <TB3> INFO: dacScan step from 35 .. 54
[09:52:32.145] <TB3> INFO: Test took 30001ms.
[09:52:32.463] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:32.518] <TB3> INFO: dacScan step from 55 .. 55
[09:52:36.885] <TB3> INFO: Test took 4367ms.
[09:52:36.909] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:50.098] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C0.dat
[09:52:50.099] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C1.dat
[09:52:50.099] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C2.dat
[09:52:50.099] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C3.dat
[09:52:50.099] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C4.dat
[09:52:50.099] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C5.dat
[09:52:50.099] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C6.dat
[09:52:50.099] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C7.dat
[09:52:50.100] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C8.dat
[09:52:50.100] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C9.dat
[09:52:50.100] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C10.dat
[09:52:50.100] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C11.dat
[09:52:50.100] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C12.dat
[09:52:50.100] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C13.dat
[09:52:50.101] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C14.dat
[09:52:50.101] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C15.dat
[09:52:50.101] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C0.dat
[09:52:50.111] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C1.dat
[09:52:50.117] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C2.dat
[09:52:50.122] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C3.dat
[09:52:50.128] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C4.dat
[09:52:50.134] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C5.dat
[09:52:50.140] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C6.dat
[09:52:50.146] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C7.dat
[09:52:50.152] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C8.dat
[09:52:50.158] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C9.dat
[09:52:50.163] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C10.dat
[09:52:50.169] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C11.dat
[09:52:50.175] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C12.dat
[09:52:50.181] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C13.dat
[09:52:50.187] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C14.dat
[09:52:50.193] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//trimParameters35_C15.dat
[09:52:50.199] <TB3> INFO: PixTestTrim::trimTest() done
[09:52:50.199] <TB3> INFO: vtrim: 124 91 110 116 112 124 111 112 96 98 129 110 109 97 119 122
[09:52:50.199] <TB3> INFO: vthrcomp: 92 83 79 84 88 92 94 88 83 82 90 84 88 87 92 91
[09:52:50.199] <TB3> INFO: vcal mean: 35.03 35.06 35.06 35.06 35.05 35.05 35.07 35.02 35.03 35.02 35.03 35.06 35.09 35.01 35.01 35.07
[09:52:50.199] <TB3> INFO: vcal RMS: 1.20 0.94 0.99 1.14 1.03 1.37 0.99 1.03 0.97 0.96 1.05 1.02 0.98 1.00 1.01 1.03
[09:52:50.199] <TB3> INFO: bits mean: 10.03 9.64 9.42 9.75 10.24 9.80 10.26 9.87 9.77 9.70 9.79 9.94 9.51 9.26 10.04 9.95
[09:52:50.199] <TB3> INFO: bits RMS: 2.53 2.58 2.29 2.57 2.26 2.63 2.46 2.41 2.69 2.51 2.52 2.56 2.52 2.99 2.53 2.55
[09:52:50.204] <TB3> INFO: ----------------------------------------------------------------------
[09:52:50.204] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 240 150 100
[09:52:50.204] <TB3> INFO: ----------------------------------------------------------------------
[09:52:50.206] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[09:52:50.215] <TB3> INFO: dacScan step from 0 .. 19
[09:53:12.836] <TB3> INFO: Test took 22621ms.
[09:53:12.874] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:12.874] <TB3> INFO: dacScan step from 20 .. 39
[09:53:35.767] <TB3> INFO: Test took 22893ms.
[09:53:35.824] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:35.828] <TB3> INFO: dacScan step from 40 .. 59
[09:54:03.610] <TB3> INFO: Test took 27780ms.
[09:54:03.858] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:03.899] <TB3> INFO: dacScan step from 60 .. 79
[09:54:35.333] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[09:54:35.333] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[09:54:35.333] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[09:54:36.655] <TB3> INFO: Test took 32756ms.
[09:54:36.944] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:36.999] <TB3> INFO: dacScan step from 80 .. 99
[09:55:07.719] <TB3> INFO: Test took 30720ms.
[09:55:08.062] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:08.123] <TB3> INFO: dacScan step from 100 .. 119
[09:55:40.636] <TB3> INFO: Test took 32512ms.
[09:55:40.933] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:40.983] <TB3> INFO: dacScan step from 120 .. 139
[09:56:11.561] <TB3> INFO: Test took 30578ms.
[09:56:11.852] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:56:11.908] <TB3> INFO: dacScan step from 140 .. 159
[09:56:44.573] <TB3> INFO: Test took 32665ms.
[09:56:44.850] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:56:44.902] <TB3> INFO: dacScan step from 160 .. 179
[09:57:16.225] <TB3> INFO: Test took 31323ms.
[09:57:16.514] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:57:16.559] <TB3> INFO: dacScan step from 180 .. 199
[09:57:48.591] <TB3> INFO: Test took 32032ms.
[09:57:48.977] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:16.795] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 84 (20) hits flags = 16 (plus default)
[09:58:16.803] <TB3> INFO: dacScan step from 0 .. 19
[09:58:39.448] <TB3> INFO: Test took 22645ms.
[09:58:39.482] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:39.482] <TB3> INFO: dacScan step from 20 .. 39
[09:59:03.259] <TB3> INFO: Test took 23777ms.
[09:59:03.349] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:03.359] <TB3> INFO: dacScan step from 40 .. 59
[09:59:34.945] <TB3> INFO: Test took 31586ms.
[09:59:35.220] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:35.266] <TB3> INFO: dacScan step from 60 .. 79
[10:00:06.902] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (8) != Token Chain Length (4)

[10:00:06.902] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (72) != TBM ID (73)

[10:00:06.903] <TB3> WARNING: ROC 0: Readback start marker after 15 readouts!

[10:00:06.903] <TB3> WARNING: ROC 1: Readback start marker after 15 readouts!

[10:00:06.903] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[10:00:06.903] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:00:08.120] <TB3> INFO: Test took 32854ms.
[10:00:08.400] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:08.448] <TB3> INFO: dacScan step from 80 .. 84
[10:00:18.088] <TB3> INFO: Test took 9639ms.
[10:00:18.198] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:35.836] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 78 (20) hits flags = 16 (plus default)
[10:00:35.845] <TB3> INFO: dacScan step from 0 .. 19
[10:00:58.346] <TB3> INFO: Test took 22501ms.
[10:00:58.383] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:58.383] <TB3> INFO: dacScan step from 20 .. 39
[10:01:23.308] <TB3> INFO: Test took 24925ms.
[10:01:23.448] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:23.468] <TB3> INFO: dacScan step from 40 .. 59
[10:01:55.186] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (2) != Token Chain Length (4)

[10:01:55.186] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[10:01:55.186] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:01:55.959] <TB3> INFO: Test took 32491ms.
[10:01:56.260] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:56.307] <TB3> INFO: dacScan step from 60 .. 78
[10:02:27.025] <TB3> INFO: Test took 30718ms.
[10:02:27.316] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:43.992] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 72 (20) hits flags = 16 (plus default)
[10:02:43.999] <TB3> INFO: dacScan step from 0 .. 19
[10:03:06.521] <TB3> INFO: Test took 22522ms.
[10:03:06.561] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:06.561] <TB3> INFO: dacScan step from 20 .. 39
[10:03:32.690] <TB3> INFO: Test took 26129ms.
[10:03:32.855] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:32.874] <TB3> INFO: dacScan step from 40 .. 59
[10:04:04.319] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (3) != Token Chain Length (4)

[10:04:04.319] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:04:05.313] <TB3> INFO: Test took 32438ms.
[10:04:05.586] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:05.626] <TB3> INFO: dacScan step from 60 .. 72
[10:04:27.534] <TB3> INFO: Test took 21908ms.
[10:04:27.826] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:44.487] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 70 (20) hits flags = 16 (plus default)
[10:04:44.496] <TB3> INFO: dacScan step from 0 .. 19
[10:05:07.092] <TB3> INFO: Test took 22596ms.
[10:05:07.133] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:07.134] <TB3> INFO: dacScan step from 20 .. 39
[10:05:34.768] <TB3> INFO: Test took 27634ms.
[10:05:34.967] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:34.993] <TB3> INFO: dacScan step from 40 .. 59
[10:06:06.683] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Number of ROCs (8) != Token Chain Length (4)

[10:06:06.683] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Event ID mismatch: local ID (118) != TBM ID (119)

[10:06:06.683] <TB3> WARNING: ROC 0: Readback start marker after 15 readouts!

[10:06:06.684] <TB3> WARNING: ROC 1: Readback start marker after 15 readouts!

[10:06:06.684] <TB3> WARNING: ROC 2: Readback start marker after 15 readouts!

[10:06:06.684] <TB3> WARNING: ROC 3: Readback start marker after 15 readouts!

[10:06:07.857] <TB3> INFO: Test took 32864ms.
[10:06:08.141] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:08.183] <TB3> INFO: dacScan step from 60 .. 70
[10:06:27.305] <TB3> INFO: Test took 19122ms.
[10:06:27.455] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:43.820] <TB3> INFO: PixTestTrim::trimBitTest() done
[10:06:43.821] <TB3> INFO: PixTestTrim::doTest() done, duration: 2089 seconds
[10:06:44.498] <TB3> INFO: ######################################################################
[10:06:44.498] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[10:06:44.498] <TB3> INFO: ######################################################################
[10:06:47.891] <TB3> INFO: Test took 3391ms.
[10:06:47.910] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:51.547] <TB3> INFO: Test took 3439ms.
[10:06:51.621] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:55.064] <TB3> INFO: Test took 3432ms.
[10:06:55.144] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:55.153] <TB3> INFO: The DUT currently contains the following objects:
[10:06:55.153] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:06:55.153] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:06:55.153] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:06:55.153] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:06:55.153] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:55.154] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.264] <TB3> INFO: Test took 1110ms.
[10:06:56.265] <TB3> INFO: The DUT currently contains the following objects:
[10:06:56.265] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:06:56.265] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:06:56.265] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:06:56.265] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:06:56.266] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:56.266] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.374] <TB3> INFO: Test took 1108ms.
[10:06:57.375] <TB3> INFO: The DUT currently contains the following objects:
[10:06:57.375] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:06:57.375] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:06:57.375] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:06:57.375] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:06:57.375] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.375] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.375] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.375] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.375] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.375] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.375] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.376] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.376] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.376] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.376] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.376] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.376] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.376] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.376] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:57.376] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.481] <TB3> INFO: Test took 1105ms.
[10:06:58.483] <TB3> INFO: The DUT currently contains the following objects:
[10:06:58.483] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:06:58.483] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:06:58.483] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:06:58.483] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:06:58.483] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:58.483] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.590] <TB3> INFO: Test took 1107ms.
[10:06:59.591] <TB3> INFO: The DUT currently contains the following objects:
[10:06:59.591] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:06:59.591] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:06:59.591] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:06:59.591] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:06:59.591] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:06:59.591] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.698] <TB3> INFO: Test took 1107ms.
[10:07:00.699] <TB3> INFO: The DUT currently contains the following objects:
[10:07:00.699] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:00.699] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:00.699] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:00.699] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:00.699] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.699] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.699] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:00.700] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.807] <TB3> INFO: Test took 1107ms.
[10:07:01.808] <TB3> INFO: The DUT currently contains the following objects:
[10:07:01.808] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:01.808] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:01.808] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:01.808] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:01.808] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:01.808] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.915] <TB3> INFO: Test took 1106ms.
[10:07:02.916] <TB3> INFO: The DUT currently contains the following objects:
[10:07:02.916] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:02.916] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:02.916] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:02.916] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:02.916] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.916] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:02.917] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.025] <TB3> INFO: Test took 1108ms.
[10:07:04.026] <TB3> INFO: The DUT currently contains the following objects:
[10:07:04.026] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:04.026] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:04.026] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:04.026] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:04.027] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:04.027] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.135] <TB3> INFO: Test took 1108ms.
[10:07:05.136] <TB3> INFO: The DUT currently contains the following objects:
[10:07:05.136] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:05.136] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:05.136] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:05.136] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:05.136] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.136] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.136] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.136] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.136] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.136] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.136] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.136] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.136] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.137] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.137] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.137] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.137] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.137] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.137] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:05.137] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.243] <TB3> INFO: Test took 1106ms.
[10:07:06.245] <TB3> INFO: The DUT currently contains the following objects:
[10:07:06.245] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:06.245] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:06.245] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:06.245] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:06.245] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.245] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.245] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.245] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.245] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.246] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.246] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.246] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.247] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.247] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.247] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.247] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.247] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.247] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.247] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:06.247] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.356] <TB3> INFO: Test took 1109ms.
[10:07:07.357] <TB3> INFO: The DUT currently contains the following objects:
[10:07:07.357] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:07.357] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:07.357] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:07.357] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:07.357] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.357] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.357] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.357] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.357] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.357] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.357] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.357] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.357] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.358] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.358] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.358] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.358] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.358] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.358] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:07.358] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.465] <TB3> INFO: Test took 1107ms.
[10:07:08.467] <TB3> INFO: The DUT currently contains the following objects:
[10:07:08.467] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:08.467] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:08.467] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:08.467] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:08.467] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.467] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.467] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.467] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.467] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.467] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.467] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.467] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.468] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.468] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.468] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.468] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.468] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.468] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.468] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:08.468] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.574] <TB3> INFO: Test took 1106ms.
[10:07:09.575] <TB3> INFO: The DUT currently contains the following objects:
[10:07:09.575] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:09.575] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:09.575] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:09.575] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:09.575] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.575] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:09.576] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.683] <TB3> INFO: Test took 1107ms.
[10:07:10.684] <TB3> INFO: The DUT currently contains the following objects:
[10:07:10.684] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:10.684] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:10.684] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:10.684] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:10.684] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.684] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.684] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.684] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.684] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.684] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.684] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.685] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.685] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.685] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.685] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.685] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.685] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.685] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.685] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:10.685] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.792] <TB3> INFO: Test took 1107ms.
[10:07:11.793] <TB3> INFO: The DUT currently contains the following objects:
[10:07:11.793] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[10:07:11.793] <TB3> INFO: TBM Core alpha (0): 7 registers set
[10:07:11.794] <TB3> INFO: TBM Core beta (1): 7 registers set
[10:07:11.794] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:07:11.794] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:11.794] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:07:12.900] <TB3> INFO: Test took 1106ms.
[10:07:12.904] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:10:54.504] <TB3> INFO: Test took 221600ms.
[10:10:56.241] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:14:40.952] <TB3> INFO: Test took 224711ms.
[10:14:44.364] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.374] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.384] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.394] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.404] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.414] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.421] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[10:14:44.430] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.439] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.448] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.458] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.468] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.478] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.488] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.498] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.508] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.518] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[10:14:44.573] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C0.dat
[10:14:44.585] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C1.dat
[10:14:44.634] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C2.dat
[10:14:44.649] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C3.dat
[10:14:44.650] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C4.dat
[10:14:44.650] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C5.dat
[10:14:44.650] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C6.dat
[10:14:44.650] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C7.dat
[10:14:44.651] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C8.dat
[10:14:44.659] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C9.dat
[10:14:44.660] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C10.dat
[10:14:44.660] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C11.dat
[10:14:44.660] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C12.dat
[10:14:44.664] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C13.dat
[10:14:44.664] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C14.dat
[10:14:44.667] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//dacParameters35_C15.dat
[10:14:48.077] <TB3> INFO: Test took 3407ms.
[10:14:51.804] <TB3> INFO: Test took 3451ms.
[10:14:55.502] <TB3> INFO: Test took 3427ms.
[10:14:55.796] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:14:56.720] <TB3> INFO: Test took 924ms.
[10:14:56.723] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:14:57.833] <TB3> INFO: Test took 1110ms.
[10:14:57.837] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:14:58.946] <TB3> INFO: Test took 1109ms.
[10:14:58.949] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:00.057] <TB3> INFO: Test took 1108ms.
[10:15:00.060] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:01.168] <TB3> INFO: Test took 1108ms.
[10:15:01.172] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:02.280] <TB3> INFO: Test took 1108ms.
[10:15:02.283] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:03.392] <TB3> INFO: Test took 1109ms.
[10:15:03.395] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:04.503] <TB3> INFO: Test took 1108ms.
[10:15:04.507] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:05.616] <TB3> INFO: Test took 1110ms.
[10:15:05.620] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:06.730] <TB3> INFO: Test took 1111ms.
[10:15:06.734] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:07.844] <TB3> INFO: Test took 1110ms.
[10:15:07.848] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:08.957] <TB3> INFO: Test took 1109ms.
[10:15:08.960] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:10.070] <TB3> INFO: Test took 1110ms.
[10:15:10.074] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:11.183] <TB3> INFO: Test took 1109ms.
[10:15:11.186] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:12.308] <TB3> INFO: Test took 1122ms.
[10:15:12.311] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:13.419] <TB3> INFO: Test took 1108ms.
[10:15:13.422] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:14.529] <TB3> INFO: Test took 1107ms.
[10:15:14.532] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:15.641] <TB3> INFO: Test took 1109ms.
[10:15:15.645] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:16.754] <TB3> INFO: Test took 1109ms.
[10:15:16.757] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:17.867] <TB3> INFO: Test took 1110ms.
[10:15:17.870] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:18.979] <TB3> INFO: Test took 1109ms.
[10:15:18.982] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:20.092] <TB3> INFO: Test took 1110ms.
[10:15:20.096] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:21.204] <TB3> INFO: Test took 1109ms.
[10:15:21.208] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:22.318] <TB3> INFO: Test took 1110ms.
[10:15:22.322] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:23.424] <TB3> INFO: Test took 1102ms.
[10:15:23.426] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:24.534] <TB3> INFO: Test took 1108ms.
[10:15:24.538] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:25.647] <TB3> INFO: Test took 1109ms.
[10:15:25.651] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:26.760] <TB3> INFO: Test took 1109ms.
[10:15:26.763] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:27.870] <TB3> INFO: Test took 1107ms.
[10:15:27.874] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:28.982] <TB3> INFO: Test took 1108ms.
[10:15:28.986] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:30.094] <TB3> INFO: Test took 1108ms.
[10:15:30.097] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:15:31.204] <TB3> INFO: Test took 1107ms.
[10:15:31.754] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 527 seconds
[10:15:31.754] <TB3> INFO: PH scale (per ROC): 87 90 86 70 86 80 92 87 89 77 79 85 84 90 89 80
[10:15:31.754] <TB3> INFO: PH offset (per ROC): 159 146 162 159 148 160 161 161 171 175 155 155 156 156 147 170
[10:15:31.977] <TB3> INFO: ######################################################################
[10:15:31.977] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[10:15:31.977] <TB3> INFO: ######################################################################
[10:15:31.987] <TB3> INFO: scanning low vcal = 50
[10:15:36.370] <TB3> INFO: Test took 4383ms.
[10:15:36.438] <TB3> INFO: scanning low vcal = 100
[10:15:40.739] <TB3> INFO: Test took 4301ms.
[10:15:40.794] <TB3> INFO: scanning low vcal = 150
[10:15:45.160] <TB3> INFO: Test took 4366ms.
[10:15:45.228] <TB3> INFO: scanning low vcal = 200
[10:15:49.613] <TB3> INFO: Test took 4385ms.
[10:15:49.673] <TB3> INFO: scanning low vcal = 250
[10:15:54.003] <TB3> INFO: Test took 4330ms.
[10:15:54.063] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[10:15:58.421] <TB3> INFO: Test took 4358ms.
[10:15:58.481] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[10:16:02.836] <TB3> INFO: Test took 4355ms.
[10:16:02.897] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[10:16:07.237] <TB3> INFO: Test took 4340ms.
[10:16:07.298] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[10:16:11.678] <TB3> INFO: Test took 4380ms.
[10:16:11.751] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[10:16:16.175] <TB3> INFO: Test took 4424ms.
[10:16:16.523] <TB3> INFO: PixTestGainPedestal::measure() done
[10:16:41.414] <TB3> INFO: PixTestGainPedestal::fit() done
[10:16:41.414] <TB3> INFO: non-linearity mean: 0.959 0.957 0.947 0.945 0.950 0.958 0.950 0.958 0.956 0.953 0.945 0.953 0.955 0.960 0.953 0.957
[10:16:41.414] <TB3> INFO: non-linearity RMS: 0.005 0.005 0.006 0.007 0.006 0.004 0.006 0.005 0.006 0.006 0.007 0.006 0.005 0.006 0.005 0.006
[10:16:41.416] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[10:16:41.437] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[10:16:41.459] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[10:16:41.481] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[10:16:41.502] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[10:16:41.524] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[10:16:41.560] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[10:16:41.582] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[10:16:41.603] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[10:16:41.625] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[10:16:41.646] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[10:16:41.667] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[10:16:41.689] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[10:16:41.711] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[10:16:41.732] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[10:16:41.754] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2039_FullQualification_2015-07-08_10h58m_1436345921//000_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[10:16:41.775] <TB3> INFO: PixTestGainPedestal::doTest() done, duration: 69 seconds
[10:16:41.792] <TB3> INFO: enter test to run
[10:16:41.794] <TB3> INFO: test: exit no parameter change
[10:16:42.571] <TB3> QUIET: Connection to board 170 closed.
[10:16:42.651] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master