Test Date: 2015-08-18 11:20
Analysis date: 2016-05-26 00:20
Logfile
LogfileView
[12:10:09.071] <TB3> INFO: *** Welcome to pxar ***
[12:10:09.071] <TB3> INFO: *** Today: 2015/08/18
[12:10:09.071] <TB3> INFO: readRocDacs: /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C15.dat
[12:10:09.072] <TB3> INFO: readTbmDacs: /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//tbmParameters_C0b.dat
[12:10:09.072] <TB3> INFO: readMaskFile: /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//defaultMaskFile.dat
[12:10:09.072] <TB3> INFO: readTrimFile: /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters_C15.dat
[12:10:09.144] <TB3> INFO: clk: 4
[12:10:09.144] <TB3> INFO: ctr: 4
[12:10:09.144] <TB3> INFO: sda: 19
[12:10:09.144] <TB3> INFO: tin: 9
[12:10:09.144] <TB3> INFO: level: 15
[12:10:09.144] <TB3> INFO: triggerdelay: 0
[12:10:09.144] <TB3> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[12:10:09.144] <TB3> INFO: Log level: INFO
[12:10:09.152] <TB3> INFO: Found DTB DTB_WZ4I6J
[12:10:09.162] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[12:10:09.166] <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:
------------------------------------------------------
[12:10:09.169] <TB3> INFO: RPC call hashes of host and DTB match: 447413373
[12:10:10.699] <TB3> INFO: DUT info:
[12:10:10.699] <TB3> INFO: The DUT currently contains the following objects:
[12:10:10.699] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:10:10.699] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:10:10.699] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:10:10.699] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:10:10.699] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:10.699] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:10:11.100] <TB3> INFO: enter 'restricted' command line mode
[12:10:11.101] <TB3> INFO: enter test to run
[12:10:11.101] <TB3> INFO: test: pretest no parameter change
[12:10:11.101] <TB3> INFO: running: pretest
[12:10:11.108] <TB3> INFO: ######################################################################
[12:10:11.108] <TB3> INFO: PixTestPretest::doTest()
[12:10:11.108] <TB3> INFO: ######################################################################
[12:10:11.110] <TB3> INFO: ----------------------------------------------------------------------
[12:10:11.110] <TB3> INFO: PixTestPretest::programROC()
[12:10:11.110] <TB3> INFO: ----------------------------------------------------------------------
[12:10:29.128] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[12:10:29.128] <TB3> INFO: IA differences per ROC: 17.7 17.7 17.7 19.3 19.3 18.5 19.3 19.3 19.3 17.7 20.9 17.7 20.9 20.1 18.5 20.1
[12:10:29.202] <TB3> INFO: ----------------------------------------------------------------------
[12:10:29.202] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[12:10:29.202] <TB3> INFO: ----------------------------------------------------------------------
[12:10:34.389] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 396.3 mA = 24.7688 mA/ROC
[12:10:34.393] <TB3> INFO: ----------------------------------------------------------------------
[12:10:34.393] <TB3> INFO: PixTestPretest::findWorkingPixel()
[12:10:34.393] <TB3> INFO: ----------------------------------------------------------------------
[12:10:42.562] <TB3> INFO: Test took 8163ms.
[12:10:42.848] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[12:10:42.886] <TB3> INFO: ----------------------------------------------------------------------
[12:10:42.886] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[12:10:42.886] <TB3> INFO: ----------------------------------------------------------------------
[12:10:51.197] <TB3> INFO: Test took 8305ms.
[12:10:51.512] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[12:10:51.512] <TB3> INFO: CalDel: 123 143 140 167 175 151 136 162 173 157 154 158 157 163 164 153
[12:10:51.512] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[12:10:51.516] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C0.dat
[12:10:51.516] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C1.dat
[12:10:51.517] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C2.dat
[12:10:51.517] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C3.dat
[12:10:51.517] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C4.dat
[12:10:51.517] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C5.dat
[12:10:51.517] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C6.dat
[12:10:51.517] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C7.dat
[12:10:51.517] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C8.dat
[12:10:51.517] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C9.dat
[12:10:51.518] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C10.dat
[12:10:51.518] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C11.dat
[12:10:51.518] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C12.dat
[12:10:51.518] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C13.dat
[12:10:51.518] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C14.dat
[12:10:51.518] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters_C15.dat
[12:10:51.518] <TB3> INFO: PixTestPretest::doTest() done, duration: 40 seconds
[12:10:51.623] <TB3> INFO: enter test to run
[12:10:51.623] <TB3> INFO: test: fulltest no parameter change
[12:10:51.623] <TB3> INFO: running: fulltest
[12:10:51.623] <TB3> INFO: ######################################################################
[12:10:51.623] <TB3> INFO: PixTestFullTest::doTest()
[12:10:51.623] <TB3> INFO: ######################################################################
[12:10:51.625] <TB3> INFO: ######################################################################
[12:10:51.625] <TB3> INFO: PixTestAlive::doTest()
[12:10:51.625] <TB3> INFO: ######################################################################
[12:10:51.626] <TB3> INFO: ----------------------------------------------------------------------
[12:10:51.626] <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)
[12:10:51.626] <TB3> INFO: ----------------------------------------------------------------------
[12:10:55.094] <TB3> INFO: Test took 3466ms.
[12:10:55.119] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:55.341] <TB3> INFO: PixTestAlive::aliveTest() done
[12:10:55.342] <TB3> INFO: number of dead pixels (per ROC): 1 0 1 0 1 0 0 3 0 1 0 0 0 0 0 1
[12:10:55.343] <TB3> INFO: ----------------------------------------------------------------------
[12:10:55.343] <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)
[12:10:55.343] <TB3> INFO: ----------------------------------------------------------------------
[12:10:58.085] <TB3> INFO: Test took 2740ms.
[12:10:58.088] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:58.089] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[12:10:58.320] <TB3> INFO: PixTestAlive::maskTest() done
[12:10:58.320] <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
[12:10:58.322] <TB3> INFO: ----------------------------------------------------------------------
[12:10:58.322] <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)
[12:10:58.322] <TB3> INFO: ----------------------------------------------------------------------
[12:11:01.780] <TB3> INFO: Test took 3456ms.
[12:11:01.803] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:02.031] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[12:11:02.031] <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
[12:11:02.031] <TB3> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[12:11:02.046] <TB3> INFO: ######################################################################
[12:11:02.047] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[12:11:02.047] <TB3> INFO: ######################################################################
[12:11:02.050] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[12:11:02.061] <TB3> INFO: dacScan step from 0 .. 29
[12:11:23.532] <TB3> INFO: Test took 21471ms.
[12:11:23.557] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:23.561] <TB3> INFO: dacScan step from 30 .. 59
[12:11:47.043] <TB3> INFO: Test took 23482ms.
[12:11:47.172] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:47.189] <TB3> INFO: dacScan step from 60 .. 89
[12:12:16.360] <TB3> INFO: Test took 29171ms.
[12:12:16.626] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:16.705] <TB3> INFO: dacScan step from 90 .. 119
[12:12:45.811] <TB3> INFO: Test took 29106ms.
[12:12:46.067] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:46.143] <TB3> INFO: dacScan step from 120 .. 149
[12:13:10.099] <TB3> INFO: Test took 23956ms.
[12:13:10.288] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:34.751] <TB3> INFO: PixTestBBMap::doTest() done, duration: 152 seconds
[12:13:34.751] <TB3> INFO: number of dead bumps (per ROC): 3 0 0 0 0 0 0 0 0 0 0 0 7 0 1 1
[12:13:34.751] <TB3> INFO: separation cut (per ROC): 84 89 89 76 74 97 82 89 79 78 88 69 105 77 74 86
[12:13:34.838] <TB3> INFO: ######################################################################
[12:13:34.838] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50
[12:13:34.838] <TB3> INFO: ######################################################################
[12:13:34.838] <TB3> INFO: ----------------------------------------------------------------------
[12:13:34.838] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[12:13:34.838] <TB3> INFO: ----------------------------------------------------------------------
[12:13:34.838] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[12:13:34.846] <TB3> INFO: dacScan step from 0 .. 3
[12:13:53.902] <TB3> INFO: Test took 19056ms.
[12:13:53.935] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:53.935] <TB3> INFO: dacScan step from 4 .. 7
[12:14:13.097] <TB3> INFO: Test took 19162ms.
[12:14:13.130] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:13.130] <TB3> INFO: dacScan step from 8 .. 11
[12:14:32.264] <TB3> INFO: Test took 19134ms.
[12:14:32.297] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:32.297] <TB3> INFO: dacScan step from 12 .. 15
[12:14:51.370] <TB3> INFO: Test took 19073ms.
[12:14:51.399] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:51.399] <TB3> INFO: dacScan step from 16 .. 19
[12:15:10.395] <TB3> INFO: Test took 18996ms.
[12:15:10.426] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:10.426] <TB3> INFO: dacScan step from 20 .. 23
[12:15:29.403] <TB3> INFO: Test took 18977ms.
[12:15:29.433] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:29.433] <TB3> INFO: dacScan step from 24 .. 27
[12:15:48.443] <TB3> INFO: Test took 19010ms.
[12:15:48.475] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:48.475] <TB3> INFO: dacScan step from 28 .. 31
[12:16:07.458] <TB3> INFO: Test took 18983ms.
[12:16:07.491] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:07.491] <TB3> INFO: dacScan step from 32 .. 35
[12:16:26.567] <TB3> INFO: Test took 19076ms.
[12:16:26.598] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:26.598] <TB3> INFO: dacScan step from 36 .. 39
[12:16:45.590] <TB3> INFO: Test took 18992ms.
[12:16:45.619] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:45.619] <TB3> INFO: dacScan step from 40 .. 43
[12:17:04.628] <TB3> INFO: Test took 19008ms.
[12:17:04.661] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:04.661] <TB3> INFO: dacScan step from 44 .. 47
[12:17:23.769] <TB3> INFO: Test took 19108ms.
[12:17:23.798] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:23.798] <TB3> INFO: dacScan step from 48 .. 51
[12:17:42.963] <TB3> INFO: Test took 19165ms.
[12:17:42.990] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:42.990] <TB3> INFO: dacScan step from 52 .. 55
[12:18:01.953] <TB3> INFO: Test took 18963ms.
[12:18:01.979] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:01.979] <TB3> INFO: dacScan step from 56 .. 59
[12:18:19.535] <TB3> INFO: Test took 17556ms.
[12:18:19.564] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:19.564] <TB3> INFO: dacScan step from 60 .. 63
[12:18:37.162] <TB3> INFO: Test took 17598ms.
[12:18:37.190] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:37.190] <TB3> INFO: dacScan step from 64 .. 67
[12:18:54.890] <TB3> INFO: Test took 17700ms.
[12:18:54.917] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:54.917] <TB3> INFO: dacScan step from 68 .. 71
[12:19:12.626] <TB3> INFO: Test took 17709ms.
[12:19:12.660] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:12.660] <TB3> INFO: dacScan step from 72 .. 75
[12:19:30.490] <TB3> INFO: Test took 17829ms.
[12:19:30.533] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:30.534] <TB3> INFO: dacScan step from 76 .. 79
[12:19:50.877] <TB3> INFO: Test took 20342ms.
[12:19:50.951] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:50.954] <TB3> INFO: dacScan step from 80 .. 83
[12:20:13.821] <TB3> INFO: Test took 22867ms.
[12:20:13.951] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:13.958] <TB3> INFO: dacScan step from 84 .. 87
[12:20:39.186] <TB3> INFO: Test took 25228ms.
[12:20:39.383] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:39.392] <TB3> INFO: dacScan step from 88 .. 91
[12:21:06.231] <TB3> INFO: Test took 26839ms.
[12:21:06.433] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:06.442] <TB3> INFO: dacScan step from 92 .. 95
[12:21:34.852] <TB3> INFO: Test took 28410ms.
[12:21:35.089] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:35.099] <TB3> INFO: dacScan step from 96 .. 99
[12:22:03.316] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (199) != TBM ID (8)

