Test Date: 2015-08-06 10:09
Analysis date: 2016-05-26 00:50
Logfile
LogfileView
[11:38:05.870] <TB1> INFO: *** Welcome to pxar ***
[11:38:05.870] <TB1> INFO: *** Today: 2015/08/06
[11:38:05.870] <TB1> INFO: readRocDacs: /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C15.dat
[11:38:05.871] <TB1> INFO: readTbmDacs: /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//tbmParameters_C0b.dat
[11:38:05.871] <TB1> INFO: readMaskFile: /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//defaultMaskFile.dat
[11:38:05.871] <TB1> INFO: readTrimFile: /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters_C15.dat
[11:38:05.942] <TB1> INFO: clk: 4
[11:38:05.942] <TB1> INFO: ctr: 4
[11:38:05.942] <TB1> INFO: sda: 19
[11:38:05.942] <TB1> INFO: tin: 9
[11:38:05.942] <TB1> INFO: level: 15
[11:38:05.942] <TB1> INFO: triggerdelay: 0
[11:38:05.942] <TB1> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[11:38:05.942] <TB1> INFO: Log level: INFO
[11:38:05.958] <TB1> INFO: Found DTB DTB_WXBYFL
[11:38:05.969] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[11:38:05.972] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[11:38:05.976] <TB1> INFO: RPC call hashes of host and DTB match: 447413373
[11:38:07.512] <TB1> INFO: DUT info:
[11:38:07.512] <TB1> INFO: The DUT currently contains the following objects:
[11:38:07.512] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:38:07.512] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:38:07.512] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:38:07.512] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:38:07.512] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.512] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:07.914] <TB1> INFO: enter 'restricted' command line mode
[11:38:07.914] <TB1> INFO: enter test to run
[11:38:07.914] <TB1> INFO: test: pretest no parameter change
[11:38:07.914] <TB1> INFO: running: pretest
[11:38:07.923] <TB1> INFO: ######################################################################
[11:38:07.923] <TB1> INFO: PixTestPretest::doTest()
[11:38:07.923] <TB1> INFO: ######################################################################
[11:38:07.925] <TB1> INFO: ----------------------------------------------------------------------
[11:38:07.925] <TB1> INFO: PixTestPretest::programROC()
[11:38:07.925] <TB1> INFO: ----------------------------------------------------------------------
[11:38:25.945] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:38:25.945] <TB1> INFO: IA differences per ROC: 20.1 17.7 20.1 19.3 20.9 16.9 20.9 19.3 16.9 16.1 17.7 20.1 16.1 19.3 17.7 17.7
[11:38:26.035] <TB1> INFO: ----------------------------------------------------------------------
[11:38:26.035] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:38:26.035] <TB1> INFO: ----------------------------------------------------------------------
[11:38:45.636] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 385.1 mA = 24.0688 mA/ROC
[11:38:45.640] <TB1> INFO: ----------------------------------------------------------------------
[11:38:45.640] <TB1> INFO: PixTestPretest::findWorkingPixel()
[11:38:45.641] <TB1> INFO: ----------------------------------------------------------------------
[11:38:57.034] <TB1> INFO: Test took 11388ms.
[11:38:57.351] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:38:57.402] <TB1> INFO: ----------------------------------------------------------------------
[11:38:57.402] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[11:38:57.402] <TB1> INFO: ----------------------------------------------------------------------
[11:39:08.023] <TB1> INFO: Test took 10611ms.
[11:39:08.349] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[11:39:08.349] <TB1> INFO: CalDel: 116 146 172 159 147 143 144 153 137 143 157 156 143 149 164 144
[11:39:08.349] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[11:39:08.355] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C0.dat
[11:39:08.355] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C1.dat
[11:39:08.355] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C2.dat
[11:39:08.355] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C3.dat
[11:39:08.356] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C4.dat
[11:39:08.356] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C5.dat
[11:39:08.356] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C6.dat
[11:39:08.357] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C7.dat
[11:39:08.357] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C8.dat
[11:39:08.357] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C9.dat
[11:39:08.358] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C10.dat
[11:39:08.358] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C11.dat
[11:39:08.358] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C12.dat
[11:39:08.359] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C13.dat
[11:39:08.359] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C14.dat
[11:39:08.359] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C15.dat
[11:39:08.360] <TB1> INFO: PixTestPretest::doTest() done, duration: 60 seconds
[11:39:08.452] <TB1> INFO: enter test to run
[11:39:08.452] <TB1> INFO: test: fulltest no parameter change
[11:39:08.453] <TB1> INFO: running: fulltest
[11:39:08.453] <TB1> INFO: ######################################################################
[11:39:08.453] <TB1> INFO: PixTestFullTest::doTest()
[11:39:08.453] <TB1> INFO: ######################################################################
[11:39:08.454] <TB1> INFO: ######################################################################
[11:39:08.454] <TB1> INFO: PixTestAlive::doTest()
[11:39:08.454] <TB1> INFO: ######################################################################
[11:39:08.457] <TB1> INFO: ----------------------------------------------------------------------
[11:39:08.457] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:39:08.457] <TB1> INFO: ----------------------------------------------------------------------
[11:39:12.954] <TB1> INFO: Test took 4495ms.
[11:39:12.980] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:13.219] <TB1> INFO: PixTestAlive::aliveTest() done
[11:39:13.219] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[11:39:13.222] <TB1> INFO: ----------------------------------------------------------------------
[11:39:13.222] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:39:13.222] <TB1> INFO: ----------------------------------------------------------------------
[11:39:16.365] <TB1> INFO: Test took 3141ms.
[11:39:16.369] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:16.369] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:39:16.611] <TB1> INFO: PixTestAlive::maskTest() done
[11:39:16.611] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:39:16.613] <TB1> INFO: ----------------------------------------------------------------------
[11:39:16.613] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:39:16.613] <TB1> INFO: ----------------------------------------------------------------------
[11:39:21.358] <TB1> INFO: Test took 4742ms.
[11:39:21.387] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:21.630] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[11:39:21.630] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:39:21.630] <TB1> INFO: PixTestAlive::doTest() done, duration: 13 seconds
[11:39:21.640] <TB1> INFO: ######################################################################
[11:39:21.640] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:39:21.640] <TB1> INFO: ######################################################################
[11:39:21.645] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[11:39:21.659] <TB1> INFO: dacScan step from 0 .. 29
[11:39:45.688] <TB1> INFO: Test took 24028ms.
[11:39:45.723] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:45.723] <TB1> INFO: dacScan step from 30 .. 59
[11:40:14.160] <TB1> INFO: Test took 28437ms.
[11:40:14.304] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:14.326] <TB1> INFO: dacScan step from 60 .. 89
[11:40:55.852] <TB1> INFO: Test took 41525ms.
[11:40:56.152] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:56.229] <TB1> INFO: dacScan step from 90 .. 119
[11:41:37.271] <TB1> INFO: Test took 41042ms.
[11:41:37.575] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:37.661] <TB1> INFO: dacScan step from 120 .. 149
[11:42:33.119] <TB1> INFO: Test took 55458ms.
[11:42:33.304] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:57.914] <TB1> INFO: PixTestBBMap::doTest() done, duration: 216 seconds
[11:42:57.914] <TB1> INFO: number of dead bumps (per ROC): 15 2 0 0 0 0 0 0 0 0 0 3 1 4 0 77
[11:42:57.914] <TB1> INFO: separation cut (per ROC): 80 102 82 86 88 83 101 95 84 78 69 83 76 95 92 67
[11:42:57.991] <TB1> INFO: ######################################################################
[11:42:57.991] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50
[11:42:57.991] <TB1> INFO: ######################################################################
[11:42:57.991] <TB1> INFO: ----------------------------------------------------------------------
[11:42:57.991] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[11:42:57.991] <TB1> INFO: ----------------------------------------------------------------------
[11:42:57.991] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[11:42:57.999] <TB1> INFO: dacScan step from 0 .. 3
[11:43:24.548] <TB1> INFO: Test took 26549ms.
[11:43:24.577] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:24.577] <TB1> INFO: dacScan step from 4 .. 7
[11:43:50.435] <TB1> INFO: Test took 25858ms.
[11:43:50.466] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:50.466] <TB1> INFO: dacScan step from 8 .. 11
[11:44:15.798] <TB1> INFO: Test took 25332ms.
[11:44:15.828] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:15.828] <TB1> INFO: dacScan step from 12 .. 15
[11:44:42.457] <TB1> INFO: Test took 26629ms.
[11:44:42.488] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:42.488] <TB1> INFO: dacScan step from 16 .. 19
[11:45:08.227] <TB1> INFO: Test took 25739ms.
[11:45:08.261] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:08.261] <TB1> INFO: dacScan step from 20 .. 23
[11:45:33.788] <TB1> INFO: Test took 25527ms.
[11:45:33.818] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:33.818] <TB1> INFO: dacScan step from 24 .. 27
[11:46:00.244] <TB1> INFO: Test took 26426ms.
[11:46:00.272] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:00.272] <TB1> INFO: dacScan step from 28 .. 31
[11:46:27.140] <TB1> INFO: Test took 26868ms.
[11:46:27.172] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:27.172] <TB1> INFO: dacScan step from 32 .. 35
[11:46:52.626] <TB1> INFO: Test took 25454ms.
[11:46:52.658] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:52.658] <TB1> INFO: dacScan step from 36 .. 39
[11:47:18.791] <TB1> INFO: Test took 26133ms.
[11:47:18.819] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:18.819] <TB1> INFO: dacScan step from 40 .. 43
[11:47:45.971] <TB1> INFO: Test took 27152ms.
[11:47:45.998] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:45.999] <TB1> INFO: dacScan step from 44 .. 47
[11:48:12.354] <TB1> INFO: Test took 26355ms.
[11:48:12.389] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:12.389] <TB1> INFO: dacScan step from 48 .. 51
[11:48:38.341] <TB1> INFO: Test took 25952ms.
[11:48:38.368] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:38.368] <TB1> INFO: dacScan step from 52 .. 55
[11:49:04.149] <TB1> INFO: Test took 25781ms.
[11:49:04.179] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:04.179] <TB1> INFO: dacScan step from 56 .. 59
[11:49:29.525] <TB1> INFO: Test took 25346ms.
[11:49:29.556] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:29.556] <TB1> INFO: dacScan step from 60 .. 63
[11:49:54.806] <TB1> INFO: Test took 25250ms.
[11:49:54.841] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:54.842] <TB1> INFO: dacScan step from 64 .. 67
[11:50:20.981] <TB1> INFO: Test took 26139ms.
[11:50:21.023] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:21.024] <TB1> INFO: dacScan step from 68 .. 71
[11:50:48.631] <TB1> INFO: Test took 27607ms.
[11:50:48.689] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:48.691] <TB1> INFO: dacScan step from 72 .. 75
[11:51:17.603] <TB1> INFO: Test took 28912ms.
[11:51:17.677] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:17.679] <TB1> INFO: dacScan step from 76 .. 79
[11:51:49.253] <TB1> INFO: Test took 31574ms.
[11:51:49.348] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:49.352] <TB1> INFO: dacScan step from 80 .. 83
[11:52:25.225] <TB1> INFO: Test took 35873ms.
[11:52:25.371] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:25.381] <TB1> INFO: dacScan step from 84 .. 87
[11:53:35.743] <TB1> INFO: Test took 70362ms.
[11:53:35.944] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:35.956] <TB1> INFO: dacScan step from 88 .. 91
[11:54:24.317] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[11:54:24.446] <TB1> INFO: Test took 48490ms.
[11:54:24.643] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:24.651] <TB1> INFO: dacScan step from 92 .. 95
[11:55:11.246] <TB1> INFO: Test took 46595ms.
[11:55:11.465] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:11.475] <TB1> INFO: dacScan step from 96 .. 99
[11:55:54.739] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

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