[12:22:03.316] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (1) != Token Chain Length (4)

[12:22:03.317] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (200)

[12:22:03.317] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[12:22:04.223] <TB3> INFO: Test took 29124ms.
[12:22:04.455] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:04.467] <TB3> INFO: dacScan step from 100 .. 103
[12:22:32.634] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:22:33.744] <TB3> INFO: Test took 29277ms.
[12:22:33.972] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:33.983] <TB3> INFO: dacScan step from 104 .. 107
[12:23:02.083] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:23:02.083] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:23:03.308] <TB3> INFO: Test took 29325ms.
[12:23:03.548] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:03.561] <TB3> INFO: dacScan step from 108 .. 111
[12:23:31.565] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:23:31.565] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:23:32.810] <TB3> INFO: Test took 29249ms.
[12:23:33.050] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:33.063] <TB3> INFO: dacScan step from 112 .. 115
[12:24:02.316] <TB3> INFO: Test took 29252ms.
[12:24:02.543] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:02.555] <TB3> INFO: dacScan step from 116 .. 119
[12:24:30.479] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (195) != TBM ID (8)

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

[12:24:30.479] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (196)

[12:24:31.724] <TB3> INFO: Test took 29169ms.
[12:24:31.958] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:31.971] <TB3> INFO: dacScan step from 120 .. 123
[12:25:01.185] <TB3> INFO: Test took 29214ms.
[12:25:01.426] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:01.440] <TB3> INFO: dacScan step from 124 .. 127
[12:25:30.712] <TB3> INFO: Test took 29272ms.
[12:25:30.949] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:30.961] <TB3> INFO: dacScan step from 128 .. 131
[12:26:00.070] <TB3> INFO: Test took 29109ms.
[12:26:00.308] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:00.324] <TB3> INFO: dacScan step from 132 .. 135
[12:26:29.679] <TB3> INFO: Test took 29355ms.
[12:26:29.927] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:29.943] <TB3> INFO: dacScan step from 136 .. 139
[12:26:59.248] <TB3> INFO: Test took 29304ms.
[12:26:59.491] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:59.504] <TB3> INFO: dacScan step from 140 .. 143
[12:27:28.702] <TB3> INFO: Test took 29198ms.
[12:27:28.919] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:28.931] <TB3> INFO: dacScan step from 144 .. 147
[12:27:58.031] <TB3> INFO: Test took 29100ms.
[12:27:58.276] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:58.288] <TB3> INFO: dacScan step from 148 .. 149
[12:28:13.032] <TB3> INFO: Test took 14743ms.
[12:28:13.145] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:13.152] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:14.601] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:16.114] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:17.511] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:19.018] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:20.497] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:21.885] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:23.292] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:24.692] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:26.144] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:27.658] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:29.131] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:30.630] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:31.968] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:33.404] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:34.845] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:28:36.367] <TB3> INFO: PixTestScurves::scurves() done
[12:28:36.367] <TB3> INFO: Vcal mean: 87.86 89.88 85.28 80.81 80.80 96.45 80.08 86.45 86.68 83.98 88.35 82.20 94.80 84.82 85.84 95.12
[12:28:36.367] <TB3> INFO: Vcal RMS: 5.39 5.06 5.33 4.97 4.39 5.10 4.57 6.00 5.36 5.27 6.15 4.51 5.99 4.60 5.31 5.33
[12:28:36.368] <TB3> INFO: PixTestScurves::fullTest() done, duration: 901 seconds
[12:28:36.447] <TB3> INFO: ######################################################################
[12:28:36.447] <TB3> INFO: PixTestTrim::doTest()
[12:28:36.447] <TB3> INFO: ######################################################################
[12:28:36.449] <TB3> INFO: ----------------------------------------------------------------------
[12:28:36.449] <TB3> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[12:28:36.449] <TB3> INFO: ----------------------------------------------------------------------
[12:28:36.543] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:28:36.543] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[12:28:36.552] <TB3> INFO: dacScan step from 0 .. 19
[12:28:51.600] <TB3> INFO: Test took 15048ms.
[12:28:51.623] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:51.623] <TB3> INFO: dacScan step from 20 .. 39
[12:29:06.693] <TB3> INFO: Test took 15070ms.
[12:29:06.722] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:06.722] <TB3> INFO: dacScan step from 40 .. 59
[12:29:21.856] <TB3> INFO: Test took 15134ms.
[12:29:21.882] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:21.882] <TB3> INFO: dacScan step from 60 .. 79
[12:29:36.956] <TB3> INFO: Test took 15074ms.
[12:29:36.981] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:36.981] <TB3> INFO: dacScan step from 80 .. 99
[12:29:52.456] <TB3> INFO: Test took 15475ms.
[12:29:52.530] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:52.540] <TB3> INFO: dacScan step from 100 .. 119
[12:30:10.662] <TB3> INFO: Test took 18122ms.
[12:30:10.896] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:10.945] <TB3> INFO: dacScan step from 120 .. 139
[12:30:29.430] <TB3> INFO: Test took 18485ms.
[12:30:29.585] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:29.616] <TB3> INFO: dacScan step from 140 .. 159
[12:30:44.725] <TB3> INFO: Test took 15109ms.
[12:30:44.800] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:06.479] <TB3> INFO: ROC 0 VthrComp = 91
[12:31:06.479] <TB3> INFO: ROC 1 VthrComp = 96
[12:31:06.479] <TB3> INFO: ROC 2 VthrComp = 91
[12:31:06.479] <TB3> INFO: ROC 3 VthrComp = 85
[12:31:06.479] <TB3> INFO: ROC 4 VthrComp = 86
[12:31:06.479] <TB3> INFO: ROC 5 VthrComp = 101
[12:31:06.479] <TB3> INFO: ROC 6 VthrComp = 86
[12:31:06.480] <TB3> INFO: ROC 7 VthrComp = 89
[12:31:06.480] <TB3> INFO: ROC 8 VthrComp = 92
[12:31:06.480] <TB3> INFO: ROC 9 VthrComp = 86
[12:31:06.480] <TB3> INFO: ROC 10 VthrComp = 91
[12:31:06.480] <TB3> INFO: ROC 11 VthrComp = 84
[12:31:06.480] <TB3> INFO: ROC 12 VthrComp = 99
[12:31:06.480] <TB3> INFO: ROC 13 VthrComp = 92
[12:31:06.480] <TB3> INFO: ROC 14 VthrComp = 85
[12:31:06.480] <TB3> INFO: ROC 15 VthrComp = 98
[12:31:06.480] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:31:06.481] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[12:31:06.490] <TB3> INFO: dacScan step from 0 .. 19
[12:31:21.542] <TB3> INFO: Test took 15052ms.
[12:31:21.563] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:21.563] <TB3> INFO: dacScan step from 20 .. 39
[12:31:36.811] <TB3> INFO: Test took 15247ms.
[12:31:36.854] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:36.859] <TB3> INFO: dacScan step from 40 .. 59
[12:31:55.737] <TB3> INFO: Test took 18878ms.
[12:31:55.890] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:55.929] <TB3> INFO: dacScan step from 60 .. 79
[12:32:16.050] <TB3> INFO: Test took 20122ms.
[12:32:16.222] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:16.278] <TB3> INFO: dacScan step from 80 .. 99
[12:32:35.282] <TB3> INFO: Test took 19004ms.
[12:32:35.445] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:35.506] <TB3> INFO: dacScan step from 100 .. 119
[12:32:54.337] <TB3> INFO: Test took 18831ms.
[12:32:54.510] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:54.568] <TB3> INFO: dacScan step from 120 .. 139
[12:33:14.820] <TB3> INFO: Test took 20252ms.
[12:33:14.998] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:15.053] <TB3> INFO: dacScan step from 140 .. 159
[12:33:34.654] <TB3> INFO: Test took 19601ms.
[12:33:34.813] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:59.952] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 58.6515 for pixel 10/3 mean/min/max = 45.696/32.7372/58.6548
[12:33:59.952] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 56.6799 for pixel 16/63 mean/min/max = 44.1504/31.4434/56.8575
[12:33:59.952] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 58.7843 for pixel 0/48 mean/min/max = 45.4167/32.0378/58.7956
[12:33:59.953] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 58.708 for pixel 1/74 mean/min/max = 45.351/31.8452/58.8569
[12:33:59.953] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 56.5832 for pixel 51/3 mean/min/max = 44.5189/32.4059/56.6318
[12:33:59.954] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 57.3133 for pixel 48/1 mean/min/max = 44.7381/31.9518/57.5245
[12:33:59.954] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 57.3456 for pixel 0/65 mean/min/max = 44.6176/31.7361/57.499
[12:33:59.955] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 60.8681 for pixel 0/69 mean/min/max = 46.4217/31.9548/60.8886
[12:33:59.955] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 60.0284 for pixel 3/6 mean/min/max = 46.3459/32.6065/60.0853
[12:33:59.955] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 59.7635 for pixel 17/78 mean/min/max = 46.1019/32.4195/59.7842
[12:33:59.955] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 61.1874 for pixel 11/72 mean/min/max = 46.382/31.4812/61.2827
[12:33:59.956] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 58.7006 for pixel 1/20 mean/min/max = 45.6335/32.2534/59.0135
[12:33:59.956] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 60.1239 for pixel 41/79 mean/min/max = 45.7469/31.3267/60.167
[12:33:59.956] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 57.1018 for pixel 20/5 mean/min/max = 44.6/31.8742/57.3259
[12:33:59.957] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 60.3633 for pixel 12/1 mean/min/max = 46.2209/31.9707/60.4711
[12:33:59.957] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 58.5354 for pixel 18/4 mean/min/max = 45.3375/32.0504/58.6246
[12:33:59.957] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:35:34.528] <TB3> INFO: Test took 94571ms.
[12:35:35.939] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:35:35.948] <TB3> INFO: dacScan step from 0 .. 19
[12:35:57.761] <TB3> INFO: Test took 21813ms.
[12:35:57.814] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:57.815] <TB3> INFO: dacScan step from 20 .. 39
[12:36:26.785] <TB3> INFO: Test took 28969ms.
[12:36:27.020] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:27.050] <TB3> INFO: dacScan step from 40 .. 59
[12:36:59.087] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:37:00.343] <TB3> INFO: Test took 33292ms.
[12:37:00.698] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:00.760] <TB3> INFO: dacScan step from 60 .. 79
[12:37:32.774] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:37:32.774] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:37:33.996] <TB3> INFO: Test took 33236ms.
[12:37:34.287] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:34.342] <TB3> INFO: dacScan step from 80 .. 99
[12:38:06.169] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (202) != TBM ID (8)

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