[11:55:54.739] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[11:55:54.739] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[11:55:56.379] <TB1> INFO: Test took 44904ms.
[11:55:56.648] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:56.658] <TB1> INFO: dacScan step from 100 .. 103
[11:56:41.643] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[11:56:44.488] <TB1> INFO: Test took 47830ms.
[11:56:44.739] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:44.751] <TB1> INFO: dacScan step from 104 .. 107
[11:57:28.909] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[11:57:30.912] <TB1> INFO: Test took 46160ms.
[11:57:31.135] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:31.145] <TB1> INFO: dacScan step from 108 .. 111
[11:58:17.754] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 32 readouts!

[11:58:22.069] <TB1> INFO: Test took 50924ms.
[11:58:22.283] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:22.294] <TB1> INFO: dacScan step from 112 .. 115
[11:59:13.802] <TB1> INFO: Test took 51508ms.
[11:59:14.049] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:14.061] <TB1> INFO: dacScan step from 116 .. 119
[11:59:55.773] <TB1> INFO: Test took 41712ms.
[11:59:56.000] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:56.013] <TB1> INFO: dacScan step from 120 .. 123
[12:00:38.978] <TB1> INFO: Test took 42965ms.
[12:00:39.214] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:39.230] <TB1> INFO: dacScan step from 124 .. 127
[12:01:33.871] <TB1> INFO: Test took 54641ms.
[12:01:34.104] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:34.116] <TB1> INFO: dacScan step from 128 .. 131
[12:02:16.306] <TB1> INFO: Test took 42190ms.
[12:02:16.544] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:16.556] <TB1> INFO: dacScan step from 132 .. 135
[12:03:01.311] <TB1> INFO: Test took 44755ms.
[12:03:01.599] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:01.611] <TB1> INFO: dacScan step from 136 .. 139
[12:03:46.144] <TB1> INFO: Test took 44533ms.
[12:03:46.415] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:46.428] <TB1> INFO: dacScan step from 140 .. 143
[12:04:45.942] <TB1> INFO: Test took 59514ms.
[12:04:46.159] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:46.171] <TB1> INFO: dacScan step from 144 .. 147
[12:05:41.434] <TB1> INFO: Test took 55263ms.
[12:05:41.709] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:41.722] <TB1> INFO: dacScan step from 148 .. 149
[12:06:04.504] <TB1> INFO: Test took 22782ms.
[12:06:04.638] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:04.647] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:06.155] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:07.644] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:09.004] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:10.598] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:12.168] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:13.708] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:15.123] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:16.481] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:17.840] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:19.245] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:20.671] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:22.104] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:23.470] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:24.823] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:26.219] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:06:27.676] <TB1> INFO: PixTestScurves::scurves() done
[12:06:27.676] <TB1> INFO: Vcal mean: 93.23 92.87 81.57 86.53 85.81 79.46 89.98 97.93 89.18 71.37 72.72 81.69 83.34 85.89 83.56 87.21
[12:06:27.676] <TB1> INFO: Vcal RMS: 5.17 5.61 4.58 5.89 5.64 4.59 6.27 6.56 5.71 4.37 4.58 4.87 5.29 5.42 5.50 4.93
[12:06:27.676] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1409 seconds
[12:06:27.772] <TB1> INFO: ######################################################################
[12:06:27.772] <TB1> INFO: PixTestTrim::doTest()
[12:06:27.772] <TB1> INFO: ######################################################################
[12:06:27.773] <TB1> INFO: ----------------------------------------------------------------------
[12:06:27.774] <TB1> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[12:06:27.774] <TB1> INFO: ----------------------------------------------------------------------
[12:06:27.899] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:06:27.899] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[12:06:27.910] <TB1> INFO: dacScan step from 0 .. 19
[12:06:51.330] <TB1> INFO: Test took 23420ms.
[12:06:51.360] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:51.360] <TB1> INFO: dacScan step from 20 .. 39
[12:07:10.370] <TB1> INFO: Test took 19010ms.
[12:07:10.394] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:10.394] <TB1> INFO: dacScan step from 40 .. 59
[12:07:30.477] <TB1> INFO: Test took 20083ms.
[12:07:30.503] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:30.503] <TB1> INFO: dacScan step from 60 .. 79
[12:07:48.895] <TB1> INFO: Test took 18392ms.
[12:07:48.925] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:48.925] <TB1> INFO: dacScan step from 80 .. 99
[12:08:12.311] <TB1> INFO: Test took 23386ms.
[12:08:12.391] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:12.401] <TB1> INFO: dacScan step from 100 .. 119
[12:08:42.725] <TB1> INFO: Test took 30324ms.
[12:08:42.899] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:42.933] <TB1> INFO: dacScan step from 120 .. 139
[12:09:07.357] <TB1> INFO: Test took 24424ms.
[12:09:07.496] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:07.522] <TB1> INFO: dacScan step from 140 .. 159
[12:09:28.609] <TB1> INFO: Test took 21087ms.
[12:09:28.666] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:52.122] <TB1> INFO: ROC 0 VthrComp = 98
[12:09:52.122] <TB1> INFO: ROC 1 VthrComp = 96
[12:09:52.122] <TB1> INFO: ROC 2 VthrComp = 85
[12:09:52.123] <TB1> INFO: ROC 3 VthrComp = 90
[12:09:52.123] <TB1> INFO: ROC 4 VthrComp = 89
[12:09:52.123] <TB1> INFO: ROC 5 VthrComp = 82
[12:09:52.123] <TB1> INFO: ROC 6 VthrComp = 94
[12:09:52.123] <TB1> INFO: ROC 7 VthrComp = 99
[12:09:52.123] <TB1> INFO: ROC 8 VthrComp = 92
[12:09:52.123] <TB1> INFO: ROC 9 VthrComp = 77
[12:09:52.123] <TB1> INFO: ROC 10 VthrComp = 77
[12:09:52.124] <TB1> INFO: ROC 11 VthrComp = 85
[12:09:52.124] <TB1> INFO: ROC 12 VthrComp = 85
[12:09:52.124] <TB1> INFO: ROC 13 VthrComp = 91
[12:09:52.124] <TB1> INFO: ROC 14 VthrComp = 85
[12:09:52.124] <TB1> INFO: ROC 15 VthrComp = 93
[12:09:52.124] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:09:52.124] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[12:09:52.133] <TB1> INFO: dacScan step from 0 .. 19
[12:10:09.681] <TB1> INFO: Test took 17548ms.
[12:10:09.712] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:09.712] <TB1> INFO: dacScan step from 20 .. 39
[12:10:30.282] <TB1> INFO: Test took 20570ms.
[12:10:30.322] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:30.324] <TB1> INFO: dacScan step from 40 .. 59
[12:10:53.722] <TB1> INFO: Test took 23398ms.
[12:10:53.883] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:53.918] <TB1> INFO: dacScan step from 60 .. 79
[12:11:21.346] <TB1> INFO: Test took 27428ms.
[12:11:21.510] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:21.555] <TB1> INFO: dacScan step from 80 .. 99
[12:11:50.934] <TB1> INFO: Test took 29379ms.
[12:11:51.095] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:51.139] <TB1> INFO: dacScan step from 100 .. 119
[12:12:31.436] <TB1> INFO: Test took 40297ms.
[12:12:31.600] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:31.655] <TB1> INFO: dacScan step from 120 .. 139
[12:13:01.693] <TB1> INFO: Test took 30038ms.
[12:13:01.866] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:01.914] <TB1> INFO: dacScan step from 140 .. 159
[12:13:29.089] <TB1> INFO: Test took 27175ms.
[12:13:29.263] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:53.621] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 58.0313 for pixel 49/9 mean/min/max = 45.3654/32.6423/58.0885
[12:13:53.621] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 58.9504 for pixel 0/4 mean/min/max = 45.7265/32.3313/59.1218
[12:13:53.622] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 57.7515 for pixel 51/4 mean/min/max = 44.883/31.7778/57.9881
[12:13:53.622] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 59.6778 for pixel 4/17 mean/min/max = 46.1588/32.579/59.7386
[12:13:53.622] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 59.6906 for pixel 9/79 mean/min/max = 45.756/31.7468/59.7651
[12:13:53.622] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 58.1903 for pixel 0/33 mean/min/max = 45.8322/32.8608/58.8036
[12:13:53.623] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 60.8045 for pixel 0/73 mean/min/max = 46.4104/31.5666/61.2542
[12:13:53.623] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 61.11 for pixel 2/78 mean/min/max = 46.2311/31.1503/61.312
[12:13:53.623] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 60.154 for pixel 3/5 mean/min/max = 46.404/32.6502/60.1579
[12:13:53.623] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 56.7023 for pixel 4/32 mean/min/max = 45.9448/35.1584/56.7312
[12:13:53.623] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 58.597 for pixel 6/0 mean/min/max = 46.4691/34.2681/58.6701
[12:13:53.624] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 58.1378 for pixel 7/79 mean/min/max = 45.1836/32.2023/58.1649
[12:13:53.624] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 60.3082 for pixel 23/77 mean/min/max = 46.0927/31.8673/60.3181
[12:13:53.624] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 59.2414 for pixel 20/8 mean/min/max = 45.752/32.2421/59.262
[12:13:53.624] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 59.5659 for pixel 15/7 mean/min/max = 45.9072/31.8912/59.9231
[12:13:53.625] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 57.4628 for pixel 28/3 mean/min/max = 44.6127/31.7146/57.5108
[12:13:53.625] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:16:10.778] <TB1> INFO: Test took 137153ms.
[12:16:12.215] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:16:12.224] <TB1> INFO: dacScan step from 0 .. 19
[12:16:50.266] <TB1> INFO: Test took 38042ms.
[12:16:50.321] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:50.323] <TB1> INFO: dacScan step from 20 .. 39
[12:17:31.970] <TB1> INFO: Test took 41647ms.
[12:17:32.241] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:32.302] <TB1> INFO: dacScan step from 40 .. 59
[12:18:30.530] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:18:32.671] <TB1> INFO: Test took 60369ms.
[12:18:32.964] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:33.013] <TB1> INFO: dacScan step from 60 .. 79
[12:19:21.102] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[12:19:23.549] <TB1> INFO: Test took 50536ms.
[12:19:23.857] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:23.918] <TB1> INFO: dacScan step from 80 .. 99
[12:20:11.843] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:20:11.843] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (198) != TBM ID (199)

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

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

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

[12:20:13.816] <TB1> INFO: Test took 49898ms.
[12:20:14.125] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:14.172] <TB1> INFO: dacScan step from 100 .. 119
[12:21:07.770] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (198) != TBM ID (0)

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

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

[12:21:10.621] <TB1> INFO: Test took 56449ms.
[12:21:10.908] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:10.958] <TB1> INFO: dacScan step from 120 .. 139
[12:22:06.218] <TB1> INFO: Test took 55260ms.
[12:22:06.492] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:06.546] <TB1> INFO: dacScan step from 140 .. 159
[12:23:24.252] <TB1> INFO: Test took 77706ms.
[12:23:24.559] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:24.658] <TB1> INFO: dacScan step from 160 .. 179
[12:24:33.062] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:24:36.069] <TB1> INFO: Test took 71411ms.
[12:24:36.341] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:36.397] <TB1> INFO: dacScan step from 180 .. 199
[12:25:24.602] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:25:26.269] <TB1> INFO: Test took 49872ms.
[12:25:26.580] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:52.331] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.058289 .. 255.000000
[12:25:52.405] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[12:25:52.413] <TB1> INFO: dacScan step from 0 .. 19
[12:26:09.855] <TB1> INFO: Test took 17442ms.
[12:26:09.882] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:09.882] <TB1> INFO: dacScan step from 20 .. 39
[12:26:28.960] <TB1> INFO: Test took 19078ms.
[12:26:29.040] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:29.058] <TB1> INFO: dacScan step from 40 .. 59
[12:26:55.295] <TB1> INFO: Test took 26237ms.
[12:26:55.442] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:55.489] <TB1> INFO: dacScan step from 60 .. 79
[12:27:32.746] <TB1> INFO: Test took 37256ms.
[12:27:32.933] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:32.990] <TB1> INFO: dacScan step from 80 .. 99
[12:27:57.760] <TB1> INFO: Test took 24770ms.
[12:27:57.939] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:57.994] <TB1> INFO: dacScan step from 100 .. 119
[12:28:22.939] <TB1> INFO: Test took 24945ms.
[12:28:23.105] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:23.158] <TB1> INFO: dacScan step from 120 .. 139
[12:29:00.657] <TB1> INFO: Test took 37499ms.
[12:29:00.813] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:00.864] <TB1> INFO: dacScan step from 140 .. 159
[12:29:24.290] <TB1> INFO: Test took 23426ms.
[12:29:24.438] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:24.488] <TB1> INFO: dacScan step from 160 .. 179
[12:30:03.776] <TB1> INFO: Test took 39288ms.
[12:30:03.916] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:03.963] <TB1> INFO: dacScan step from 180 .. 199
[12:30:37.910] <TB1> INFO: Test took 33947ms.
[12:30:38.080] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:38.204] <TB1> INFO: dacScan step from 200 .. 219
[12:31:04.184] <TB1> INFO: Test took 25980ms.
[12:31:04.335] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:04.383] <TB1> INFO: dacScan step from 220 .. 239
[12:31:29.132] <TB1> INFO: Test took 24749ms.
[12:31:29.296] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:29.377] <TB1> INFO: dacScan step from 240 .. 255
[12:32:02.234] <TB1> INFO: Test took 32857ms.
[12:32:02.371] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:34.686] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 14.500000 .. 45.117610
[12:32:34.764] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 4 .. 55 (20) hits flags = 16 (plus default)
[12:32:34.772] <TB1> INFO: dacScan step from 4 .. 23
[12:32:52.499] <TB1> INFO: Test took 17727ms.
[12:32:52.522] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:52.522] <TB1> INFO: dacScan step from 24 .. 43
[12:33:20.806] <TB1> INFO: Test took 28284ms.
[12:33:20.940] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:20.965] <TB1> INFO: dacScan step from 44 .. 55
[12:33:37.864] <TB1> INFO: Test took 16899ms.
[12:33:37.960] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:55.788] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 18.499948 .. 43.500019
[12:33:55.874] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 8 .. 53 (20) hits flags = 16 (plus default)
[12:33:55.882] <TB1> INFO: dacScan step from 8 .. 27
[12:34:19.946] <TB1> INFO: Test took 24064ms.
[12:34:19.967] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:19.967] <TB1> INFO: dacScan step from 28 .. 47
[12:34:42.332] <TB1> INFO: Test took 22365ms.
[12:34:42.462] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:42.502] <TB1> INFO: dacScan step from 48 .. 53
[12:34:56.306] <TB1> INFO: Test took 13804ms.
[12:34:56.352] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:12.090] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 1.812465 .. 41.206130
[12:35:12.172] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 51 (20) hits flags = 16 (plus default)
[12:35:12.180] <TB1> INFO: dacScan step from 1 .. 20
[12:35:28.641] <TB1> INFO: Test took 16461ms.
[12:35:28.669] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:28.669] <TB1> INFO: dacScan step from 21 .. 40
[12:35:47.790] <TB1> INFO: Test took 19120ms.
[12:35:47.885] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:47.904] <TB1> INFO: dacScan step from 41 .. 51
[12:36:09.553] <TB1> INFO: Test took 21648ms.
[12:36:09.631] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:24.651] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:36:24.651] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[12:36:24.659] <TB1> INFO: dacScan step from 15 .. 34
[12:36:56.192] <TB1> INFO: Test took 31533ms.
[12:36:56.266] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:56.276] <TB1> INFO: dacScan step from 35 .. 54
[12:37:41.344] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:37:42.852] <TB1> INFO: Test took 46576ms.
[12:37:43.159] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:43.207] <TB1> INFO: dacScan step from 55 .. 55
[12:37:48.612] <TB1> INFO: Test took 5405ms.
[12:37:48.636] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:02.143] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:38:02.143] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:38:02.143] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:38:02.143] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:38:02.144] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:38:02.144] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:38:02.144] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:38:02.144] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:38:02.145] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:38:02.145] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:38:02.145] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:38:02.145] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:38:02.145] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:38:02.146] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:38:02.146] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:38:02.146] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:38:02.146] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C0.dat
[12:38:02.153] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C1.dat
[12:38:02.162] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C2.dat
[12:38:02.168] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C3.dat
[12:38:02.176] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C4.dat
[12:38:02.182] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C5.dat
[12:38:02.188] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C6.dat
[12:38:02.194] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C7.dat
[12:38:02.200] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C8.dat
[12:38:02.209] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C9.dat
[12:38:02.217] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C10.dat
[12:38:02.225] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C11.dat
[12:38:02.231] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C12.dat
[12:38:02.237] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C13.dat
[12:38:02.246] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C14.dat
[12:38:02.252] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C15.dat
[12:38:02.260] <TB1> INFO: PixTestTrim::trimTest() done
[12:38:02.260] <TB1> INFO: vtrim: 112 100 85 105 95 89 108 121 105 99 103 105 118 122 109 117
[12:38:02.260] <TB1> INFO: vthrcomp: 98 96 85 90 89 82 94 99 92 77 77 85 85 91 85 93
[12:38:02.260] <TB1> INFO: vcal mean: 35.03 35.03 35.01 35.00 35.03 35.04 35.03 35.03 35.00 35.05 35.05 35.05 35.04 35.04 34.98 35.03
[12:38:02.260] <TB1> INFO: vcal RMS: 1.04 1.15 1.04 1.23 0.99 1.02 1.01 1.13 1.03 0.86 1.04 1.05 1.02 1.01 1.06 1.02
[12:38:02.260] <TB1> INFO: bits mean: 9.97 9.49 9.64 9.60 9.63 9.62 9.12 9.90 9.52 9.01 9.48 9.71 10.04 9.98 9.94 10.38
[12:38:02.260] <TB1> INFO: bits RMS: 2.41 2.66 2.68 2.51 2.68 2.57 2.88 2.59 2.55 2.41 2.32 2.58 2.39 2.49 2.47 2.38
[12:38:02.270] <TB1> INFO: ----------------------------------------------------------------------
[12:38:02.270] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[12:38:02.270] <TB1> INFO: ----------------------------------------------------------------------
[12:38:02.274] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:38:02.288] <TB1> INFO: dacScan step from 0 .. 19
[12:38:30.849] <TB1> INFO: Test took 28561ms.
[12:38:30.888] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:30.888] <TB1> INFO: dacScan step from 20 .. 39
[12:39:00.656] <TB1> INFO: Test took 29768ms.
[12:39:00.702] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:00.702] <TB1> INFO: dacScan step from 40 .. 59
[12:39:32.181] <TB1> INFO: Test took 31479ms.
[12:39:32.224] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:32.224] <TB1> INFO: dacScan step from 60 .. 79
[12:40:04.145] <TB1> INFO: Test took 31921ms.
[12:40:04.188] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:04.188] <TB1> INFO: dacScan step from 80 .. 99
[12:40:44.144] <TB1> INFO: Test took 39956ms.
[12:40:44.213] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:44.217] <TB1> INFO: dacScan step from 100 .. 119
[12:41:38.539] <TB1> INFO: Test took 54322ms.
[12:41:38.770] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:38.802] <TB1> INFO: dacScan step from 120 .. 139
[12:42:23.774] <TB1> INFO: Test took 44972ms.
[12:42:24.062] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:24.117] <TB1> INFO: dacScan step from 140 .. 159
[12:43:11.193] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (69) != TBM ID (0)

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

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