[12:38:06.169] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (203)

[12:38:07.445] <TB3> INFO: Test took 33103ms.
[12:38:07.751] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:07.805] <TB3> INFO: dacScan step from 100 .. 119
[12:38:39.567] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:38:39.567] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (203) != TBM ID (204)

[12:38:39.567] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[12:38:39.567] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[12:38:40.846] <TB3> INFO: Test took 33041ms.
[12:38:41.154] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:41.214] <TB3> INFO: dacScan step from 120 .. 139
[12:39:13.178] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:39:14.418] <TB3> INFO: Test took 33204ms.
[12:39:14.767] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:14.827] <TB3> INFO: dacScan step from 140 .. 159
[12:39:46.671] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:39:46.671] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (204) != TBM ID (205)

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

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

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

[12:39:47.924] <TB3> INFO: Test took 33097ms.
[12:39:48.195] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:48.248] <TB3> INFO: dacScan step from 160 .. 179
[12:40:20.525] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (206) != TBM ID (8)

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

[12:40:20.525] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (207)

[12:40:21.727] <TB3> INFO: Test took 33479ms.
[12:40:22.059] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:22.111] <TB3> INFO: dacScan step from 180 .. 199
[12:40:55.663] <TB3> INFO: Test took 33552ms.
[12:40:55.935] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:21.393] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 0.005423 .. 255.000000
[12:41:21.477] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[12:41:21.486] <TB3> INFO: dacScan step from 0 .. 19
[12:41:34.998] <TB3> INFO: Test took 13512ms.
[12:41:35.022] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:35.023] <TB3> INFO: dacScan step from 20 .. 39
[12:41:49.940] <TB3> INFO: Test took 14917ms.
[12:41:50.027] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:50.045] <TB3> INFO: dacScan step from 40 .. 59
[12:42:07.700] <TB3> INFO: Test took 17655ms.
[12:42:07.855] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:07.909] <TB3> INFO: dacScan step from 60 .. 79
[12:42:25.718] <TB3> INFO: Test took 17809ms.
[12:42:25.861] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:25.918] <TB3> INFO: dacScan step from 80 .. 99
[12:42:43.614] <TB3> INFO: Test took 17696ms.
[12:42:43.765] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:43.820] <TB3> INFO: dacScan step from 100 .. 119
[12:43:01.512] <TB3> INFO: Test took 17692ms.
[12:43:01.662] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:01.719] <TB3> INFO: dacScan step from 120 .. 139
[12:43:19.476] <TB3> INFO: Test took 17757ms.
[12:43:19.619] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:19.674] <TB3> INFO: dacScan step from 140 .. 159
[12:43:36.370] <TB3> INFO: Test took 16696ms.
[12:43:36.618] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:36.699] <TB3> INFO: dacScan step from 160 .. 179
[12:43:53.570] <TB3> INFO: Test took 16871ms.
[12:43:53.713] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:53.765] <TB3> INFO: dacScan step from 180 .. 199
[12:44:12.278] <TB3> INFO: Test took 18513ms.
[12:44:12.421] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:12.475] <TB3> INFO: dacScan step from 200 .. 219
[12:44:30.144] <TB3> INFO: Test took 17668ms.
[12:44:30.299] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:30.347] <TB3> INFO: dacScan step from 220 .. 239
[12:44:47.961] <TB3> INFO: Test took 17614ms.
[12:44:48.105] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:48.158] <TB3> INFO: dacScan step from 240 .. 255
[12:45:02.796] <TB3> INFO: Test took 14638ms.
[12:45:02.909] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:44.148] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 2.896701 .. 43.897206
[12:45:44.489] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 2 .. 53 (20) hits flags = 16 (plus default)
[12:45:44.518] <TB3> INFO: dacScan step from 2 .. 21
[12:45:58.004] <TB3> INFO: Test took 13485ms.
[12:45:58.076] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:58.076] <TB3> INFO: dacScan step from 22 .. 41
[12:46:13.767] <TB3> INFO: Test took 15691ms.
[12:46:14.060] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:14.161] <TB3> INFO: dacScan step from 42 .. 53
[12:46:25.832] <TB3> INFO: Test took 11671ms.
[12:46:25.921] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:41.711] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 2.896701 .. 40.035431
[12:46:41.786] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 2 .. 50 (20) hits flags = 16 (plus default)
[12:46:41.795] <TB3> INFO: dacScan step from 2 .. 21
[12:46:55.068] <TB3> INFO: Test took 13273ms.
[12:46:55.117] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:55.117] <TB3> INFO: dacScan step from 22 .. 41
[12:47:10.398] <TB3> INFO: Test took 15281ms.
[12:47:10.783] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:10.924] <TB3> INFO: dacScan step from 42 .. 50
[12:47:20.670] <TB3> INFO: Test took 9746ms.
[12:47:20.984] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:48.576] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 1.593059 .. 62.659979
[12:47:48.667] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 72 (20) hits flags = 16 (plus default)
[12:47:48.677] <TB3> INFO: dacScan step from 1 .. 20
[12:48:01.857] <TB3> INFO: Test took 13180ms.
[12:48:01.883] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:01.883] <TB3> INFO: dacScan step from 21 .. 40
[12:48:16.392] <TB3> INFO: Test took 14509ms.
[12:48:16.876] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:17.045] <TB3> INFO: dacScan step from 41 .. 60
[12:48:34.272] <TB3> INFO: Test took 17226ms.
[12:48:34.967] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:35.306] <TB3> INFO: dacScan step from 61 .. 72
[12:48:47.107] <TB3> INFO: Test took 11801ms.
[12:48:47.620] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:11.005] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:49:11.005] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[12:49:11.014] <TB3> INFO: dacScan step from 15 .. 34
[12:49:32.957] <TB3> INFO: Test took 21943ms.
[12:49:33.049] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:33.060] <TB3> INFO: dacScan step from 35 .. 54
[12:50:03.692] <TB3> INFO: Test took 30632ms.
[12:50:04.118] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:04.203] <TB3> INFO: dacScan step from 55 .. 55
[12:50:08.537] <TB3> INFO: Test took 4334ms.
[12:50:08.565] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:24.850] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:50:24.851] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:50:24.851] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:50:24.851] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:50:24.851] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:50:24.851] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:50:24.852] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:50:24.852] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:50:24.852] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:50:24.852] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:50:24.853] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:50:24.853] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:50:24.853] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:50:24.853] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:50:24.853] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:50:24.854] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:50:24.854] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C0.dat
[12:50:24.867] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C1.dat
[12:50:24.874] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C2.dat
[12:50:24.880] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C3.dat
[12:50:24.887] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C4.dat
[12:50:24.893] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C5.dat
[12:50:24.900] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C6.dat
[12:50:24.906] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C7.dat
[12:50:24.913] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C8.dat
[12:50:24.920] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C9.dat
[12:50:24.926] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C10.dat
[12:50:24.933] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C11.dat
[12:50:24.939] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C12.dat
[12:50:24.946] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C13.dat
[12:50:24.952] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C14.dat
[12:50:24.959] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//trimParameters35_C15.dat
[12:50:24.965] <TB3> INFO: PixTestTrim::trimTest() done
[12:50:24.965] <TB3> INFO: vtrim: 121 100 173 110 91 102 109 120 105 115 114 96 109 108 111 110
[12:50:24.965] <TB3> INFO: vthrcomp: 91 96 91 85 86 101 86 89 92 86 91 84 99 92 85 98
[12:50:24.965] <TB3> INFO: vcal mean: 35.02 35.00 34.96 34.99 35.00 35.01 35.01 34.62 35.04 35.04 35.04 35.05 35.04 35.01 35.06 35.07
[12:50:24.965] <TB3> INFO: vcal RMS: 1.15 1.01 1.52 1.27 1.11 1.03 0.96 1.29 1.14 1.20 1.06 1.17 1.06 1.01 1.08 1.16
[12:50:24.965] <TB3> INFO: bits mean: 9.83 10.22 11.65 10.16 9.36 9.96 9.84 9.47 9.91 9.73 9.78 9.95 9.76 10.29 9.85 9.71
[12:50:24.965] <TB3> INFO: bits RMS: 2.43 2.47 1.67 2.42 2.76 2.54 2.63 2.53 2.41 2.52 2.61 2.46 2.66 2.40 2.52 2.63
[12:50:24.973] <TB3> INFO: ----------------------------------------------------------------------
[12:50:24.973] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[12:50:24.973] <TB3> INFO: ----------------------------------------------------------------------
[12:50:24.976] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:50:24.986] <TB3> INFO: dacScan step from 0 .. 19
[12:50:46.962] <TB3> INFO: Test took 21976ms.
[12:50:46.999] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:46.999] <TB3> INFO: dacScan step from 20 .. 39
[12:51:08.216] <TB3> INFO: Test took 21217ms.
[12:51:08.253] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:08.253] <TB3> INFO: dacScan step from 40 .. 59
[12:51:30.906] <TB3> INFO: Test took 22653ms.
[12:51:30.942] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:30.942] <TB3> INFO: dacScan step from 60 .. 79
[12:51:53.246] <TB3> INFO: Test took 22304ms.
[12:51:53.281] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:53.282] <TB3> INFO: dacScan step from 80 .. 99
[12:52:15.635] <TB3> INFO: Test took 22353ms.
[12:52:15.688] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:15.690] <TB3> INFO: dacScan step from 100 .. 119
[12:52:43.467] <TB3> INFO: Test took 27777ms.
[12:52:43.678] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:43.704] <TB3> INFO: dacScan step from 120 .. 139
[12:53:15.041] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:53:15.041] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[12:53:15.996] <TB3> INFO: Test took 32292ms.
[12:53:16.323] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:16.378] <TB3> INFO: dacScan step from 140 .. 159
[12:53:48.253] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (73) != TBM ID (8)

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