[12:43:13.800] <TB1> INFO: Test took 49683ms.
[12:43:14.084] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:14.141] <TB1> INFO: dacScan step from 160 .. 179
[12:44:19.522] <TB1> INFO: Test took 65381ms.
[12:44:19.816] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:19.867] <TB1> INFO: dacScan step from 180 .. 199
[12:45:17.050] <TB1> INFO: Test took 57183ms.
[12:45:17.358] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:44.931] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 164 (20) hits flags = 16 (plus default)
[12:45:44.940] <TB1> INFO: dacScan step from 0 .. 19
[12:46:15.722] <TB1> INFO: Test took 30782ms.
[12:46:15.759] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:15.759] <TB1> INFO: dacScan step from 20 .. 39
[12:46:59.225] <TB1> INFO: Test took 43466ms.
[12:46:59.264] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:59.264] <TB1> INFO: dacScan step from 40 .. 59
[12:47:29.951] <TB1> INFO: Test took 30687ms.
[12:47:29.992] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:29.992] <TB1> INFO: dacScan step from 60 .. 79
[12:48:01.343] <TB1> INFO: Test took 31351ms.
[12:48:01.392] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:01.392] <TB1> INFO: dacScan step from 80 .. 99
[12:48:40.019] <TB1> INFO: Test took 38627ms.
[12:48:40.142] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:40.162] <TB1> INFO: dacScan step from 100 .. 119
[12:49:37.250] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (200) != TBM ID (0)

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

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