[12:53:48.253] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (74)

[12:53:49.452] <TB3> INFO: Test took 33074ms.
[12:53:49.750] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:49.805] <TB3> INFO: dacScan step from 160 .. 179
[12:54:23.058] <TB3> INFO: Test took 33253ms.
[12:54:23.364] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:23.422] <TB3> INFO: dacScan step from 180 .. 199
[12:54:57.358] <TB3> INFO: Test took 33936ms.
[12:54:57.634] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:24.833] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 155 (20) hits flags = 16 (plus default)
[12:55:24.841] <TB3> INFO: dacScan step from 0 .. 19
[12:55:47.575] <TB3> INFO: Test took 22734ms.
[12:55:47.614] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:47.614] <TB3> INFO: dacScan step from 20 .. 39
[12:56:10.225] <TB3> INFO: Test took 22611ms.
[12:56:10.263] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:10.263] <TB3> INFO: dacScan step from 40 .. 59
[12:56:32.996] <TB3> INFO: Test took 22733ms.
[12:56:33.034] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:33.034] <TB3> INFO: dacScan step from 60 .. 79
[12:56:55.751] <TB3> INFO: Test took 22717ms.
[12:56:55.789] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:55.789] <TB3> INFO: dacScan step from 80 .. 99
[12:57:19.724] <TB3> INFO: Test took 23935ms.
[12:57:19.827] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:19.836] <TB3> INFO: dacScan step from 100 .. 119
[12:57:49.380] <TB3> INFO: Test took 29545ms.
[12:57:49.661] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:49.703] <TB3> INFO: dacScan step from 120 .. 139
[12:58:21.017] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:58:21.017] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (49) != TBM ID (50)