[12:49:38.132] <TB1> INFO: Test took 57970ms.
[12:49:38.399] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:38.443] <TB1> INFO: dacScan step from 120 .. 139
[12:50:26.698] <TB1> INFO: Test took 48255ms.
[12:50:27.029] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:50:27.082] <TB1> INFO: dacScan step from 140 .. 159
[12:51:14.226] <TB1> INFO: Test took 47143ms.
[12:51:14.555] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:14.612] <TB1> INFO: dacScan step from 160 .. 164
[12:51:28.910] <TB1> INFO: Test took 14298ms.
[12:51:28.998] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:53.934] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 153 (20) hits flags = 16 (plus default)
[12:51:53.942] <TB1> INFO: dacScan step from 0 .. 19
[12:52:39.496] <TB1> INFO: Test took 45554ms.
[12:52:39.532] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:52:39.532] <TB1> INFO: dacScan step from 20 .. 39
[12:53:28.497] <TB1> INFO: Test took 48965ms.
[12:53:28.534] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:28.534] <TB1> INFO: dacScan step from 40 .. 59
[12:54:07.271] <TB1> INFO: Test took 38737ms.
[12:54:07.310] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:07.310] <TB1> INFO: dacScan step from 60 .. 79
[12:54:35.613] <TB1> INFO: Test took 28303ms.
[12:54:35.661] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:54:35.661] <TB1> INFO: dacScan step from 80 .. 99
[12:55:09.001] <TB1> INFO: Test took 33340ms.
[12:55:09.149] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:09.164] <TB1> INFO: dacScan step from 100 .. 119
[12:55:50.908] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:55:50.908] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (200) != TBM ID (201)

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

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

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

[12:55:51.484] <TB1> INFO: Test took 42319ms.
[12:55:51.811] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:55:51.855] <TB1> INFO: dacScan step from 120 .. 139
[12:56:56.569] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (252) != TBM ID (0)

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

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

[12:56:58.644] <TB1> INFO: Test took 66789ms.
[12:56:58.926] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:58.985] <TB1> INFO: dacScan step from 140 .. 153
[12:57:41.459] <TB1> INFO: Test took 42474ms.
[12:57:41.737] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:03.926] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 153 (20) hits flags = 16 (plus default)
[12:58:03.934] <TB1> INFO: dacScan step from 0 .. 19
[12:58:40.426] <TB1> INFO: Test took 36492ms.
[12:58:40.465] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:40.465] <TB1> INFO: dacScan step from 20 .. 39
[12:59:07.129] <TB1> INFO: Test took 26664ms.
[12:59:07.166] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:07.166] <TB1> INFO: dacScan step from 40 .. 59
[12:59:33.977] <TB1> INFO: Test took 26811ms.
[12:59:34.016] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:59:34.016] <TB1> INFO: dacScan step from 60 .. 79
[13:00:00.645] <TB1> INFO: Test took 26629ms.
[13:00:00.683] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:00.683] <TB1> INFO: dacScan step from 80 .. 99
[13:00:30.714] <TB1> INFO: Test took 30031ms.
[13:00:30.851] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:00:30.864] <TB1> INFO: dacScan step from 100 .. 119
[13:01:10.235] <TB1> INFO: Test took 39370ms.
[13:01:10.499] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:10.551] <TB1> INFO: dacScan step from 120 .. 139
[13:01:50.568] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[13:01:50.568] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (248) != TBM ID (249)

[13:01:50.568] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[13:01:50.568] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[13:01:52.465] <TB1> INFO: Test took 41914ms.
[13:01:52.828] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:01:52.883] <TB1> INFO: dacScan step from 140 .. 153
[13:02:25.896] <TB1> INFO: Test took 33013ms.
[13:02:26.084] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:02:49.334] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 152 (20) hits flags = 16 (plus default)
[13:02:49.342] <TB1> INFO: dacScan step from 0 .. 19
[13:03:26.891] <TB1> INFO: Test took 37549ms.
[13:03:26.944] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:26.944] <TB1> INFO: dacScan step from 20 .. 39
[13:03:53.770] <TB1> INFO: Test took 26826ms.
[13:03:53.813] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:03:53.813] <TB1> INFO: dacScan step from 40 .. 59
[13:04:20.391] <TB1> INFO: Test took 26577ms.
[13:04:20.433] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:20.433] <TB1> INFO: dacScan step from 60 .. 79
[13:04:47.061] <TB1> INFO: Test took 26627ms.
[13:04:47.100] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:04:47.101] <TB1> INFO: dacScan step from 80 .. 99
[13:05:17.178] <TB1> INFO: Test took 30077ms.
[13:05:17.304] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:17.317] <TB1> INFO: dacScan step from 100 .. 119
[13:05:55.551] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (29) != TBM ID (0)

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

[13:05:55.551] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (30)