[12:58:21.017] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[12:58:21.017] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[12:58:21.017] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:58:22.096] <TB3> INFO: Test took 32393ms.
[12:58:22.536] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:22.607] <TB3> INFO: dacScan step from 140 .. 155
[12:58:48.380] <TB3> INFO: Test took 25773ms.
[12:58:48.659] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:14.721] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 148 (20) hits flags = 16 (plus default)
[12:59:14.730] <TB3> INFO: dacScan step from 0 .. 19
[12:59:37.140] <TB3> INFO: Test took 22410ms.
[12:59:37.176] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:37.192] <TB3> INFO: dacScan step from 20 .. 39
[12:59:58.507] <TB3> INFO: Test took 21315ms.
[12:59:58.543] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:58.543] <TB3> INFO: dacScan step from 40 .. 59
[13:00:21.426] <TB3> INFO: Test took 22883ms.
[13:00:21.464] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:21.464] <TB3> INFO: dacScan step from 60 .. 79
[13:00:44.178] <TB3> INFO: Test took 22714ms.
[13:00:44.221] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:44.221] <TB3> INFO: dacScan step from 80 .. 99
[13:01:08.550] <TB3> INFO: Test took 24329ms.
[13:01:08.746] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:08.773] <TB3> INFO: dacScan step from 100 .. 119
[13:01:39.372] <TB3> INFO: Test took 30599ms.
[13:01:40.588] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:40.846] <TB3> INFO: dacScan step from 120 .. 139
[13:02:11.817] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[13:02:11.817] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[13:02:12.917] <TB3> INFO: Test took 32071ms.
[13:02:13.279] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:13.348] <TB3> INFO: dacScan step from 140 .. 148
[13:02:29.162] <TB3> INFO: Test took 15814ms.
[13:02:30.043] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:18.973] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 147 (20) hits flags = 16 (plus default)
[13:03:18.982] <TB3> INFO: dacScan step from 0 .. 19
[13:03:41.107] <TB3> INFO: Test took 22124ms.
[13:03:41.246] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:41.246] <TB3> INFO: dacScan step from 20 .. 39
[13:04:07.023] <TB3> INFO: Test took 25777ms.
[13:04:07.161] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:07.161] <TB3> INFO: dacScan step from 40 .. 59
[13:04:29.576] <TB3> INFO: Test took 22415ms.
[13:04:29.618] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:29.618] <TB3> INFO: dacScan step from 60 .. 79
[13:04:52.016] <TB3> INFO: Test took 22398ms.
[13:04:52.058] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:52.058] <TB3> INFO: dacScan step from 80 .. 99
[13:05:15.928] <TB3> INFO: Test took 23870ms.
[13:05:16.034] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:16.043] <TB3> INFO: dacScan step from 100 .. 119
[13:05:46.746] <TB3> INFO: Test took 30703ms.
[13:05:47.020] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:47.062] <TB3> INFO: dacScan step from 120 .. 139
[13:06:17.910] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[13:06:17.910] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (165) != TBM ID (166)