[13:05:56.225] <TB1> INFO: Test took 38908ms.
[13:05:56.479] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:05:56.522] <TB1> INFO: dacScan step from 120 .. 139
[13:06:36.035] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[13:06:37.951] <TB1> INFO: Test took 41428ms.
[13:06:38.216] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:06:38.272] <TB1> INFO: dacScan step from 140 .. 152
[13:07:05.732] <TB1> INFO: Test took 27460ms.
[13:07:05.914] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:31.131] <TB1> INFO: PixTestTrim::trimBitTest() done
[13:07:31.132] <TB1> INFO: PixTestTrim::doTest() done, duration: 3663 seconds
[13:07:31.797] <TB1> INFO: ######################################################################
[13:07:31.797] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[13:07:31.797] <TB1> INFO: ######################################################################
[13:07:35.539] <TB1> INFO: Test took 3739ms.
[13:07:35.566] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:39.581] <TB1> INFO: Test took 3816ms.
[13:07:39.654] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:43.655] <TB1> INFO: Test took 3985ms.
[13:07:43.755] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:07:43.765] <TB1> INFO: The DUT currently contains the following objects:
[13:07:43.765] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:43.765] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:43.765] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:43.765] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:43.765] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:43.765] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.888] <TB1> INFO: Test took 1123ms.
[13:07:44.889] <TB1> INFO: The DUT currently contains the following objects:
[13:07:44.889] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:44.889] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:44.889] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:44.889] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:44.889] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.889] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:44.890] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.031] <TB1> INFO: Test took 1141ms.
[13:07:46.033] <TB1> INFO: The DUT currently contains the following objects:
[13:07:46.033] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:46.033] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:46.033] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:46.033] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:46.033] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:46.033] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.172] <TB1> INFO: Test took 1139ms.
[13:07:47.173] <TB1> INFO: The DUT currently contains the following objects:
[13:07:47.173] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:47.173] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:47.173] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:47.173] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:47.173] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.173] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.173] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.173] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.173] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.173] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:47.174] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.296] <TB1> INFO: Test took 1122ms.
[13:07:48.298] <TB1> INFO: The DUT currently contains the following objects:
[13:07:48.298] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:48.298] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:48.298] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:48.298] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:48.298] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:48.298] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.437] <TB1> INFO: Test took 1139ms.
[13:07:49.439] <TB1> INFO: The DUT currently contains the following objects:
[13:07:49.439] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:49.439] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:49.439] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:49.439] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:49.439] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:49.439] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.564] <TB1> INFO: Test took 1125ms.
[13:07:50.565] <TB1> INFO: The DUT currently contains the following objects:
[13:07:50.565] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:50.565] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:50.565] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:50.565] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:50.565] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.565] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.565] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.565] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.565] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.565] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:50.566] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.721] <TB1> INFO: Test took 1155ms.
[13:07:51.722] <TB1> INFO: The DUT currently contains the following objects:
[13:07:51.722] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:51.722] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:51.722] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:51.722] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:51.722] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.722] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.722] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.722] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.722] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.722] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.722] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.722] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.723] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.723] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.723] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.723] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.723] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.723] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.723] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:51.723] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.846] <TB1> INFO: Test took 1123ms.
[13:07:52.847] <TB1> INFO: The DUT currently contains the following objects:
[13:07:52.847] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:52.847] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:52.847] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:52.847] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:52.847] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:52.848] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.973] <TB1> INFO: Test took 1125ms.
[13:07:53.975] <TB1> INFO: The DUT currently contains the following objects:
[13:07:53.975] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:53.975] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:53.975] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:53.975] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:53.975] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:53.975] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.098] <TB1> INFO: Test took 1123ms.
[13:07:55.100] <TB1> INFO: The DUT currently contains the following objects:
[13:07:55.100] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:55.100] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:55.100] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:55.100] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:55.100] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.100] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.100] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.100] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.100] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.100] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.100] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.100] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.100] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.100] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.101] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.101] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.101] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.101] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.101] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:55.101] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.226] <TB1> INFO: Test took 1125ms.
[13:07:56.228] <TB1> INFO: The DUT currently contains the following objects:
[13:07:56.228] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:56.228] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:56.228] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:56.228] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:56.228] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:56.229] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.368] <TB1> INFO: Test took 1139ms.
[13:07:57.369] <TB1> INFO: The DUT currently contains the following objects:
[13:07:57.369] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:57.369] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:57.369] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:57.369] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:57.369] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.369] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.369] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.369] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.369] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.369] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.369] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.370] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.370] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.370] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.370] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.370] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.370] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.370] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.370] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:57.370] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.526] <TB1> INFO: Test took 1156ms.
[13:07:58.528] <TB1> INFO: The DUT currently contains the following objects:
[13:07:58.528] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:58.528] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:58.528] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:58.528] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:58.528] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.528] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.528] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.528] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.528] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.528] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.528] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.528] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.528] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.529] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.529] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.529] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.529] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.529] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.529] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:58.529] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.651] <TB1> INFO: Test took 1122ms.
[13:07:59.652] <TB1> INFO: The DUT currently contains the following objects:
[13:07:59.653] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:07:59.653] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:07:59.653] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:07:59.653] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:07:59.653] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.653] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:07:59.654] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.792] <TB1> INFO: Test took 1138ms.
[13:08:00.793] <TB1> INFO: The DUT currently contains the following objects:
[13:08:00.793] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:08:00.793] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:08:00.793] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:08:00.793] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[13:08:00.793] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.793] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.793] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.793] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.793] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.793] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.793] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.793] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.793] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.793] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.794] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.794] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.794] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.794] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.794] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:00.794] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[13:08:01.917] <TB1> INFO: Test took 1123ms.
[13:08:01.922] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:12:46.496] <TB1> INFO: Test took 284574ms.
[13:12:48.544] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:31.559] <TB1> INFO: Test took 283015ms.
[13:17:33.306] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.313] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.320] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.326] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.333] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.339] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.346] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.353] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.359] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.366] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.373] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.382] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.391] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.400] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.406] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.413] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[13:17:33.468] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C0.dat
[13:17:33.468] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C1.dat
[13:17:33.469] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C2.dat
[13:17:33.469] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C3.dat
[13:17:33.469] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C4.dat
[13:17:33.469] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C5.dat
[13:17:33.469] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C6.dat
[13:17:33.470] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C7.dat
[13:17:33.470] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C8.dat
[13:17:33.470] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C9.dat
[13:17:33.470] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C10.dat
[13:17:33.470] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C11.dat
[13:17:33.471] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C12.dat
[13:17:33.471] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C13.dat
[13:17:33.471] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C14.dat
[13:17:33.471] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C15.dat
[13:17:37.500] <TB1> INFO: Test took 4024ms.
[13:17:41.680] <TB1> INFO: Test took 3889ms.
[13:17:45.830] <TB1> INFO: Test took 3836ms.
[13:17:46.129] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:47.080] <TB1> INFO: Test took 951ms.
[13:17:47.084] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:48.236] <TB1> INFO: Test took 1152ms.
[13:17:48.240] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:49.380] <TB1> INFO: Test took 1140ms.
[13:17:49.383] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:50.521] <TB1> INFO: Test took 1138ms.
[13:17:50.524] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:51.680] <TB1> INFO: Test took 1156ms.
[13:17:51.684] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:52.854] <TB1> INFO: Test took 1170ms.
[13:17:52.858] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:53.999] <TB1> INFO: Test took 1141ms.
[13:17:54.003] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:55.206] <TB1> INFO: Test took 1203ms.
[13:17:55.210] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:56.349] <TB1> INFO: Test took 1139ms.
[13:17:56.353] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:57.492] <TB1> INFO: Test took 1139ms.
[13:17:57.496] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:58.651] <TB1> INFO: Test took 1155ms.
[13:17:58.655] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:17:59.810] <TB1> INFO: Test took 1155ms.
[13:17:59.814] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:00.953] <TB1> INFO: Test took 1139ms.
[13:18:00.957] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:02.097] <TB1> INFO: Test took 1140ms.
[13:18:02.101] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:03.240] <TB1> INFO: Test took 1139ms.
[13:18:03.244] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:04.383] <TB1> INFO: Test took 1139ms.
[13:18:04.387] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:05.628] <TB1> INFO: Test took 1241ms.
[13:18:05.632] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:06.786] <TB1> INFO: Test took 1154ms.
[13:18:06.789] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:07.960] <TB1> INFO: Test took 1171ms.
[13:18:07.964] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:09.119] <TB1> INFO: Test took 1156ms.
[13:18:09.123] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:10.263] <TB1> INFO: Test took 1140ms.
[13:18:10.267] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:11.390] <TB1> INFO: Test took 1123ms.
[13:18:11.394] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:12.532] <TB1> INFO: Test took 1138ms.
[13:18:12.537] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:13.777] <TB1> INFO: Test took 1241ms.
[13:18:13.781] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:14.922] <TB1> INFO: Test took 1141ms.
[13:18:14.928] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:16.152] <TB1> INFO: Test took 1225ms.
[13:18:16.155] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:17.293] <TB1> INFO: Test took 1138ms.
[13:18:17.297] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:18.437] <TB1> INFO: Test took 1140ms.
[13:18:18.441] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:19.580] <TB1> INFO: Test took 1139ms.
[13:18:19.584] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:20.724] <TB1> INFO: Test took 1140ms.
[13:18:20.727] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:21.882] <TB1> INFO: Test took 1155ms.
[13:18:21.886] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:18:23.030] <TB1> INFO: Test took 1144ms.
[13:18:23.678] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 651 seconds
[13:18:23.678] <TB1> INFO: PH scale (per ROC): 82 81 79 79 76 78 91 83 74 98 79 87 79 84 86 82
[13:18:23.678] <TB1> INFO: PH offset (per ROC): 153 157 159 165 145 159 182 162 155 134 157 154 149 158 154 158
[13:18:23.865] <TB1> INFO: ######################################################################
[13:18:23.865] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[13:18:23.865] <TB1> INFO: ######################################################################
[13:18:23.875] <TB1> INFO: scanning low vcal = 10
[13:18:27.956] <TB1> INFO: Test took 4081ms.
[13:18:27.962] <TB1> INFO: scanning low vcal = 20
[13:18:32.264] <TB1> INFO: Test took 4302ms.
[13:18:32.270] <TB1> INFO: scanning low vcal = 30
[13:18:36.429] <TB1> INFO: Test took 4159ms.
[13:18:36.440] <TB1> INFO: scanning low vcal = 40
[13:18:41.354] <TB1> INFO: Test took 4914ms.
[13:18:41.417] <TB1> INFO: scanning low vcal = 50
[13:18:46.406] <TB1> INFO: Test took 4988ms.
[13:18:46.469] <TB1> INFO: scanning low vcal = 60
[13:18:51.429] <TB1> INFO: Test took 4960ms.
[13:18:51.491] <TB1> INFO: scanning low vcal = 70
[13:18:56.192] <TB1> INFO: Test took 4701ms.
[13:18:56.261] <TB1> INFO: scanning low vcal = 80
[13:19:01.084] <TB1> INFO: Test took 4823ms.
[13:19:01.179] <TB1> INFO: scanning low vcal = 90
[13:19:08.353] <TB1> INFO: Test took 7173ms.
[13:19:08.412] <TB1> INFO: scanning low vcal = 100
[13:19:15.666] <TB1> INFO: Test took 7254ms.
[13:19:15.726] <TB1> INFO: scanning low vcal = 110
[13:19:22.782] <TB1> INFO: Test took 7056ms.
[13:19:22.844] <TB1> INFO: scanning low vcal = 120
[13:19:30.142] <TB1> INFO: Test took 7298ms.
[13:19:30.198] <TB1> INFO: scanning low vcal = 130
[13:19:37.278] <TB1> INFO: Test took 7080ms.
[13:19:37.340] <TB1> INFO: scanning low vcal = 140
[13:19:44.379] <TB1> INFO: Test took 7039ms.
[13:19:44.448] <TB1> INFO: scanning low vcal = 150
[13:19:51.585] <TB1> INFO: Test took 7137ms.
[13:19:51.690] <TB1> INFO: scanning low vcal = 160
[13:19:58.829] <TB1> INFO: Test took 7139ms.
[13:19:58.893] <TB1> INFO: scanning low vcal = 170
[13:20:05.842] <TB1> INFO: Test took 6949ms.
[13:20:05.900] <TB1> INFO: scanning low vcal = 180
[13:20:13.402] <TB1> INFO: Test took 7502ms.
[13:20:13.456] <TB1> INFO: scanning low vcal = 190
[13:20:20.794] <TB1> INFO: Test took 7338ms.
[13:20:20.854] <TB1> INFO: scanning low vcal = 200
[13:20:27.976] <TB1> INFO: Test took 7122ms.
[13:20:28.031] <TB1> INFO: scanning low vcal = 210
[13:20:35.180] <TB1> INFO: Test took 7149ms.
[13:20:35.242] <TB1> INFO: scanning low vcal = 220
[13:20:42.319] <TB1> INFO: Test took 7077ms.
[13:20:42.376] <TB1> INFO: scanning low vcal = 230
[13:20:49.752] <TB1> INFO: Test took 7376ms.
[13:20:49.810] <TB1> INFO: scanning low vcal = 240
[13:20:57.134] <TB1> INFO: Test took 7324ms.
[13:20:57.191] <TB1> INFO: scanning low vcal = 250
[13:21:04.822] <TB1> INFO: Test took 7631ms.
[13:21:04.881] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[13:21:12.434] <TB1> INFO: Test took 7553ms.
[13:21:12.491] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[13:21:19.943] <TB1> INFO: Test took 7452ms.
[13:21:19.999] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[13:21:27.417] <TB1> INFO: Test took 7418ms.
[13:21:27.474] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[13:21:35.360] <TB1> INFO: Test took 7886ms.
[13:21:35.417] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[13:21:43.061] <TB1> INFO: Test took 7644ms.
[13:21:43.545] <TB1> INFO: PixTestGainPedestal::measure() done
[13:22:13.543] <TB1> INFO: PixTestGainPedestal::fit() done
[13:22:13.543] <TB1> INFO: non-linearity mean: 0.956 0.959 0.959 0.954 0.957 0.952 0.957 0.961 0.956 0.958 0.960 0.958 0.959 0.960 0.959 0.958
[13:22:13.543] <TB1> INFO: non-linearity RMS: 0.005 0.005 0.006 0.006 0.006 0.007 0.006 0.005 0.005 0.004 0.007 0.006 0.005 0.005 0.005 0.006
[13:22:13.543] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[13:22:13.561] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[13:22:13.579] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[13:22:13.597] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[13:22:13.614] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[13:22:13.631] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[13:22:13.649] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[13:22:13.666] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[13:22:13.684] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[13:22:13.702] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[13:22:13.719] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[13:22:13.737] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[13:22:13.755] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[13:22:13.772] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[13:22:13.790] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[13:22:13.807] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[13:22:13.825] <TB1> INFO: PixTestGainPedestal::doTest() done, duration: 229 seconds
[13:22:13.831] <TB1> INFO: enter test to run
[13:22:13.831] <TB1> INFO: test: exit no parameter change
[13:22:14.257] <TB1> QUIET: Connection to board 153 closed.
[13:22:14.258] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master