[13:06:17.910] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[13:06:17.910] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[13:06:17.910] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[13:06:19.092] <TB3> INFO: Test took 32030ms.
[13:06:19.420] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:19.483] <TB3> INFO: dacScan step from 140 .. 147
[13:06:33.796] <TB3> INFO: Test took 14313ms.
[13:06:33.953] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:55.495] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 146 (20) hits flags = 16 (plus default)
[13:06:55.504] <TB3> INFO: dacScan step from 0 .. 19
[13:07:16.823] <TB3> INFO: Test took 21319ms.
[13:07:16.860] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:16.860] <TB3> INFO: dacScan step from 20 .. 39
[13:07:39.510] <TB3> INFO: Test took 22650ms.
[13:07:39.550] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:39.550] <TB3> INFO: dacScan step from 40 .. 59
[13:08:02.424] <TB3> INFO: Test took 22875ms.
[13:08:02.460] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:02.460] <TB3> INFO: dacScan step from 60 .. 79
[13:08:25.270] <TB3> INFO: Test took 22810ms.
[13:08:25.311] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:25.311] <TB3> INFO: dacScan step from 80 .. 99
[13:08:47.862] <TB3> INFO: Test took 22551ms.
[13:08:47.957] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:08:47.966] <TB3> INFO: dacScan step from 100 .. 119
[13:09:19.815] <TB3> INFO: Test took 31849ms.
[13:09:20.090] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:20.130] <TB3> INFO: dacScan step from 120 .. 139
[13:09:52.196] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (150) != TBM ID (8)

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

[13:09:52.196] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (151)

[13:09:53.481] <TB3> INFO: Test took 33351ms.
[13:09:53.780] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:09:53.832] <TB3> INFO: dacScan step from 140 .. 146
[13:10:07.267] <TB3> INFO: Test took 13435ms.
[13:10:07.379] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:30.088] <TB3> INFO: PixTestTrim::trimBitTest() done
[13:10:30.089] <TB3> INFO: PixTestTrim::doTest() done, duration: 2513 seconds
[13:10:30.827] <TB3> INFO: ######################################################################
[13:10:30.827] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[13:10:30.827] <TB3> INFO: ######################################################################
[13:10:34.118] <TB3> INFO: Test took 3290ms.
[13:10:34.136] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:37.678] <TB3> INFO: Test took 3345ms.
[13:10:37.753] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:41.265] <TB3> INFO: Test took 3499ms.
[13:10:41.332] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:10:41.339] <TB3> INFO: The DUT currently contains the following objects:
[13:10:41.339] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:41.339] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:41.339] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:41.339] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:41.339] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:41.339] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.450] <TB3> INFO: Test took 1111ms.
[13:10:42.451] <TB3> INFO: The DUT currently contains the following objects:
[13:10:42.451] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:42.451] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:42.451] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:42.451] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:42.451] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.451] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.452] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.452] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.452] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:42.452] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.559] <TB3> INFO: Test took 1107ms.
[13:10:43.562] <TB3> INFO: The DUT currently contains the following objects:
[13:10:43.562] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:43.562] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:43.562] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:43.563] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:43.563] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:43.563] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.670] <TB3> INFO: Test took 1107ms.
[13:10:44.670] <TB3> INFO: The DUT currently contains the following objects:
[13:10:44.670] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:44.670] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:44.670] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:44.670] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:44.670] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.670] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.670] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:44.671] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.780] <TB3> INFO: Test took 1109ms.
[13:10:45.781] <TB3> INFO: The DUT currently contains the following objects:
[13:10:45.781] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:45.781] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:45.781] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:45.781] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:45.782] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:45.782] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.890] <TB3> INFO: Test took 1107ms.
[13:10:46.894] <TB3> INFO: The DUT currently contains the following objects:
[13:10:46.894] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:46.894] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:46.894] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:46.894] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:46.894] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:46.894] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.002] <TB3> INFO: Test took 1108ms.
[13:10:48.003] <TB3> INFO: The DUT currently contains the following objects:
[13:10:48.003] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:48.003] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:48.003] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:48.004] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:48.004] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:48.004] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.113] <TB3> INFO: Test took 1109ms.
[13:10:49.115] <TB3> INFO: The DUT currently contains the following objects:
[13:10:49.115] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:49.115] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:49.115] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:49.115] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:49.115] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.115] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.115] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.115] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.115] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.115] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.115] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.115] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.116] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.116] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.116] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.116] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.116] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.116] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.116] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:49.116] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.224] <TB3> INFO: Test took 1108ms.
[13:10:50.226] <TB3> INFO: The DUT currently contains the following objects:
[13:10:50.226] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:50.226] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:50.226] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:50.226] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:50.226] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.226] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.226] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.226] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.226] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.226] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.226] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.226] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.226] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.226] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.227] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.227] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.227] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.227] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.227] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:50.227] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.336] <TB3> INFO: Test took 1109ms.
[13:10:51.337] <TB3> INFO: The DUT currently contains the following objects:
[13:10:51.337] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:51.337] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:51.337] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:51.337] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:51.337] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.337] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.337] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.337] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.337] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.337] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.337] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.337] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.338] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.338] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.338] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.338] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.338] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.338] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.338] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:51.338] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.445] <TB3> INFO: Test took 1107ms.
[13:10:52.446] <TB3> INFO: The DUT currently contains the following objects:
[13:10:52.446] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:52.446] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:52.447] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:52.447] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:52.447] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:52.447] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.556] <TB3> INFO: Test took 1109ms.
[13:10:53.557] <TB3> INFO: The DUT currently contains the following objects:
[13:10:53.557] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:53.557] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:53.558] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:53.558] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:53.558] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:53.558] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.665] <TB3> INFO: Test took 1107ms.
[13:10:54.667] <TB3> INFO: The DUT currently contains the following objects:
[13:10:54.667] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:54.667] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:54.667] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:54.667] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:54.667] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:54.667] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.776] <TB3> INFO: Test took 1109ms.
[13:10:55.777] <TB3> INFO: The DUT currently contains the following objects:
[13:10:55.777] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:55.777] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:55.777] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:55.777] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:55.777] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.777] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.777] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.777] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.777] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.777] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.777] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.777] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.777] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.777] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.778] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.778] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.778] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.778] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.778] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:55.778] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.886] <TB3> INFO: Test took 1108ms.
[13:10:56.887] <TB3> INFO: The DUT currently contains the following objects:
[13:10:56.887] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:56.887] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:56.887] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:56.887] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:56.887] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.887] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.888] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.888] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.888] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.888] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:56.888] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.997] <TB3> INFO: Test took 1109ms.
[13:10:57.998] <TB3> INFO: The DUT currently contains the following objects:
[13:10:57.998] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[13:10:57.998] <TB3> INFO: TBM Core alpha (0): 7 registers set
[13:10:57.998] <TB3> INFO: TBM Core beta (1): 7 registers set
[13:10:57.998] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:10:57.998] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.998] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.998] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.998] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.998] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.998] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.998] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.999] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.999] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.999] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.999] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.999] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.999] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.999] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.999] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:57.999] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:10:59.107] <TB3> INFO: Test took 1108ms.
[13:10:59.111] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:14:38.457] <TB3> INFO: Test took 219346ms.
[13:14:40.172] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:22.353] <TB3> INFO: Test took 222181ms.
[13:18:24.199] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.207] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.215] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.223] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:18:24.230] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[13:18:24.239] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.248] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.256] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.264] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.272] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.280] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.288] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.295] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.303] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.311] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:18:24.318] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[13:18:24.326] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[13:18:24.334] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[13:18:24.341] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.349] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.357] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.365] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:18:24.373] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:18:24.417] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C0.dat
[13:18:24.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C1.dat
[13:18:24.423] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C2.dat
[13:18:24.427] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C3.dat
[13:18:24.427] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C4.dat
[13:18:24.431] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C5.dat
[13:18:24.431] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C6.dat
[13:18:24.431] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C7.dat
[13:18:24.432] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C8.dat
[13:18:24.436] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C9.dat
[13:18:24.436] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C10.dat
[13:18:24.436] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C11.dat
[13:18:24.439] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C12.dat
[13:18:24.439] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C13.dat
[13:18:24.445] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C14.dat
[13:18:24.445] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//dacParameters35_C15.dat
[13:18:27.754] <TB3> INFO: Test took 3306ms.
[13:18:31.345] <TB3> INFO: Test took 3315ms.
[13:18:34.897] <TB3> INFO: Test took 3285ms.
[13:18:35.176] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:36.089] <TB3> INFO: Test took 913ms.
[13:18:36.091] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:37.192] <TB3> INFO: Test took 1101ms.
[13:18:37.194] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:38.296] <TB3> INFO: Test took 1102ms.
[13:18:38.298] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:39.400] <TB3> INFO: Test took 1102ms.
[13:18:39.402] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:40.504] <TB3> INFO: Test took 1102ms.
[13:18:40.506] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:41.614] <TB3> INFO: Test took 1108ms.
[13:18:41.617] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:42.724] <TB3> INFO: Test took 1107ms.
[13:18:42.728] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:43.829] <TB3> INFO: Test took 1101ms.
[13:18:43.832] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:44.934] <TB3> INFO: Test took 1102ms.
[13:18:44.937] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:46.039] <TB3> INFO: Test took 1102ms.
[13:18:46.041] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:47.145] <TB3> INFO: Test took 1104ms.
[13:18:47.148] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:48.251] <TB3> INFO: Test took 1103ms.
[13:18:48.254] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:49.357] <TB3> INFO: Test took 1103ms.
[13:18:49.359] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:50.463] <TB3> INFO: Test took 1104ms.
[13:18:50.465] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:51.567] <TB3> INFO: Test took 1102ms.
[13:18:51.569] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:52.671] <TB3> INFO: Test took 1102ms.
[13:18:52.673] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:53.784] <TB3> INFO: Test took 1111ms.
[13:18:53.788] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:54.889] <TB3> INFO: Test took 1102ms.
[13:18:54.892] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:55.994] <TB3> INFO: Test took 1102ms.
[13:18:55.997] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:57.098] <TB3> INFO: Test took 1102ms.
[13:18:57.100] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:58.202] <TB3> INFO: Test took 1102ms.
[13:18:58.205] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:59.307] <TB3> INFO: Test took 1102ms.
[13:18:59.310] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:00.412] <TB3> INFO: Test took 1102ms.
[13:19:00.414] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:01.516] <TB3> INFO: Test took 1102ms.
[13:19:01.519] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:02.623] <TB3> INFO: Test took 1104ms.
[13:19:02.625] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:03.729] <TB3> INFO: Test took 1104ms.
[13:19:03.733] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:04.835] <TB3> INFO: Test took 1102ms.
[13:19:04.838] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:05.940] <TB3> INFO: Test took 1102ms.
[13:19:05.942] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:07.044] <TB3> INFO: Test took 1102ms.
[13:19:07.046] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:08.148] <TB3> INFO: Test took 1102ms.
[13:19:08.150] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:09.254] <TB3> INFO: Test took 1104ms.
[13:19:09.256] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:19:10.357] <TB3> INFO: Test took 1101ms.
[13:19:10.893] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 520 seconds
[13:19:10.893] <TB3> INFO: PH scale (per ROC): 77 89 80 83 87 84 81 82 80 81 87 86 83 85 80 80
[13:19:10.893] <TB3> INFO: PH offset (per ROC): 157 148 159 145 147 155 147 171 153 156 155 176 174 149 164 160
[13:19:11.124] <TB3> INFO: ######################################################################
[13:19:11.124] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[13:19:11.124] <TB3> INFO: ######################################################################
[13:19:11.137] <TB3> INFO: scanning low vcal = 10
[13:19:14.987] <TB3> INFO: Test took 3850ms.
[13:19:14.991] <TB3> INFO: scanning low vcal = 20
[13:19:18.780] <TB3> INFO: Test took 3789ms.
[13:19:18.785] <TB3> INFO: scanning low vcal = 30
[13:19:22.592] <TB3> INFO: Test took 3807ms.
[13:19:22.600] <TB3> INFO: scanning low vcal = 40
[13:19:26.962] <TB3> INFO: Test took 4362ms.
[13:19:27.025] <TB3> INFO: scanning low vcal = 50
[13:19:31.252] <TB3> INFO: Test took 4227ms.
[13:19:31.314] <TB3> INFO: scanning low vcal = 60
[13:19:35.542] <TB3> INFO: Test took 4228ms.
[13:19:35.609] <TB3> INFO: scanning low vcal = 70
[13:19:40.028] <TB3> INFO: Test took 4418ms.
[13:19:40.105] <TB3> INFO: scanning low vcal = 80
[13:19:44.501] <TB3> INFO: Test took 4396ms.
[13:19:44.573] <TB3> INFO: scanning low vcal = 90
[13:19:48.954] <TB3> INFO: Test took 4381ms.
[13:19:49.025] <TB3> INFO: scanning low vcal = 100
[13:19:53.377] <TB3> INFO: Test took 4352ms.
[13:19:53.446] <TB3> INFO: scanning low vcal = 110
[13:19:57.819] <TB3> INFO: Test took 4374ms.
[13:19:57.883] <TB3> INFO: scanning low vcal = 120
[13:20:02.241] <TB3> INFO: Test took 4358ms.
[13:20:02.311] <TB3> INFO: scanning low vcal = 130
[13:20:06.660] <TB3> INFO: Test took 4349ms.
[13:20:06.719] <TB3> INFO: scanning low vcal = 140
[13:20:10.994] <TB3> INFO: Test took 4275ms.
[13:20:11.059] <TB3> INFO: scanning low vcal = 150
[13:20:15.460] <TB3> INFO: Test took 4401ms.
[13:20:15.532] <TB3> INFO: scanning low vcal = 160
[13:20:19.917] <TB3> INFO: Test took 4385ms.
[13:20:19.979] <TB3> INFO: scanning low vcal = 170
[13:20:24.354] <TB3> INFO: Test took 4375ms.
[13:20:24.422] <TB3> INFO: scanning low vcal = 180
[13:20:28.797] <TB3> INFO: Test took 4375ms.
[13:20:28.873] <TB3> INFO: scanning low vcal = 190
[13:20:33.362] <TB3> INFO: Test took 4489ms.
[13:20:33.438] <TB3> INFO: scanning low vcal = 200
[13:20:37.809] <TB3> INFO: Test took 4371ms.
[13:20:37.869] <TB3> INFO: scanning low vcal = 210
[13:20:42.242] <TB3> INFO: Test took 4373ms.
[13:20:42.308] <TB3> INFO: scanning low vcal = 220
[13:20:46.717] <TB3> INFO: Test took 4409ms.
[13:20:46.785] <TB3> INFO: scanning low vcal = 230
[13:20:51.203] <TB3> INFO: Test took 4418ms.
[13:20:51.277] <TB3> INFO: scanning low vcal = 240
[13:20:55.660] <TB3> INFO: Test took 4383ms.
[13:20:55.731] <TB3> INFO: scanning low vcal = 250
[13:21:00.083] <TB3> INFO: Test took 4352ms.
[13:21:00.146] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[13:21:04.505] <TB3> INFO: Test took 4359ms.
[13:21:04.574] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[13:21:08.956] <TB3> INFO: Test took 4382ms.
[13:21:09.016] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[13:21:13.355] <TB3> INFO: Test took 4339ms.
[13:21:13.414] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[13:21:17.781] <TB3> INFO: Test took 4367ms.
[13:21:17.841] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[13:21:22.234] <TB3> INFO: Test took 4393ms.
[13:21:22.872] <TB3> INFO: PixTestGainPedestal::measure() done
[13:21:54.322] <TB3> INFO: PixTestGainPedestal::fit() done
[13:21:54.322] <TB3> INFO: non-linearity mean: 0.958 0.958 0.954 0.953 0.958 0.964 0.955 0.956 0.954 0.961 0.958 0.963 0.958 0.954 0.951 0.965
[13:21:54.322] <TB3> INFO: non-linearity RMS: 0.007 0.006 0.005 0.007 0.005 0.005 0.005 0.005 0.005 0.005 0.006 0.005 0.005 0.006 0.006 0.005
[13:21:54.338] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[13:21:54.357] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[13:21:54.375] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[13:21:54.394] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[13:21:54.413] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[13:21:54.431] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[13:21:54.450] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[13:21:54.468] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[13:21:54.487] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[13:21:54.505] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[13:21:54.524] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[13:21:54.542] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[13:21:54.561] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[13:21:54.579] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[13:21:54.598] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[13:21:54.616] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2059_FullQualification_2015-08-18_11h20m_1439889632//002_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[13:21:54.634] <TB3> INFO: PixTestGainPedestal::doTest() done, duration: 163 seconds
[13:21:54.657] <TB3> INFO: enter test to run
[13:21:54.659] <TB3> INFO: test: exit no parameter change
[13:21:55.157] <TB3> QUIET: Connection to board 170 closed.
[13:21:55.237] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master