[13:48:17.726] <TB2> INFO: *** Welcome to pxar ***
[13:48:17.726] <TB2> INFO: *** Today: 2015/08/25
[13:48:17.726] <TB2> INFO: readRocDacs: /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C15.dat
[13:48:17.728] <TB2> INFO: readTbmDacs: /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//tbmParameters_C0b.dat
[13:48:17.728] <TB2> INFO: readMaskFile: /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//defaultMaskFile.dat
[13:48:17.728] <TB2> INFO: readTrimFile: /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters_C15.dat
[13:48:17.817] <TB2> INFO: clk: 4
[13:48:17.817] <TB2> INFO: ctr: 4
[13:48:17.817] <TB2> INFO: sda: 19
[13:48:17.817] <TB2> INFO: tin: 9
[13:48:17.817] <TB2> INFO: level: 15
[13:48:17.817] <TB2> INFO: triggerdelay: 0
[13:48:17.817] <TB2> QUIET: Instanciating API for pxar prod-01+86~g1838649
[13:48:17.817] <TB2> INFO: Log level: INFO
[13:48:17.825] <TB2> INFO: Found DTB DTB_WXC55Z
[13:48:17.834] <TB2> QUIET: Connection to board DTB_WXC55Z opened.
[13:48:17.837] <TB2> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 156
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXC55Z
MAC address: 40D85511809C
Hostname: pixelDTB156
Comment:
------------------------------------------------------
[13:48:17.840] <TB2> INFO: RPC call hashes of host and DTB match: 447413373
[13:48:19.397] <TB2> INFO: DUT info:
[13:48:19.397] <TB2> INFO: The DUT currently contains the following objects:
[13:48:19.397] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[13:48:19.397] <TB2> INFO: TBM Core alpha (0): 7 registers set
[13:48:19.397] <TB2> INFO: TBM Core beta (1): 7 registers set
[13:48:19.397] <TB2> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:48:19.397] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.397] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.398] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.398] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.398] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.398] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.398] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:48:19.799] <TB2> INFO: enter 'restricted' command line mode
[13:48:19.799] <TB2> INFO: enter test to run
[13:48:19.799] <TB2> INFO: test: pretest no parameter change
[13:48:19.799] <TB2> INFO: running: pretest
[13:48:19.807] <TB2> INFO: ######################################################################
[13:48:19.807] <TB2> INFO: PixTestPretest::doTest()
[13:48:19.807] <TB2> INFO: ######################################################################
[13:48:19.808] <TB2> INFO: ----------------------------------------------------------------------
[13:48:19.808] <TB2> INFO: PixTestPretest::programROC()
[13:48:19.808] <TB2> INFO: ----------------------------------------------------------------------
[13:48:37.826] <TB2> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[13:48:37.826] <TB2> INFO: IA differences per ROC: 18.5 18.5 17.7 17.7 17.7 18.5 17.7 20.1 20.1 19.3 16.9 18.5 20.9 17.7 19.3 17.7
[13:48:37.907] <TB2> INFO: ----------------------------------------------------------------------
[13:48:37.907] <TB2> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[13:48:37.907] <TB2> INFO: ----------------------------------------------------------------------
[13:48:43.591] <TB2> INFO: PixTestPretest::setVana() done, Module Ia 395.5 mA = 24.7188 mA/ROC
[13:48:43.594] <TB2> INFO: ----------------------------------------------------------------------
[13:48:43.594] <TB2> INFO: PixTestPretest::findWorkingPixel()
[13:48:43.594] <TB2> INFO: ----------------------------------------------------------------------
[13:48:52.090] <TB2> INFO: Test took 8491ms.
[13:48:52.388] <TB2> INFO: Found working pixel in all ROCs: col/row = 12/22
[13:48:52.426] <TB2> INFO: ----------------------------------------------------------------------
[13:48:52.426] <TB2> INFO: PixTestPretest::setVthrCompCalDel()
[13:48:52.426] <TB2> INFO: ----------------------------------------------------------------------
[13:49:00.789] <TB2> INFO: Test took 8356ms.
[13:49:01.097] <TB2> INFO: PixTestPretest::setVthrCompCalDel() done
[13:49:01.097] <TB2> INFO: CalDel: 128 135 171 144 122 128 119 149 112 137 128 137 121 114 143 126
[13:49:01.097] <TB2> INFO: VthrComp: 51 51 52 51 51 51 51 51 51 51 51 51 51 51 51 51
[13:49:01.102] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C0.dat
[13:49:01.102] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C1.dat
[13:49:01.103] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C2.dat
[13:49:01.103] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C3.dat
[13:49:01.103] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C4.dat
[13:49:01.103] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C5.dat
[13:49:01.104] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C6.dat
[13:49:01.104] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C7.dat
[13:49:01.104] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C8.dat
[13:49:01.104] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C9.dat
[13:49:01.105] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C10.dat
[13:49:01.105] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C11.dat
[13:49:01.105] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C12.dat
[13:49:01.105] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C13.dat
[13:49:01.106] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C14.dat
[13:49:01.106] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters_C15.dat
[13:49:01.106] <TB2> INFO: write tbm parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//tbmParameters_C0a.dat
[13:49:01.106] <TB2> INFO: write tbm parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//tbmParameters_C0b.dat
[13:49:01.106] <TB2> INFO: PixTestPretest::doTest() done, duration: 41 seconds
[13:49:01.210] <TB2> INFO: enter test to run
[13:49:01.210] <TB2> INFO: test: fulltest no parameter change
[13:49:01.210] <TB2> INFO: running: fulltest
[13:49:01.210] <TB2> INFO: ######################################################################
[13:49:01.210] <TB2> INFO: PixTestFullTest::doTest()
[13:49:01.210] <TB2> INFO: ######################################################################
[13:49:01.211] <TB2> INFO: ######################################################################
[13:49:01.211] <TB2> INFO: PixTestAlive::doTest()
[13:49:01.211] <TB2> INFO: ######################################################################
[13:49:01.213] <TB2> INFO: ----------------------------------------------------------------------
[13:49:01.213] <TB2> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:49:01.213] <TB2> INFO: ----------------------------------------------------------------------
[13:49:04.286] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (3) != Token Chain Length (4)
[13:49:04.286] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[13:49:04.672] <TB2> INFO: Test took 3458ms.
[13:49:04.697] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:04.920] <TB2> INFO: PixTestAlive::aliveTest() done with 4 decoding errors
[13:49:04.920] <TB2> INFO: number of dead pixels (per ROC): 4 0 0 0 0 0 0 0 2 0 0 0 0 0 0 0
[13:49:04.921] <TB2> INFO: ----------------------------------------------------------------------
[13:49:04.921] <TB2> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:49:04.921] <TB2> INFO: ----------------------------------------------------------------------
[13:49:07.837] <TB2> INFO: Test took 2915ms.
[13:49:07.840] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:07.841] <TB2> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[13:49:08.071] <TB2> INFO: PixTestAlive::maskTest() done
[13:49:08.071] <TB2> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:49:08.074] <TB2> INFO: ----------------------------------------------------------------------
[13:49:08.074] <TB2> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:49:08.074] <TB2> INFO: ----------------------------------------------------------------------
[13:49:11.647] <TB2> INFO: Test took 3570ms.
[13:49:11.664] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:11.894] <TB2> INFO: PixTestAlive::addressDecodingTest() done
[13:49:11.894] <TB2> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:49:11.894] <TB2> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[13:49:11.907] <TB2> INFO: ######################################################################
[13:49:11.907] <TB2> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[13:49:11.907] <TB2> INFO: ######################################################################
[13:49:11.910] <TB2> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[13:49:11.921] <TB2> INFO: dacScan step from 0 .. 29
[13:49:11.921] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:49:11.921] <TB2> INFO: run 1 of 1
[13:49:35.062] <TB2> INFO: Test took 23141ms.
[13:49:35.094] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:35.095] <TB2> INFO: dacScan step from 30 .. 59
[13:49:35.095] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:49:35.095] <TB2> INFO: run 1 of 1
[13:49:50.614] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 2 Event ID mismatch: local ID (18) != TBM ID (19)
[13:49:50.614] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (18) != TBM ID (19)
[13:49:50.614] <TB2> WARNING: Channel 2 ROC 0: Readback start marker after 15 readouts!
[13:49:50.614] <TB2> WARNING: Channel 2 ROC 1: Readback start marker after 15 readouts!
[13:49:50.614] <TB2> WARNING: Channel 2 ROC 2: Readback start marker after 15 readouts!
[13:49:50.614] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[13:49:50.614] <TB2> WARNING: Channel 3 ROC 0: Readback start marker after 15 readouts!
[13:49:50.615] <TB2> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[13:49:50.615] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[13:49:50.615] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[13:49:58.887] <TB2> INFO: Test took 23792ms.
[13:49:58.952] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:58.959] <TB2> INFO: dacScan step from 60 .. 89
[13:49:58.959] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:49:58.959] <TB2> INFO: run 1 of 1
[13:50:29.657] <TB2> INFO: Test took 30698ms.
[13:50:29.921] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:29.967] <TB2> INFO: dacScan step from 90 .. 119
[13:50:29.967] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:50:29.967] <TB2> INFO: run 1 of 1
[13:51:00.823] <TB2> INFO: Test took 30856ms.
[13:51:01.067] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:01.110] <TB2> INFO: dacScan step from 120 .. 149
[13:51:01.110] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[13:51:01.110] <TB2> INFO: run 1 of 1
[13:51:26.082] <TB2> INFO: Test took 24972ms.
[13:51:26.298] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:49.196] <TB2> INFO: PixTestBBMap::doTest() done, duration: 157 seconds
[13:51:49.196] <TB2> INFO: number of dead bumps (per ROC): 3 0 1 0 0 0 0 0 0 0 0 0 0 1 0 25
[13:51:49.196] <TB2> INFO: separation cut (per ROC): 103 100 100 95 104 95 106 97 115 90 88 83 99 88 97 82
[13:51:49.266] <TB2> INFO: ######################################################################
[13:51:49.266] <TB2> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = 4, ntrig/step = 50
[13:51:49.266] <TB2> INFO: ######################################################################
[13:51:49.266] <TB2> INFO: ----------------------------------------------------------------------
[13:51:49.266] <TB2> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = 4, ntrig/step = 50
[13:51:49.266] <TB2> INFO: ----------------------------------------------------------------------
[13:51:49.266] <TB2> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4/50) hits flags = 16 (plus default)
[13:51:49.275] <TB2> INFO: dacScan step from 0 .. 3
[13:51:49.275] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:51:49.275] <TB2> INFO: run 1 of 1
[13:52:10.898] <TB2> INFO: Test took 21623ms.
[13:52:10.926] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:10.929] <TB2> INFO: dacScan step from 4 .. 7
[13:52:10.929] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:52:10.929] <TB2> INFO: run 1 of 1
[13:52:32.310] <TB2> INFO: Test took 21381ms.
[13:52:32.338] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:32.338] <TB2> INFO: dacScan step from 8 .. 11
[13:52:32.338] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:52:32.338] <TB2> INFO: run 1 of 1
[13:52:53.206] <TB2> INFO: Test took 20867ms.
[13:52:53.230] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:53.232] <TB2> INFO: dacScan step from 12 .. 15
[13:52:53.232] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:52:53.232] <TB2> INFO: run 1 of 1
[13:53:14.100] <TB2> INFO: Test took 20868ms.
[13:53:14.126] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:14.128] <TB2> INFO: dacScan step from 16 .. 19
[13:53:14.128] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:53:14.128] <TB2> INFO: run 1 of 1
[13:53:35.013] <TB2> INFO: Test took 20885ms.
[13:53:35.035] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:35.035] <TB2> INFO: dacScan step from 20 .. 23
[13:53:35.035] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:53:35.035] <TB2> INFO: run 1 of 1
[13:53:56.023] <TB2> INFO: Test took 20988ms.
[13:53:56.050] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:56.051] <TB2> INFO: dacScan step from 24 .. 27
[13:53:56.051] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:53:56.051] <TB2> INFO: run 1 of 1
[13:54:16.737] <TB2> INFO: Test took 20686ms.
[13:54:16.767] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:16.767] <TB2> INFO: dacScan step from 28 .. 31
[13:54:16.767] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:54:16.767] <TB2> INFO: run 1 of 1
[13:54:36.779] <TB2> INFO: Test took 20012ms.
[13:54:36.809] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:36.809] <TB2> INFO: dacScan step from 32 .. 35
[13:54:36.809] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:54:36.809] <TB2> INFO: run 1 of 1
[13:54:56.811] <TB2> INFO: Test took 20002ms.
[13:54:56.839] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:56.839] <TB2> INFO: dacScan step from 36 .. 39
[13:54:56.839] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:54:56.839] <TB2> INFO: run 1 of 1
[13:55:16.666] <TB2> INFO: Test took 19827ms.
[13:55:16.693] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:16.693] <TB2> INFO: dacScan step from 40 .. 43
[13:55:16.693] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:55:16.693] <TB2> INFO: run 1 of 1
[13:55:36.643] <TB2> INFO: Test took 19950ms.
[13:55:36.672] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:36.672] <TB2> INFO: dacScan step from 44 .. 47
[13:55:36.672] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:55:36.672] <TB2> INFO: run 1 of 1
[13:55:57.538] <TB2> INFO: Test took 20866ms.
[13:55:57.570] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:57.570] <TB2> INFO: dacScan step from 48 .. 51
[13:55:57.570] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:55:57.570] <TB2> INFO: run 1 of 1
[13:56:17.901] <TB2> INFO: Test took 20331ms.
[13:56:17.932] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:17.932] <TB2> INFO: dacScan step from 52 .. 55
[13:56:17.932] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:56:17.932] <TB2> INFO: run 1 of 1
[13:56:38.903] <TB2> INFO: Test took 20971ms.
[13:56:38.931] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:38.931] <TB2> INFO: dacScan step from 56 .. 59
[13:56:38.931] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:56:38.931] <TB2> INFO: run 1 of 1
[13:57:00.062] <TB2> INFO: Test took 21131ms.
[13:57:00.090] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:00.090] <TB2> INFO: dacScan step from 60 .. 63
[13:57:00.090] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:57:00.090] <TB2> INFO: run 1 of 1
[13:57:21.014] <TB2> INFO: Test took 20924ms.
[13:57:21.043] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:21.043] <TB2> INFO: dacScan step from 64 .. 67
[13:57:21.043] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:57:21.043] <TB2> INFO: run 1 of 1
[13:57:41.985] <TB2> INFO: Test took 20941ms.
[13:57:42.019] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:42.019] <TB2> INFO: dacScan step from 68 .. 71
[13:57:42.019] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:57:42.019] <TB2> INFO: run 1 of 1
[13:58:03.483] <TB2> INFO: Test took 21464ms.
[13:58:03.518] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:03.518] <TB2> INFO: dacScan step from 72 .. 75
[13:58:03.518] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:58:03.518] <TB2> INFO: run 1 of 1
[13:58:24.883] <TB2> INFO: Test took 21365ms.
[13:58:24.913] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:24.913] <TB2> INFO: dacScan step from 76 .. 79
[13:58:24.913] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:58:24.913] <TB2> INFO: run 1 of 1
[13:58:46.248] <TB2> INFO: Test took 21334ms.
[13:58:46.289] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:46.290] <TB2> INFO: dacScan step from 80 .. 83
[13:58:46.291] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:58:46.291] <TB2> INFO: run 1 of 1
[13:59:08.679] <TB2> INFO: Test took 22388ms.
[13:59:08.744] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:08.747] <TB2> INFO: dacScan step from 84 .. 87
[13:59:08.747] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:59:08.747] <TB2> INFO: run 1 of 1
[13:59:32.296] <TB2> INFO: Test took 23549ms.
[13:59:32.388] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:32.392] <TB2> INFO: dacScan step from 88 .. 91
[13:59:32.392] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:59:32.392] <TB2> INFO: run 1 of 1
[13:59:56.744] <TB2> INFO: Test took 24352ms.
[13:59:56.860] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:56.865] <TB2> INFO: dacScan step from 92 .. 95
[13:59:56.865] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[13:59:56.865] <TB2> INFO: run 1 of 1
[14:00:22.922] <TB2> INFO: Test took 26057ms.
[14:00:23.060] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:23.066] <TB2> INFO: dacScan step from 96 .. 99
[14:00:23.066] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:00:23.066] <TB2> INFO: run 1 of 1
[14:00:50.805] <TB2> INFO: Test took 27739ms.
[14:00:50.976] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:50.984] <TB2> INFO: dacScan step from 100 .. 103
[14:00:50.984] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:00:50.984] <TB2> INFO: run 1 of 1
[14:01:20.066] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (180) != TBM ID (0)
[14:01:20.066] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (1) != Token Chain Length (4)
[14:01:20.066] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (1) != TBM ID (181)
[14:01:20.066] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[14:01:20.066] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:01:20.098] <TB2> INFO: Test took 29114ms.
[14:01:20.303] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:20.312] <TB2> INFO: dacScan step from 104 .. 107
[14:01:20.312] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:01:20.312] <TB2> INFO: run 1 of 1
[14:01:50.216] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (105) != TBM ID (0)
[14:01:50.216] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:01:50.216] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (1) != TBM ID (106)
[14:01:50.962] <TB2> INFO: Test took 30650ms.
[14:01:51.191] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:51.202] <TB2> INFO: dacScan step from 108 .. 111
[14:01:51.202] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:01:51.202] <TB2> INFO: run 1 of 1
[14:02:21.209] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[14:02:22.212] <TB2> INFO: Test took 31010ms.
[14:02:22.433] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:22.442] <TB2> INFO: dacScan step from 112 .. 115
[14:02:22.442] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:02:22.442] <TB2> INFO: run 1 of 1
[14:02:53.109] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:02:53.109] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:02:54.468] <TB2> INFO: Test took 32026ms.
[14:02:54.724] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:54.734] <TB2> INFO: dacScan step from 116 .. 119
[14:02:54.734] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:02:54.734] <TB2> INFO: run 1 of 1
[14:03:25.445] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:03:25.445] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:03:27.033] <TB2> INFO: Test took 32299ms.
[14:03:27.264] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:27.273] <TB2> INFO: dacScan step from 120 .. 123
[14:03:27.273] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:03:27.273] <TB2> INFO: run 1 of 1
[14:03:58.335] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:03:58.335] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:03:59.868] <TB2> INFO: Test took 32594ms.
[14:04:00.103] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:00.112] <TB2> INFO: dacScan step from 124 .. 127
[14:04:00.112] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:04:00.112] <TB2> INFO: run 1 of 1
[14:04:30.995] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[14:04:30.995] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (214) != TBM ID (215)
[14:04:30.995] <TB2> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[14:04:30.995] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[14:04:30.995] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:04:32.451] <TB2> INFO: Test took 32339ms.
[14:04:32.678] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:32.687] <TB2> INFO: dacScan step from 128 .. 131
[14:04:32.691] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:04:32.691] <TB2> INFO: run 1 of 1
[14:05:03.366] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:05:03.366] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:05:04.910] <TB2> INFO: Test took 32219ms.
[14:05:05.150] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:05.159] <TB2> INFO: dacScan step from 132 .. 135
[14:05:05.159] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:05:05.159] <TB2> INFO: run 1 of 1
[14:05:32.607] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[14:05:32.607] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:05:32.607] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[14:05:32.607] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:05:35.848] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[14:05:35.848] <TB2> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (195) != TBM ID (196)
[14:05:35.848] <TB2> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[14:05:35.848] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[14:05:35.848] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:05:37.455] <TB2> INFO: Test took 32296ms.
[14:05:37.705] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:37.717] <TB2> INFO: dacScan step from 136 .. 139
[14:05:37.717] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:05:37.717] <TB2> INFO: run 1 of 1
[14:06:09.106] <TB2> INFO: Test took 31389ms.
[14:06:09.353] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:09.363] <TB2> INFO: dacScan step from 140 .. 143
[14:06:09.363] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:06:09.363] <TB2> INFO: run 1 of 1
[14:06:39.901] <TB2> INFO: Test took 30538ms.
[14:06:40.149] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:40.159] <TB2> INFO: dacScan step from 144 .. 147
[14:06:40.159] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:06:40.159] <TB2> INFO: run 1 of 1
[14:07:10.076] <TB2> INFO: Test took 29918ms.
[14:07:10.319] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:10.328] <TB2> INFO: dacScan step from 148 .. 149
[14:07:10.328] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[14:07:10.328] <TB2> INFO: run 1 of 1
[14:07:24.817] <TB2> INFO: Test took 14489ms.
[14:07:24.968] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:24.974] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:26.386] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:27.758] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:29.117] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:30.509] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:32.017] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:33.419] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:34.850] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:36.305] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:37.776] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:39.200] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:40.848] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:42.611] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:44.275] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:45.971] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:47.517] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[14:07:49.059] <TB2> INFO: PixTestScurves::scurves() done
[14:07:49.059] <TB2> INFO: Vcal mean: 110.12 103.30 107.47 97.26 101.63 101.25 107.39 89.76 105.04 92.01 86.46 83.37 99.07 85.18 93.60 98.09
[14:07:49.059] <TB2> INFO: Vcal RMS: 6.09 6.18 5.65 5.08 5.97 5.20 6.03 5.61 6.22 5.86 4.80 4.44 6.31 5.15 5.85 5.79
[14:07:49.059] <TB2> INFO: PixTestScurves::fullTest() done, duration: 959 seconds
[14:07:49.140] <TB2> INFO: ######################################################################
[14:07:49.141] <TB2> INFO: PixTestTrim::doTest()
[14:07:49.141] <TB2> INFO: ######################################################################
[14:07:49.142] <TB2> INFO: ----------------------------------------------------------------------
[14:07:49.142] <TB2> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[14:07:49.142] <TB2> INFO: ----------------------------------------------------------------------
[14:07:49.229] <TB2> INFO: ---> VthrComp thr map (minimal VthrComp)
[14:07:49.229] <TB2> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[14:07:49.238] <TB2> INFO: dacScan step from 0 .. 19
[14:07:49.238] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:07:49.238] <TB2> INFO: run 1 of 1
[14:08:04.344] <TB2> INFO: Test took 15106ms.
[14:08:04.370] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:04.370] <TB2> INFO: dacScan step from 20 .. 39
[14:08:04.370] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:08:04.370] <TB2> INFO: run 1 of 1
[14:08:19.443] <TB2> INFO: Test took 15072ms.
[14:08:19.464] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:19.464] <TB2> INFO: dacScan step from 40 .. 59
[14:08:19.464] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:08:19.464] <TB2> INFO: run 1 of 1
[14:08:34.689] <TB2> INFO: Test took 15225ms.
[14:08:34.715] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:34.715] <TB2> INFO: dacScan step from 60 .. 79
[14:08:34.715] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:08:34.715] <TB2> INFO: run 1 of 1
[14:08:49.196] <TB2> INFO: Test took 14480ms.
[14:08:49.217] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:49.217] <TB2> INFO: dacScan step from 80 .. 99
[14:08:49.217] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:08:49.217] <TB2> INFO: run 1 of 1
[14:09:04.721] <TB2> INFO: Test took 15504ms.
[14:09:04.759] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:04.764] <TB2> INFO: dacScan step from 100 .. 119
[14:09:04.764] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:09:04.764] <TB2> INFO: run 1 of 1
[14:09:21.943] <TB2> INFO: Test took 17179ms.
[14:09:22.081] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:22.105] <TB2> INFO: dacScan step from 120 .. 139
[14:09:22.105] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:09:22.105] <TB2> INFO: run 1 of 1
[14:09:41.230] <TB2> INFO: Test took 19125ms.
[14:09:41.398] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:41.428] <TB2> INFO: dacScan step from 140 .. 159
[14:09:41.428] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:09:41.428] <TB2> INFO: run 1 of 1
[14:09:57.388] <TB2> INFO: Test took 15960ms.
[14:09:57.512] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:20.145] <TB2> INFO: ROC 0 VthrComp = 109
[14:10:20.145] <TB2> INFO: ROC 1 VthrComp = 100
[14:10:20.145] <TB2> INFO: ROC 2 VthrComp = 100
[14:10:20.146] <TB2> INFO: ROC 3 VthrComp = 97
[14:10:20.146] <TB2> INFO: ROC 4 VthrComp = 104
[14:10:20.146] <TB2> INFO: ROC 5 VthrComp = 101
[14:10:20.146] <TB2> INFO: ROC 6 VthrComp = 105
[14:10:20.146] <TB2> INFO: ROC 7 VthrComp = 93
[14:10:20.146] <TB2> INFO: ROC 8 VthrComp = 106
[14:10:20.146] <TB2> INFO: ROC 9 VthrComp = 95
[14:10:20.146] <TB2> INFO: ROC 10 VthrComp = 90
[14:10:20.146] <TB2> INFO: ROC 11 VthrComp = 86
[14:10:20.146] <TB2> INFO: ROC 12 VthrComp = 101
[14:10:20.147] <TB2> INFO: ROC 13 VthrComp = 87
[14:10:20.147] <TB2> INFO: ROC 14 VthrComp = 96
[14:10:20.147] <TB2> INFO: ROC 15 VthrComp = 95
[14:10:20.147] <TB2> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[14:10:20.147] <TB2> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[14:10:20.156] <TB2> INFO: dacScan step from 0 .. 19
[14:10:20.156] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:10:20.156] <TB2> INFO: run 1 of 1
[14:10:35.267] <TB2> INFO: Test took 15111ms.
[14:10:35.291] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:35.291] <TB2> INFO: dacScan step from 20 .. 39
[14:10:35.291] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:10:35.291] <TB2> INFO: run 1 of 1
[14:10:50.677] <TB2> INFO: Test took 15386ms.
[14:10:50.715] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:50.717] <TB2> INFO: dacScan step from 40 .. 59
[14:10:50.717] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:10:50.717] <TB2> INFO: run 1 of 1
[14:11:09.547] <TB2> INFO: Test took 18831ms.
[14:11:09.731] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:09.762] <TB2> INFO: dacScan step from 60 .. 79
[14:11:09.762] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:11:09.762] <TB2> INFO: run 1 of 1
[14:11:19.942] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[14:11:19.942] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:11:19.942] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[14:11:19.942] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:11:29.759] <TB2> INFO: Test took 19997ms.
[14:11:29.924] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:29.954] <TB2> INFO: dacScan step from 80 .. 99
[14:11:29.954] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:11:29.954] <TB2> INFO: run 1 of 1
[14:11:48.696] <TB2> INFO: Test took 18742ms.
[14:11:48.860] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:48.889] <TB2> INFO: dacScan step from 100 .. 119
[14:11:48.889] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:11:48.889] <TB2> INFO: run 1 of 1
[14:12:09.510] <TB2> INFO: Test took 20621ms.
[14:12:09.675] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:09.703] <TB2> INFO: dacScan step from 120 .. 139
[14:12:09.703] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:12:09.703] <TB2> INFO: run 1 of 1
[14:12:29.093] <TB2> INFO: Test took 19390ms.
[14:12:29.257] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:29.288] <TB2> INFO: dacScan step from 140 .. 159
[14:12:29.288] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[14:12:29.288] <TB2> INFO: run 1 of 1
[14:12:48.249] <TB2> INFO: Test took 18961ms.
[14:12:48.408] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:14.191] <TB2> INFO: roc 0 with ID = 0 has maximal Vcal 61.3098 for pixel 8/74 mean/min/max = 48.0278/34.737/61.3186
[14:13:14.191] <TB2> INFO: roc 1 with ID = 1 has maximal Vcal 63.2187 for pixel 0/17 mean/min/max = 47.5946/31.6164/63.5729
[14:13:14.191] <TB2> INFO: roc 2 with ID = 2 has maximal Vcal 60.1146 for pixel 3/0 mean/min/max = 46.4114/32.5121/60.3108
[14:13:14.191] <TB2> INFO: roc 3 with ID = 3 has maximal Vcal 58.1206 for pixel 6/1 mean/min/max = 45.3485/32.4967/58.2004
[14:13:14.192] <TB2> INFO: roc 4 with ID = 4 has maximal Vcal 60.8189 for pixel 27/79 mean/min/max = 47.2942/33.6353/60.9532
[14:13:14.192] <TB2> INFO: roc 5 with ID = 5 has maximal Vcal 58.2803 for pixel 2/1 mean/min/max = 45.1351/31.7337/58.5366
[14:13:14.192] <TB2> INFO: roc 6 with ID = 6 has maximal Vcal 62.4312 for pixel 21/79 mean/min/max = 48.1913/33.7399/62.6427
[14:13:14.192] <TB2> INFO: roc 7 with ID = 7 has maximal Vcal 58.7184 for pixel 14/77 mean/min/max = 45.5737/32.3533/58.7942
[14:13:14.193] <TB2> INFO: roc 8 with ID = 8 has maximal Vcal 61.7227 for pixel 0/14 mean/min/max = 47.98/34.1055/61.8545
[14:13:14.193] <TB2> INFO: roc 9 with ID = 9 has maximal Vcal 59.5833 for pixel 36/65 mean/min/max = 45.9153/32.2373/59.5934
[14:13:14.193] <TB2> INFO: roc 10 with ID = 10 has maximal Vcal 56.8724 for pixel 18/79 mean/min/max = 45.1896/33.4029/56.9764
[14:13:14.193] <TB2> INFO: roc 11 with ID = 11 has maximal Vcal 56.0329 for pixel 16/5 mean/min/max = 44.4601/32.5254/56.3947
[14:13:14.194] <TB2> INFO: roc 12 with ID = 12 has maximal Vcal 60.4503 for pixel 13/79 mean/min/max = 46.3041/32.1275/60.4807
[14:13:14.194] <TB2> INFO: roc 13 with ID = 13 has maximal Vcal 57.139 for pixel 17/75 mean/min/max = 44.4906/31.5173/57.4639
[14:13:14.194] <TB2> INFO: roc 14 with ID = 14 has maximal Vcal 58.7676 for pixel 8/12 mean/min/max = 45.3465/31.784/58.909
[14:13:14.194] <TB2> INFO: roc 15 with ID = 15 has maximal Vcal 60.9504 for pixel 11/46 mean/min/max = 46.8189/32.5808/61.0569
[14:13:14.195] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:13:35.656] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (0) != Token Chain Length (4)
[14:13:39.271] <TB2> CRITICAL: <hal.cc/SingleRocOnePixelDacDacScan:L1547> Incomplete DAQ data readout! Missing -1 Events.
[14:13:39.291] <TB2> CRITICAL: <PixTestTrim.cc/trimTest:L262> pXar execption: Incomplete DAQ data readout in function SingleRocOnePixelDacDacScan
[14:13:39.291] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:14:44.637] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[14:14:44.638] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:14:44.638] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[14:14:44.638] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:15:19.075] <TB2> INFO: Test took 99784ms.
[14:15:20.533] <TB2> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[14:15:20.542] <TB2> INFO: dacScan step from 0 .. 19
[14:15:20.542] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:15:20.542] <TB2> INFO: run 1 of 2
[14:15:36.830] <TB2> INFO: Test took 16288ms.
[14:15:36.856] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:36.857] <TB2> INFO: run 2 of 2
[14:15:53.375] <TB2> INFO: Test took 16518ms.
[14:15:53.407] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:53.408] <TB2> INFO: dacScan step from 20 .. 39
[14:15:53.408] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:15:53.408] <TB2> INFO: run 1 of 2
[14:16:12.692] <TB2> INFO: Test took 19284ms.
[14:16:12.836] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:12.859] <TB2> INFO: run 2 of 2
[14:16:32.063] <TB2> INFO: Test took 19204ms.
[14:16:32.260] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:32.300] <TB2> INFO: dacScan step from 40 .. 59
[14:16:32.300] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:16:32.300] <TB2> INFO: run 1 of 2
[14:16:54.105] <TB2> INFO: Test took 21805ms.
[14:16:54.276] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:54.308] <TB2> INFO: run 2 of 2
[14:17:15.915] <TB2> INFO: Test took 21607ms.
[14:17:16.084] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:16.116] <TB2> INFO: dacScan step from 60 .. 79
[14:17:16.116] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:17:16.116] <TB2> INFO: run 1 of 2
[14:17:37.300] <TB2> INFO: Test took 21184ms.
[14:17:37.465] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:37.492] <TB2> INFO: run 2 of 2
[14:17:59.038] <TB2> INFO: Test took 21546ms.
[14:17:59.208] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:59.238] <TB2> INFO: dacScan step from 80 .. 99
[14:17:59.238] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:17:59.238] <TB2> INFO: run 1 of 2
[14:18:20.930] <TB2> INFO: Test took 21692ms.
[14:18:21.099] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:21.129] <TB2> INFO: run 2 of 2
[14:18:42.490] <TB2> INFO: Test took 21361ms.
[14:18:42.659] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:42.688] <TB2> INFO: dacScan step from 100 .. 119
[14:18:42.688] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:18:42.688] <TB2> INFO: run 1 of 2
[14:19:03.795] <TB2> INFO: Test took 21107ms.
[14:19:03.968] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:03.998] <TB2> INFO: run 2 of 2
[14:19:25.524] <TB2> INFO: Test took 21526ms.
[14:19:25.705] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:25.733] <TB2> INFO: dacScan step from 120 .. 139
[14:19:25.733] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:19:25.733] <TB2> INFO: run 1 of 2
[14:19:46.818] <TB2> INFO: Test took 21084ms.
[14:19:46.980] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:47.009] <TB2> INFO: run 2 of 2
[14:20:07.399] <TB2> INFO: Test took 20390ms.
[14:20:07.565] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:07.599] <TB2> INFO: dacScan step from 140 .. 159
[14:20:07.599] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:20:07.599] <TB2> INFO: run 1 of 2
[14:20:27.864] <TB2> INFO: Test took 20265ms.
[14:20:28.037] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:28.066] <TB2> INFO: run 2 of 2
[14:20:48.957] <TB2> INFO: Test took 20891ms.
[14:20:49.137] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:49.170] <TB2> INFO: dacScan step from 160 .. 179
[14:20:49.170] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:20:49.170] <TB2> INFO: run 1 of 2
[14:21:08.772] <TB2> INFO: Test took 19602ms.
[14:21:08.943] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:08.978] <TB2> INFO: run 2 of 2
[14:21:28.304] <TB2> INFO: Test took 19326ms.
[14:21:28.472] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:28.517] <TB2> INFO: dacScan step from 180 .. 199
[14:21:28.517] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:21:28.517] <TB2> INFO: run 1 of 2
[14:21:48.218] <TB2> INFO: Test took 19701ms.
[14:21:48.377] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:48.406] <TB2> INFO: run 2 of 2
[14:22:08.961] <TB2> INFO: Test took 20555ms.
[14:22:09.137] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:36.462] <TB2> INFO: ---> TrimStepCorr4 extremal thresholds: 0.068688 .. 255.000000
[14:22:36.561] <TB2> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[14:22:36.569] <TB2> INFO: dacScan step from 0 .. 19
[14:22:36.569] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:22:36.569] <TB2> INFO: run 1 of 1
[14:22:50.808] <TB2> INFO: Test took 14239ms.
[14:22:50.830] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:50.830] <TB2> INFO: dacScan step from 20 .. 39
[14:22:50.830] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:22:50.830] <TB2> INFO: run 1 of 1
[14:23:06.915] <TB2> INFO: Test took 16084ms.
[14:23:06.998] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:07.014] <TB2> INFO: dacScan step from 40 .. 59
[14:23:07.014] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:23:07.014] <TB2> INFO: run 1 of 1
[14:23:25.971] <TB2> INFO: Test took 18957ms.
[14:23:26.130] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:26.162] <TB2> INFO: dacScan step from 60 .. 79
[14:23:26.162] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:23:26.162] <TB2> INFO: run 1 of 1
[14:23:45.329] <TB2> INFO: Test took 19168ms.
[14:23:45.474] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:45.503] <TB2> INFO: dacScan step from 80 .. 99
[14:23:45.503] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:23:45.503] <TB2> INFO: run 1 of 1
[14:24:04.637] <TB2> INFO: Test took 19134ms.
[14:24:04.867] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:04.919] <TB2> INFO: dacScan step from 100 .. 119
[14:24:04.930] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:24:04.930] <TB2> INFO: run 1 of 1
[14:24:24.125] <TB2> INFO: Test took 19195ms.
[14:24:24.267] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:24.324] <TB2> INFO: dacScan step from 120 .. 139
[14:24:24.324] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:24:24.324] <TB2> INFO: run 1 of 1
[14:24:43.477] <TB2> INFO: Test took 19153ms.
[14:24:43.626] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:43.663] <TB2> INFO: dacScan step from 140 .. 159
[14:24:43.663] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:24:43.663] <TB2> INFO: run 1 of 1
[14:25:01.449] <TB2> INFO: Test took 17786ms.
[14:25:01.595] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:01.631] <TB2> INFO: dacScan step from 160 .. 179
[14:25:01.631] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:25:01.631] <TB2> INFO: run 1 of 1
[14:25:20.565] <TB2> INFO: Test took 18934ms.
[14:25:20.800] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:20.896] <TB2> INFO: dacScan step from 180 .. 199
[14:25:20.896] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:25:20.896] <TB2> INFO: run 1 of 1
[14:25:40.104] <TB2> INFO: Test took 19208ms.
[14:25:40.263] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:40.355] <TB2> INFO: dacScan step from 200 .. 219
[14:25:40.384] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:25:40.384] <TB2> INFO: run 1 of 1
[14:25:59.006] <TB2> INFO: Test took 18622ms.
[14:25:59.147] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:59.177] <TB2> INFO: dacScan step from 220 .. 239
[14:25:59.177] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:25:59.177] <TB2> INFO: run 1 of 1
[14:26:15.945] <TB2> INFO: Test took 16768ms.
[14:26:16.085] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:16.118] <TB2> INFO: dacScan step from 240 .. 255
[14:26:16.118] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:26:16.118] <TB2> INFO: run 1 of 1
[14:26:30.055] <TB2> INFO: Test took 13937ms.
[14:26:30.165] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:03.046] <TB2> INFO: ---> TrimStepCorr2 extremal thresholds: 5.319571 .. 58.116966
[14:27:03.128] <TB2> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 5 .. 68 (20/-1) hits flags = 16 (plus default)
[14:27:03.136] <TB2> INFO: dacScan step from 5 .. 24
[14:27:03.136] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:27:03.136] <TB2> INFO: run 1 of 1
[14:27:17.563] <TB2> INFO: Test took 14427ms.
[14:27:17.589] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:17.589] <TB2> INFO: dacScan step from 25 .. 44
[14:27:17.589] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:27:17.589] <TB2> INFO: run 1 of 1
[14:27:32.531] <TB2> INFO: Test took 14942ms.
[14:27:32.651] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:32.676] <TB2> INFO: dacScan step from 45 .. 64
[14:27:32.676] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:27:32.676] <TB2> INFO: run 1 of 1
[14:27:49.424] <TB2> INFO: Test took 16748ms.
[14:27:49.580] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:49.618] <TB2> INFO: dacScan step from 65 .. 68
[14:27:49.618] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:27:49.618] <TB2> INFO: run 1 of 1
[14:27:55.238] <TB2> INFO: Test took 5620ms.
[14:27:55.267] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:12.826] <TB2> INFO: ---> TrimStepCorr1a extremal thresholds: 2.891168 .. 58.116966
[14:28:12.911] <TB2> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 2 .. 68 (20/-1) hits flags = 16 (plus default)
[14:28:12.920] <TB2> INFO: dacScan step from 2 .. 21
[14:28:12.920] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:28:12.920] <TB2> INFO: run 1 of 1
[14:28:26.430] <TB2> INFO: Test took 13510ms.
[14:28:26.455] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:26.455] <TB2> INFO: dacScan step from 22 .. 41
[14:28:26.455] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:28:26.455] <TB2> INFO: run 1 of 1
[14:28:36.054] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[14:28:36.054] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:28:36.054] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[14:28:36.054] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:28:42.138] <TB2> INFO: Test took 15683ms.
[14:28:42.222] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:42.240] <TB2> INFO: dacScan step from 42 .. 61
[14:28:42.240] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:28:42.240] <TB2> INFO: run 1 of 1
[14:28:59.056] <TB2> INFO: Test took 16816ms.
[14:28:59.219] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:59.252] <TB2> INFO: dacScan step from 62 .. 68
[14:28:59.252] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:28:59.252] <TB2> INFO: run 1 of 1
[14:29:07.301] <TB2> INFO: Test took 8049ms.
[14:29:07.353] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:24.100] <TB2> INFO: ---> TrimStepCorr1b extremal thresholds: 0.217241 .. 58.116966
[14:29:24.179] <TB2> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 68 (20/-1) hits flags = 16 (plus default)
[14:29:24.187] <TB2> INFO: dacScan step from 0 .. 19
[14:29:24.187] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:29:24.187] <TB2> INFO: run 1 of 1
[14:29:38.012] <TB2> INFO: Test took 13826ms.
[14:29:38.038] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:38.038] <TB2> INFO: dacScan step from 20 .. 39
[14:29:38.038] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:29:38.038] <TB2> INFO: run 1 of 1
[14:29:52.779] <TB2> INFO: Test took 14741ms.
[14:29:52.854] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:52.869] <TB2> INFO: dacScan step from 40 .. 59
[14:29:52.869] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:29:52.869] <TB2> INFO: run 1 of 1
[14:30:09.637] <TB2> INFO: Test took 16768ms.
[14:30:09.786] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:09.818] <TB2> INFO: dacScan step from 60 .. 68
[14:30:09.818] <TB2> INFO: dacScan split into 1 runs with ntrig = 4
[14:30:09.818] <TB2> INFO: run 1 of 1
[14:30:19.028] <TB2> INFO: Test took 9210ms.
[14:30:19.131] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:36.833] <TB2> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[14:30:36.833] <TB2> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[14:30:36.841] <TB2> INFO: dacScan step from 15 .. 34
[14:30:36.841] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:30:36.841] <TB2> INFO: run 1 of 2
[14:30:52.428] <TB2> INFO: Test took 15587ms.
[14:30:52.470] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:52.477] <TB2> INFO: run 2 of 2
[14:31:09.253] <TB2> INFO: Test took 16776ms.
[14:31:09.298] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:09.306] <TB2> INFO: dacScan step from 35 .. 54
[14:31:09.306] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:31:09.306] <TB2> INFO: run 1 of 2
[14:31:30.818] <TB2> INFO: Test took 21511ms.
[14:31:31.006] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:31.038] <TB2> INFO: run 2 of 2
[14:31:49.868] <TB2> INFO: Test took 18830ms.
[14:31:50.054] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:50.092] <TB2> INFO: dacScan step from 55 .. 55
[14:31:50.092] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:31:50.092] <TB2> INFO: run 1 of 2
[14:31:53.770] <TB2> INFO: Test took 3678ms.
[14:31:53.783] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:53.786] <TB2> INFO: run 2 of 2
[14:31:57.528] <TB2> INFO: Test took 3742ms.
[14:31:57.542] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:12.165] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C0.dat
[14:32:12.165] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C1.dat
[14:32:12.166] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C2.dat
[14:32:12.166] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C3.dat
[14:32:12.166] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C4.dat
[14:32:12.166] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C5.dat
[14:32:12.166] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C6.dat
[14:32:12.167] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C7.dat
[14:32:12.167] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C8.dat
[14:32:12.167] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C9.dat
[14:32:12.167] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C10.dat
[14:32:12.167] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C11.dat
[14:32:12.167] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C12.dat
[14:32:12.167] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C13.dat
[14:32:12.168] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C14.dat
[14:32:12.168] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C15.dat
[14:32:12.168] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C0.dat
[14:32:12.176] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C1.dat
[14:32:12.183] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C2.dat
[14:32:12.190] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C3.dat
[14:32:12.197] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C4.dat
[14:32:12.203] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C5.dat
[14:32:12.210] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C6.dat
[14:32:12.216] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C7.dat
[14:32:12.222] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C8.dat
[14:32:12.228] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C9.dat
[14:32:12.234] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C10.dat
[14:32:12.242] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C11.dat
[14:32:12.249] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C12.dat
[14:32:12.257] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C13.dat
[14:32:12.264] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C14.dat
[14:32:12.272] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//trimParameters35_C15.dat
[14:32:12.280] <TB2> INFO: PixTestTrim::trimTest() done
[14:32:12.280] <TB2> INFO: vtrim: 123 123 100 107 118 113 116 124 120 111 92 103 116 99 114 105
[14:32:12.280] <TB2> INFO: vthrcomp: 109 100 100 97 104 101 105 93 106 95 90 86 101 87 96 95
[14:32:12.280] <TB2> INFO: vcal mean: 35.11 35.09 35.13 35.07 35.13 35.03 35.11 35.06 35.02 35.04 35.11 35.08 35.06 35.06 35.01 35.10
[14:32:12.280] <TB2> INFO: vcal RMS: 1.45 1.25 1.23 1.12 1.13 1.07 1.14 0.99 1.19 1.03 1.01 1.00 1.03 1.07 1.03 1.09
[14:32:12.280] <TB2> INFO: bits mean: 8.94 9.58 9.65 9.82 9.18 10.11 8.83 10.10 8.63 9.69 9.71 10.26 9.49 10.48 10.24 9.79
[14:32:12.280] <TB2> INFO: bits RMS: 2.43 2.59 2.59 2.58 2.52 2.51 2.60 2.44 2.59 2.62 2.48 2.34 2.68 2.37 2.44 2.43
[14:32:12.289] <TB2> INFO: ----------------------------------------------------------------------
[14:32:12.289] <TB2> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[14:32:12.289] <TB2> INFO: ----------------------------------------------------------------------
[14:32:12.292] <TB2> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[14:32:12.301] <TB2> INFO: dacScan step from 0 .. 19
[14:32:12.301] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:32:12.301] <TB2> INFO: run 1 of 2
[14:32:27.572] <TB2> INFO: Test took 15271ms.
[14:32:27.602] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:27.602] <TB2> INFO: run 2 of 2
[14:32:42.636] <TB2> INFO: Test took 15034ms.
[14:32:42.658] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:42.658] <TB2> INFO: dacScan step from 20 .. 39
[14:32:42.658] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:32:42.658] <TB2> INFO: run 1 of 2
[14:32:57.576] <TB2> INFO: Test took 14918ms.
[14:32:57.602] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:57.602] <TB2> INFO: run 2 of 2
[14:33:12.779] <TB2> INFO: Test took 15177ms.
[14:33:12.808] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:12.808] <TB2> INFO: dacScan step from 40 .. 59
[14:33:12.808] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:33:12.808] <TB2> INFO: run 1 of 2
[14:33:27.947] <TB2> INFO: Test took 15139ms.
[14:33:27.975] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:27.975] <TB2> INFO: run 2 of 2
[14:33:43.170] <TB2> INFO: Test took 15195ms.
[14:33:43.195] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:43.195] <TB2> INFO: dacScan step from 60 .. 79
[14:33:43.195] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:33:43.195] <TB2> INFO: run 1 of 2
[14:33:58.347] <TB2> INFO: Test took 15152ms.
[14:33:58.375] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:58.375] <TB2> INFO: run 2 of 2
[14:34:13.485] <TB2> INFO: Test took 15110ms.
[14:34:13.508] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:13.508] <TB2> INFO: dacScan step from 80 .. 99
[14:34:13.508] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:34:13.508] <TB2> INFO: run 1 of 2
[14:34:23.586] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[14:34:23.586] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[14:34:23.586] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[14:34:23.586] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[14:34:27.937] <TB2> INFO: Test took 14429ms.
[14:34:27.963] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:27.963] <TB2> INFO: run 2 of 2
[14:34:42.985] <TB2> INFO: Test took 15022ms.
[14:34:43.016] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:43.016] <TB2> INFO: dacScan step from 100 .. 119
[14:34:43.016] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:34:43.016] <TB2> INFO: run 1 of 2
[14:34:59.317] <TB2> INFO: Test took 16301ms.
[14:34:59.386] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:59.397] <TB2> INFO: run 2 of 2
[14:35:16.301] <TB2> INFO: Test took 16904ms.
[14:35:16.367] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:16.374] <TB2> INFO: dacScan step from 120 .. 139
[14:35:16.374] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:35:16.374] <TB2> INFO: run 1 of 2
[14:35:36.860] <TB2> INFO: Test took 20486ms.
[14:35:37.024] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:37.048] <TB2> INFO: run 2 of 2
[14:35:58.351] <TB2> INFO: Test took 21303ms.
[14:35:58.508] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:58.533] <TB2> INFO: dacScan step from 140 .. 159
[14:35:58.533] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:35:58.533] <TB2> INFO: run 1 of 2
[14:36:20.925] <TB2> INFO: Test took 22392ms.
[14:36:21.103] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:21.133] <TB2> INFO: run 2 of 2
[14:36:43.949] <TB2> INFO: Test took 22816ms.
[14:36:44.152] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:44.189] <TB2> INFO: dacScan step from 160 .. 179
[14:36:44.190] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:36:44.190] <TB2> INFO: run 1 of 2
[14:37:07.385] <TB2> INFO: Test took 23195ms.
[14:37:07.672] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:07.760] <TB2> INFO: run 2 of 2
[14:37:30.787] <TB2> INFO: Test took 23027ms.
[14:37:30.955] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:30.985] <TB2> INFO: dacScan step from 180 .. 199
[14:37:30.985] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:37:30.985] <TB2> INFO: run 1 of 2
[14:37:54.442] <TB2> INFO: Test took 23456ms.
[14:37:54.605] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:54.637] <TB2> INFO: run 2 of 2
[14:38:14.754] <TB2> INFO: Test took 20117ms.
[14:38:15.027] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:41.547] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 187 (20/5) hits flags = 16 (plus default)
[14:38:41.556] <TB2> INFO: dacScan step from 0 .. 19
[14:38:41.556] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:38:41.556] <TB2> INFO: run 1 of 2
[14:38:56.956] <TB2> INFO: Test took 15400ms.
[14:38:56.984] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:56.984] <TB2> INFO: run 2 of 2
[14:39:11.623] <TB2> INFO: Test took 14639ms.
[14:39:11.644] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:11.644] <TB2> INFO: dacScan step from 20 .. 39
[14:39:11.644] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:39:11.644] <TB2> INFO: run 1 of 2
[14:39:26.252] <TB2> INFO: Test took 14608ms.
[14:39:26.274] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:26.274] <TB2> INFO: run 2 of 2
[14:39:41.236] <TB2> INFO: Test took 14962ms.
[14:39:41.257] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:41.257] <TB2> INFO: dacScan step from 40 .. 59
[14:39:41.257] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:39:41.257] <TB2> INFO: run 1 of 2
[14:39:55.989] <TB2> INFO: Test took 14732ms.
[14:39:56.016] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:56.016] <TB2> INFO: run 2 of 2
[14:40:11.335] <TB2> INFO: Test took 15319ms.
[14:40:11.360] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:11.361] <TB2> INFO: dacScan step from 60 .. 79
[14:40:11.361] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:40:11.361] <TB2> INFO: run 1 of 2
[14:40:26.489] <TB2> INFO: Test took 15128ms.
[14:40:26.519] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:26.519] <TB2> INFO: run 2 of 2
[14:40:41.764] <TB2> INFO: Test took 15245ms.
[14:40:41.791] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:41.791] <TB2> INFO: dacScan step from 80 .. 99
[14:40:41.791] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:40:41.791] <TB2> INFO: run 1 of 2
[14:40:57.120] <TB2> INFO: Test took 15329ms.
[14:40:57.152] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:57.153] <TB2> INFO: run 2 of 2
[14:41:13.120] <TB2> INFO: Test took 15967ms.
[14:41:13.155] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:13.158] <TB2> INFO: dacScan step from 100 .. 119
[14:41:13.158] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:41:13.158] <TB2> INFO: run 1 of 2
[14:41:32.064] <TB2> INFO: Test took 18906ms.
[14:41:32.181] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:32.197] <TB2> INFO: run 2 of 2
[14:41:51.616] <TB2> INFO: Test took 19419ms.
[14:41:51.742] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:51.759] <TB2> INFO: dacScan step from 120 .. 139
[14:41:51.759] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:41:51.759] <TB2> INFO: run 1 of 2
[14:42:13.586] <TB2> INFO: Test took 21827ms.
[14:42:13.769] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:13.799] <TB2> INFO: run 2 of 2
[14:42:36.068] <TB2> INFO: Test took 22269ms.
[14:42:36.261] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:36.292] <TB2> INFO: dacScan step from 140 .. 159
[14:42:36.292] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:42:36.292] <TB2> INFO: run 1 of 2
[14:42:58.739] <TB2> INFO: Test took 22447ms.
[14:42:58.923] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:58.955] <TB2> INFO: run 2 of 2
[14:43:20.718] <TB2> INFO: Test took 21763ms.
[14:43:20.904] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:20.932] <TB2> INFO: dacScan step from 160 .. 179
[14:43:20.932] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:43:20.932] <TB2> INFO: run 1 of 2
[14:43:41.810] <TB2> INFO: Test took 20878ms.
[14:43:41.979] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:42.011] <TB2> INFO: run 2 of 2
[14:44:01.153] <TB2> INFO: Test took 19142ms.
[14:44:01.416] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:01.448] <TB2> INFO: dacScan step from 180 .. 187
[14:44:01.448] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:44:01.448] <TB2> INFO: run 1 of 2
[14:44:11.342] <TB2> INFO: Test took 9894ms.
[14:44:11.405] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:11.418] <TB2> INFO: run 2 of 2
[14:44:21.477] <TB2> INFO: Test took 10059ms.
[14:44:21.544] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:47.116] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 171 (20/5) hits flags = 16 (plus default)
[14:44:47.124] <TB2> INFO: dacScan step from 0 .. 19
[14:44:47.124] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:44:47.124] <TB2> INFO: run 1 of 2
[14:45:02.403] <TB2> INFO: Test took 15279ms.
[14:45:02.424] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:02.424] <TB2> INFO: run 2 of 2
[14:45:18.413] <TB2> INFO: Test took 15989ms.
[14:45:18.442] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:18.442] <TB2> INFO: dacScan step from 20 .. 39
[14:45:18.442] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:45:18.442] <TB2> INFO: run 1 of 2
[14:45:34.179] <TB2> INFO: Test took 15737ms.
[14:45:34.202] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:34.202] <TB2> INFO: run 2 of 2
[14:45:50.155] <TB2> INFO: Test took 15953ms.
[14:45:50.181] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:50.181] <TB2> INFO: dacScan step from 40 .. 59
[14:45:50.181] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:45:50.181] <TB2> INFO: run 1 of 2
[14:46:06.313] <TB2> INFO: Test took 16132ms.
[14:46:06.340] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:06.340] <TB2> INFO: run 2 of 2
[14:46:22.682] <TB2> INFO: Test took 16342ms.
[14:46:22.702] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:22.702] <TB2> INFO: dacScan step from 60 .. 79
[14:46:22.702] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:46:22.702] <TB2> INFO: run 1 of 2
[14:46:39.098] <TB2> INFO: Test took 16396ms.
[14:46:39.118] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:39.118] <TB2> INFO: run 2 of 2
[14:46:55.696] <TB2> INFO: Test took 16578ms.
[14:46:55.722] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:55.722] <TB2> INFO: dacScan step from 80 .. 99
[14:46:55.722] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:46:55.722] <TB2> INFO: run 1 of 2
[14:47:11.633] <TB2> INFO: Test took 15911ms.
[14:47:11.664] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:11.666] <TB2> INFO: run 2 of 2
[14:47:26.927] <TB2> INFO: Test took 15261ms.
[14:47:26.961] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:26.963] <TB2> INFO: dacScan step from 100 .. 119
[14:47:26.963] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:47:26.963] <TB2> INFO: run 1 of 2
[14:47:44.515] <TB2> INFO: Test took 17551ms.
[14:47:44.635] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:44.651] <TB2> INFO: run 2 of 2
[14:48:02.866] <TB2> INFO: Test took 18215ms.
[14:48:02.982] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:02.998] <TB2> INFO: dacScan step from 120 .. 139
[14:48:02.998] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:48:02.998] <TB2> INFO: run 1 of 2
[14:48:24.400] <TB2> INFO: Test took 21402ms.
[14:48:24.578] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:24.611] <TB2> INFO: run 2 of 2
[14:48:46.020] <TB2> INFO: Test took 21409ms.
[14:48:46.209] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:46.243] <TB2> INFO: dacScan step from 140 .. 159
[14:48:46.243] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:48:46.243] <TB2> INFO: run 1 of 2
[14:49:05.369] <TB2> INFO: Test took 19126ms.
[14:49:05.540] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:05.597] <TB2> INFO: run 2 of 2
[14:49:27.004] <TB2> INFO: Test took 21407ms.
[14:49:27.190] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:27.222] <TB2> INFO: dacScan step from 160 .. 171
[14:49:27.222] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:49:27.222] <TB2> INFO: run 1 of 2
[14:49:40.127] <TB2> INFO: Test took 12904ms.
[14:49:40.222] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:40.247] <TB2> INFO: run 2 of 2
[14:49:54.229] <TB2> INFO: Test took 13982ms.
[14:49:54.327] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:18.105] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 173 (20/5) hits flags = 16 (plus default)
[14:50:18.114] <TB2> INFO: dacScan step from 0 .. 19
[14:50:18.114] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:50:18.114] <TB2> INFO: run 1 of 2
[14:50:33.491] <TB2> INFO: Test took 15377ms.
[14:50:33.514] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:33.514] <TB2> INFO: run 2 of 2
[14:50:48.939] <TB2> INFO: Test took 15425ms.
[14:50:48.964] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:48.964] <TB2> INFO: dacScan step from 20 .. 39
[14:50:48.964] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:50:48.964] <TB2> INFO: run 1 of 2
[14:51:04.501] <TB2> INFO: Test took 15537ms.
[14:51:04.525] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:04.525] <TB2> INFO: run 2 of 2
[14:51:20.055] <TB2> INFO: Test took 15530ms.
[14:51:20.081] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:20.081] <TB2> INFO: dacScan step from 40 .. 59
[14:51:20.081] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:51:20.081] <TB2> INFO: run 1 of 2
[14:51:35.703] <TB2> INFO: Test took 15622ms.
[14:51:35.730] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:35.730] <TB2> INFO: run 2 of 2
[14:51:51.335] <TB2> INFO: Test took 15605ms.
[14:51:51.362] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:51.362] <TB2> INFO: dacScan step from 60 .. 79
[14:51:51.362] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:51:51.362] <TB2> INFO: run 1 of 2
[14:52:06.588] <TB2> INFO: Test took 15226ms.
[14:52:06.615] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:06.615] <TB2> INFO: run 2 of 2
[14:52:21.841] <TB2> INFO: Test took 15226ms.
[14:52:21.864] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:21.864] <TB2> INFO: dacScan step from 80 .. 99
[14:52:21.864] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:52:21.864] <TB2> INFO: run 1 of 2
[14:52:37.939] <TB2> INFO: Test took 16075ms.
[14:52:37.971] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:37.974] <TB2> INFO: run 2 of 2
[14:52:54.370] <TB2> INFO: Test took 16396ms.
[14:52:54.402] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:54.405] <TB2> INFO: dacScan step from 100 .. 119
[14:52:54.405] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:52:54.405] <TB2> INFO: run 1 of 2
[14:53:12.650] <TB2> INFO: Test took 18245ms.
[14:53:12.766] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:12.782] <TB2> INFO: run 2 of 2
[14:53:30.790] <TB2> INFO: Test took 18008ms.
[14:53:30.910] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:30.927] <TB2> INFO: dacScan step from 120 .. 139
[14:53:30.927] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:53:30.927] <TB2> INFO: run 1 of 2
[14:53:49.788] <TB2> INFO: Test took 18861ms.
[14:53:49.968] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:49.999] <TB2> INFO: run 2 of 2
[14:54:08.948] <TB2> INFO: Test took 18949ms.
[14:54:09.124] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:09.158] <TB2> INFO: dacScan step from 140 .. 159
[14:54:09.158] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:54:09.158] <TB2> INFO: run 1 of 2
[14:54:28.599] <TB2> INFO: Test took 19441ms.
[14:54:28.770] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:28.800] <TB2> INFO: run 2 of 2
[14:54:49.349] <TB2> INFO: Test took 20549ms.
[14:54:49.531] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:49.574] <TB2> INFO: dacScan step from 160 .. 173
[14:54:49.574] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:54:49.574] <TB2> INFO: run 1 of 2
[14:55:05.088] <TB2> INFO: Test took 15513ms.
[14:55:05.199] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:05.221] <TB2> INFO: run 2 of 2
[14:55:20.585] <TB2> INFO: Test took 15363ms.
[14:55:20.703] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:45.289] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 171 (20/5) hits flags = 16 (plus default)
[14:55:45.297] <TB2> INFO: dacScan step from 0 .. 19
[14:55:45.297] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:55:45.297] <TB2> INFO: run 1 of 2
[14:56:00.920] <TB2> INFO: Test took 15623ms.
[14:56:00.943] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:00.943] <TB2> INFO: run 2 of 2
[14:56:16.951] <TB2> INFO: Test took 16007ms.
[14:56:16.979] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:16.979] <TB2> INFO: dacScan step from 20 .. 39
[14:56:16.979] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:56:16.979] <TB2> INFO: run 1 of 2
[14:56:32.633] <TB2> INFO: Test took 15654ms.
[14:56:32.660] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:32.670] <TB2> INFO: run 2 of 2
[14:56:48.335] <TB2> INFO: Test took 15665ms.
[14:56:48.360] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:48.360] <TB2> INFO: dacScan step from 40 .. 59
[14:56:48.360] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:56:48.360] <TB2> INFO: run 1 of 2
[14:57:03.645] <TB2> INFO: Test took 15285ms.
[14:57:03.672] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:03.672] <TB2> INFO: run 2 of 2
[14:57:18.846] <TB2> INFO: Test took 15174ms.
[14:57:18.871] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:18.871] <TB2> INFO: dacScan step from 60 .. 79
[14:57:18.871] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:57:18.871] <TB2> INFO: run 1 of 2
[14:57:34.897] <TB2> INFO: Test took 16026ms.
[14:57:34.921] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:34.921] <TB2> INFO: run 2 of 2
[14:57:51.222] <TB2> INFO: Test took 16301ms.
[14:57:51.243] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:51.243] <TB2> INFO: dacScan step from 80 .. 99
[14:57:51.243] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:57:51.243] <TB2> INFO: run 1 of 2
[14:58:06.647] <TB2> INFO: Test took 15404ms.
[14:58:06.682] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:06.684] <TB2> INFO: run 2 of 2
[14:58:22.078] <TB2> INFO: Test took 15394ms.
[14:58:22.118] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:22.120] <TB2> INFO: dacScan step from 100 .. 119
[14:58:22.120] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:58:22.120] <TB2> INFO: run 1 of 2
[14:58:40.605] <TB2> INFO: Test took 18485ms.
[14:58:40.721] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:40.738] <TB2> INFO: run 2 of 2
[14:58:57.367] <TB2> INFO: Test took 16629ms.
[14:58:57.489] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:57.506] <TB2> INFO: dacScan step from 120 .. 139
[14:58:57.506] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:58:57.506] <TB2> INFO: run 1 of 2
[14:59:18.131] <TB2> INFO: Test took 20624ms.
[14:59:18.315] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:18.346] <TB2> INFO: run 2 of 2
[14:59:38.197] <TB2> INFO: Test took 19851ms.
[14:59:38.459] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:38.510] <TB2> INFO: dacScan step from 140 .. 159
[14:59:38.510] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[14:59:38.510] <TB2> INFO: run 1 of 2
[14:59:58.883] <TB2> INFO: Test took 20374ms.
[14:59:59.048] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:59.079] <TB2> INFO: run 2 of 2
[15:00:20.388] <TB2> INFO: Test took 21309ms.
[15:00:20.560] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:20.591] <TB2> INFO: dacScan step from 160 .. 171
[15:00:20.591] <TB2> INFO: dacScan split into 2 runs with ntrig = 5
[15:00:20.591] <TB2> INFO: run 1 of 2
[15:00:27.896] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (2) != Token Chain Length (4)
[15:00:27.896] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[15:00:27.897] <TB2> WARNING: Channel 2 ROC 3: Readback start marker after 15 readouts!
[15:00:27.897] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[15:00:34.555] <TB2> INFO: Test took 13964ms.
[15:00:34.662] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:34.681] <TB2> INFO: run 2 of 2
[15:00:48.804] <TB2> INFO: Test took 14123ms.
[15:00:48.911] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:13.474] <TB2> INFO: PixTestTrim::trimBitTest() done
[15:01:13.476] <TB2> INFO: PixTestTrim::doTest() done, duration: 3204 seconds
[15:01:14.167] <TB2> INFO: ######################################################################
[15:01:14.167] <TB2> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[15:01:14.167] <TB2> INFO: ######################################################################
[15:01:17.885] <TB2> INFO: Test took 3716ms.
[15:01:17.908] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:21.767] <TB2> INFO: Test took 3662ms.
[15:01:21.837] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:25.597] <TB2> INFO: Test took 3749ms.
[15:01:25.666] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:25.673] <TB2> INFO: The DUT currently contains the following objects:
[15:01:25.674] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:25.674] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:25.674] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:25.674] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:25.674] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:25.674] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.781] <TB2> INFO: Test took 1107ms.
[15:01:26.782] <TB2> INFO: The DUT currently contains the following objects:
[15:01:26.782] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:26.782] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:26.782] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:26.782] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:26.782] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.782] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.782] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:26.783] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.890] <TB2> INFO: Test took 1107ms.
[15:01:27.891] <TB2> INFO: The DUT currently contains the following objects:
[15:01:27.891] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:27.891] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:27.891] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:27.891] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:27.891] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:27.891] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:28.999] <TB2> INFO: Test took 1108ms.
[15:01:29.001] <TB2> INFO: The DUT currently contains the following objects:
[15:01:29.001] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:29.001] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:29.001] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:29.001] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:29.001] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.001] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.001] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.001] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.001] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.001] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.001] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.002] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.002] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.002] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.002] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.002] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.002] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.002] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.002] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:29.002] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.108] <TB2> INFO: Test took 1106ms.
[15:01:30.109] <TB2> INFO: The DUT currently contains the following objects:
[15:01:30.121] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:30.121] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:30.121] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:30.121] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:30.121] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.121] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.122] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.122] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.122] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.122] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:30.122] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.216] <TB2> INFO: Test took 1094ms.
[15:01:31.217] <TB2> INFO: The DUT currently contains the following objects:
[15:01:31.217] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:31.217] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:31.217] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:31.217] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:31.217] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.217] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.217] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.217] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.217] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.217] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.217] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.218] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.218] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.218] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.218] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.218] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.218] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.218] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.218] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:31.218] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.353] <TB2> INFO: Test took 1135ms.
[15:01:32.355] <TB2> INFO: The DUT currently contains the following objects:
[15:01:32.355] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:32.355] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:32.355] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:32.355] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:32.355] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:32.355] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.462] <TB2> INFO: Test took 1107ms.
[15:01:33.463] <TB2> INFO: The DUT currently contains the following objects:
[15:01:33.463] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:33.463] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:33.463] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:33.463] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:33.463] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:33.463] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.570] <TB2> INFO: Test took 1106ms.
[15:01:34.571] <TB2> INFO: The DUT currently contains the following objects:
[15:01:34.571] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:34.571] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:34.571] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:34.571] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:34.571] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:34.571] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.708] <TB2> INFO: Test took 1137ms.
[15:01:35.709] <TB2> INFO: The DUT currently contains the following objects:
[15:01:35.709] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:35.709] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:35.709] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:35.709] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:35.709] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.709] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.709] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.709] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.709] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.709] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.709] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.709] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.709] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.710] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.710] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.710] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.710] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.710] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.710] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:35.710] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.846] <TB2> INFO: Test took 1136ms.
[15:01:36.849] <TB2> INFO: The DUT currently contains the following objects:
[15:01:36.849] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:36.849] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:36.849] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:36.849] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:36.849] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:36.849] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.968] <TB2> INFO: Test took 1119ms.
[15:01:37.969] <TB2> INFO: The DUT currently contains the following objects:
[15:01:37.969] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:37.969] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:37.969] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:37.970] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:37.970] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:37.970] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.092] <TB2> INFO: Test took 1122ms.
[15:01:39.093] <TB2> INFO: The DUT currently contains the following objects:
[15:01:39.094] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:39.094] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:39.094] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:39.094] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:39.094] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:39.094] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.216] <TB2> INFO: Test took 1122ms.
[15:01:40.217] <TB2> INFO: The DUT currently contains the following objects:
[15:01:40.217] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:40.217] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:40.217] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:40.217] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:40.217] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.217] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.218] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.218] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:40.218] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.324] <TB2> INFO: Test took 1106ms.
[15:01:41.326] <TB2> INFO: The DUT currently contains the following objects:
[15:01:41.326] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:41.326] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:41.326] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:41.326] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:41.326] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:41.327] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.434] <TB2> INFO: Test took 1107ms.
[15:01:42.435] <TB2> INFO: The DUT currently contains the following objects:
[15:01:42.435] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[15:01:42.435] <TB2> INFO: TBM Core alpha (0): 7 registers set
[15:01:42.435] <TB2> INFO: TBM Core beta (1): 7 registers set
[15:01:42.435] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:01:42.435] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.435] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.435] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.435] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.435] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.435] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:42.436] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:01:43.540] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (3) != Token Chain Length (4)
[15:01:43.540] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[15:01:43.544] <TB2> INFO: Test took 1108ms.
[15:01:43.548] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:05:59.921] <TB2> INFO: Test took 256373ms.
[15:06:01.475] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:09:57.767] <TB2> INFO: Test took 236292ms.
[15:09:59.480] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.487] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.494] <TB2> INFO: safety margin for low PH: adding 1, margin is now 21
[15:09:59.501] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.508] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.515] <TB2> INFO: safety margin for low PH: adding 1, margin is now 21
[15:09:59.522] <TB2> INFO: safety margin for low PH: adding 2, margin is now 22
[15:09:59.529] <TB2> INFO: safety margin for low PH: adding 3, margin is now 23
[15:09:59.536] <TB2> INFO: safety margin for low PH: adding 4, margin is now 24
[15:09:59.543] <TB2> INFO: safety margin for low PH: adding 5, margin is now 25
[15:09:59.550] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.557] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.564] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.570] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.577] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.584] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.591] <TB2> INFO: safety margin for low PH: adding 1, margin is now 21
[15:09:59.598] <TB2> INFO: safety margin for low PH: adding 2, margin is now 22
[15:09:59.605] <TB2> INFO: safety margin for low PH: adding 3, margin is now 23
[15:09:59.612] <TB2> INFO: safety margin for low PH: adding 4, margin is now 24
[15:09:59.619] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.626] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.633] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.640] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.647] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.654] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[15:09:59.691] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C0.dat
[15:09:59.691] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C1.dat
[15:09:59.691] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C2.dat
[15:09:59.691] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C3.dat
[15:09:59.691] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C4.dat
[15:09:59.691] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C5.dat
[15:09:59.691] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C6.dat
[15:09:59.692] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C7.dat
[15:09:59.692] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C8.dat
[15:09:59.692] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C9.dat
[15:09:59.692] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C10.dat
[15:09:59.692] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C11.dat
[15:09:59.692] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C12.dat
[15:09:59.692] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C13.dat
[15:09:59.693] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C14.dat
[15:09:59.693] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//dacParameters35_C15.dat
[15:10:03.179] <TB2> INFO: Test took 3484ms.
[15:10:06.922] <TB2> INFO: Test took 3466ms.
[15:10:10.678] <TB2> INFO: Test took 3477ms.
[15:10:10.972] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:11.890] <TB2> INFO: Test took 918ms.
[15:10:11.893] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:13.029] <TB2> INFO: Test took 1136ms.
[15:10:13.032] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:14.137] <TB2> INFO: Test took 1105ms.
[15:10:14.141] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:15.247] <TB2> INFO: Test took 1107ms.
[15:10:15.250] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:16.356] <TB2> INFO: Test took 1106ms.
[15:10:16.360] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:17.482] <TB2> INFO: Test took 1123ms.
[15:10:17.485] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:18.606] <TB2> INFO: Test took 1121ms.
[15:10:18.610] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:19.717] <TB2> INFO: Test took 1107ms.
[15:10:19.720] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:20.827] <TB2> INFO: Test took 1108ms.
[15:10:20.831] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:21.966] <TB2> INFO: Test took 1135ms.
[15:10:21.969] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:23.075] <TB2> INFO: Test took 1106ms.
[15:10:23.078] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:24.184] <TB2> INFO: Test took 1106ms.
[15:10:24.187] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:25.296] <TB2> INFO: Test took 1109ms.
[15:10:25.299] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:26.420] <TB2> INFO: Test took 1121ms.
[15:10:26.424] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:27.545] <TB2> INFO: Test took 1121ms.
[15:10:27.548] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:28.656] <TB2> INFO: Test took 1109ms.
[15:10:28.661] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:29.769] <TB2> INFO: Test took 1108ms.
[15:10:29.773] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:30.887] <TB2> INFO: Test took 1115ms.
[15:10:30.889] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:31.996] <TB2> INFO: Test took 1107ms.
[15:10:32.000] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:33.108] <TB2> INFO: Test took 1108ms.
[15:10:33.112] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:34.219] <TB2> INFO: Test took 1108ms.
[15:10:34.223] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:35.323] <TB2> INFO: Test took 1101ms.
[15:10:35.325] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:36.431] <TB2> INFO: Test took 1106ms.
[15:10:36.435] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:37.543] <TB2> INFO: Test took 1108ms.
[15:10:37.547] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:38.654] <TB2> INFO: Test took 1107ms.
[15:10:38.658] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:39.758] <TB2> INFO: Test took 1101ms.
[15:10:39.761] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:40.869] <TB2> INFO: Test took 1109ms.
[15:10:40.873] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:41.981] <TB2> INFO: Test took 1108ms.
[15:10:41.984] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:43.105] <TB2> INFO: Test took 1121ms.
[15:10:43.109] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:44.209] <TB2> INFO: Test took 1100ms.
[15:10:44.211] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:45.320] <TB2> INFO: Test took 1109ms.
[15:10:45.324] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:46.431] <TB2> INFO: Test took 1108ms.
[15:10:46.954] <TB2> INFO: PixTestPhOptimization::doTest() done, duration: 572 seconds
[15:10:46.954] <TB2> INFO: PH scale (per ROC): 69 67 69 68 77 76 71 78 78 80 75 73 76 78 79 74
[15:10:46.954] <TB2> INFO: PH offset (per ROC): 184 192 176 176 181 181 190 174 177 177 164 162 175 171 158 173
[15:10:47.131] <TB2> INFO: ######################################################################
[15:10:47.131] <TB2> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[15:10:47.131] <TB2> INFO: ######################################################################
[15:10:47.141] <TB2> INFO: scanning low vcal = 10
[15:10:50.939] <TB2> INFO: Test took 3798ms.
[15:10:50.942] <TB2> INFO: scanning low vcal = 20
[15:10:54.725] <TB2> INFO: Test took 3783ms.
[15:10:54.728] <TB2> INFO: scanning low vcal = 30
[15:10:58.567] <TB2> INFO: Test took 3839ms.
[15:10:58.573] <TB2> INFO: scanning low vcal = 40
[15:11:02.828] <TB2> INFO: Test took 4255ms.
[15:11:02.884] <TB2> INFO: scanning low vcal = 50
[15:11:07.114] <TB2> INFO: Test took 4230ms.
[15:11:07.176] <TB2> INFO: scanning low vcal = 60
[15:11:11.483] <TB2> INFO: Test took 4307ms.
[15:11:11.581] <TB2> INFO: scanning low vcal = 70
[15:11:15.856] <TB2> INFO: Test took 4275ms.
[15:11:15.941] <TB2> INFO: scanning low vcal = 80
[15:11:20.199] <TB2> INFO: Test took 4258ms.
[15:11:20.297] <TB2> INFO: scanning low vcal = 90
[15:11:24.601] <TB2> INFO: Test took 4304ms.
[15:11:24.658] <TB2> INFO: scanning low vcal = 100
[15:11:28.906] <TB2> INFO: Test took 4248ms.
[15:11:28.961] <TB2> INFO: scanning low vcal = 110
[15:11:33.187] <TB2> INFO: Test took 4226ms.
[15:11:33.244] <TB2> INFO: scanning low vcal = 120
[15:11:37.624] <TB2> INFO: Test took 4380ms.
[15:11:37.708] <TB2> INFO: scanning low vcal = 130
[15:11:42.162] <TB2> INFO: Test took 4454ms.
[15:11:42.226] <TB2> INFO: scanning low vcal = 140
[15:11:46.585] <TB2> INFO: Test took 4359ms.
[15:11:46.648] <TB2> INFO: scanning low vcal = 150
[15:11:51.010] <TB2> INFO: Test took 4362ms.
[15:11:51.069] <TB2> INFO: scanning low vcal = 160
[15:11:55.501] <TB2> INFO: Test took 4432ms.
[15:11:55.582] <TB2> INFO: scanning low vcal = 170
[15:11:59.945] <TB2> INFO: Test took 4363ms.
[15:12:00.008] <TB2> INFO: scanning low vcal = 180
[15:12:04.390] <TB2> INFO: Test took 4382ms.
[15:12:04.454] <TB2> INFO: scanning low vcal = 190
[15:12:09.010] <TB2> INFO: Test took 4556ms.
[15:12:09.067] <TB2> INFO: scanning low vcal = 200
[15:12:12.437] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 2 Number of ROCs (3) != Token Chain Length (4)
[15:12:13.446] <TB2> INFO: Test took 4379ms.
[15:12:13.508] <TB2> INFO: scanning low vcal = 210
[15:12:17.937] <TB2> INFO: Test took 4429ms.
[15:12:18.000] <TB2> INFO: scanning low vcal = 220
[15:12:22.346] <TB2> INFO: Test took 4346ms.
[15:12:22.408] <TB2> INFO: scanning low vcal = 230
[15:12:26.783] <TB2> INFO: Test took 4375ms.
[15:12:26.863] <TB2> INFO: scanning low vcal = 240
[15:12:31.230] <TB2> INFO: Test took 4367ms.
[15:12:31.297] <TB2> INFO: scanning low vcal = 250
[15:12:35.747] <TB2> INFO: Test took 4450ms.
[15:12:35.838] <TB2> INFO: scanning high vcal = 30 (= 210 in low range)
[15:12:40.218] <TB2> INFO: Test took 4380ms.
[15:12:40.277] <TB2> INFO: scanning high vcal = 50 (= 350 in low range)
[15:12:44.632] <TB2> INFO: Test took 4355ms.
[15:12:44.696] <TB2> INFO: scanning high vcal = 70 (= 490 in low range)
[15:12:49.057] <TB2> INFO: Test took 4361ms.
[15:12:49.124] <TB2> INFO: scanning high vcal = 90 (= 630 in low range)
[15:12:53.503] <TB2> INFO: Test took 4379ms.
[15:12:53.580] <TB2> INFO: scanning high vcal = 200 (= 1400 in low range)
[15:12:57.914] <TB2> INFO: Test took 4334ms.
[15:12:58.457] <TB2> INFO: PixTestGainPedestal::measure() done
[15:13:31.034] <TB2> INFO: PixTestGainPedestal::fit() done
[15:13:31.034] <TB2> INFO: non-linearity mean: 0.957 0.958 0.962 0.963 0.957 0.961 0.962 0.953 0.958 0.961 0.954 0.949 0.960 0.953 0.956 0.958
[15:13:31.034] <TB2> INFO: non-linearity RMS: 0.008 0.006 0.010 0.007 0.007 0.006 0.006 0.007 0.006 0.006 0.006 0.009 0.006 0.007 0.007 0.006
[15:13:31.035] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C0.dat
[15:13:31.053] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C1.dat
[15:13:31.072] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C2.dat
[15:13:31.090] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C3.dat
[15:13:31.109] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C4.dat
[15:13:31.127] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C5.dat
[15:13:31.146] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C6.dat
[15:13:31.164] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C7.dat
[15:13:31.183] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C8.dat
[15:13:31.201] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C9.dat
[15:13:31.222] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C10.dat
[15:13:31.240] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C11.dat
[15:13:31.259] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C12.dat
[15:13:31.278] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C13.dat
[15:13:31.296] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C14.dat
[15:13:31.315] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//phCalibrationFitErr35_C15.dat
[15:13:31.333] <TB2> INFO: PixTestGainPedestal::doTest() done, duration: 164 seconds
[15:13:31.339] <TB2> INFO: readReadbackCal: /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C0.dat .. /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C15.dat
[15:13:31.340] <TB2> INFO: PixTestReadback::doTest() start.
[15:13:31.341] <TB2> INFO: PixTestReadback::RES sent once
[15:13:47.842] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C0.dat
[15:13:47.843] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C1.dat
[15:13:47.843] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C2.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C3.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C4.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C5.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C6.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C7.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C8.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C9.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C10.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C11.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C12.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C13.dat
[15:13:47.844] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C14.dat
[15:13:47.845] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C15.dat
[15:13:47.879] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[15:13:47.879] <TB2> INFO: PixTestReadback::RES sent once
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C0.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C1.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C2.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C3.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C4.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C5.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C6.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C7.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C8.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C9.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C10.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C11.dat
[15:14:04.306] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C12.dat
[15:14:04.307] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C13.dat
[15:14:04.307] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C14.dat
[15:14:04.307] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C15.dat
[15:14:04.335] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[15:14:04.335] <TB2> INFO: PixTestReadback::RES sent once
[15:14:17.052] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[15:14:17.052] <TB2> INFO: Vbg will be calibrated using Vd calibration
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 163.9calibrated Vbg = 1.20502 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 160calibrated Vbg = 1.20703 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 156.6calibrated Vbg = 1.21199 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 156calibrated Vbg = 1.22224 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 151.9calibrated Vbg = 1.22355 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 156.6calibrated Vbg = 1.22616 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 150.2calibrated Vbg = 1.2222 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 161.6calibrated Vbg = 1.22204 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 151.5calibrated Vbg = 1.21032 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 161.7calibrated Vbg = 1.21448 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 155.6calibrated Vbg = 1.20822 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 156.7calibrated Vbg = 1.20989 :::*/*/*/*/
[15:14:17.053] <TB2> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 255calibrated Vbg = 1.1775 :::*/*/*/*/
[15:14:17.057] <TB2> INFO: PixTestReadback::RES sent once
[15:18:11.541] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C0.dat
[15:18:11.541] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C1.dat
[15:18:11.541] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C2.dat
[15:18:11.541] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C3.dat
[15:18:11.541] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C4.dat
[15:18:11.541] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C5.dat
[15:18:11.541] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C6.dat
[15:18:11.542] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C7.dat
[15:18:11.542] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C8.dat
[15:18:11.542] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C9.dat
[15:18:11.542] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C10.dat
[15:18:11.542] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C11.dat
[15:18:11.542] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C12.dat
[15:18:11.542] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C13.dat
[15:18:11.542] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C14.dat
[15:18:11.542] <TB2> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2086_FullQualification_2015-08-25_10h29m_1440491371//004_FulltestPxar_p17//readbackCal_C15.dat
[15:18:11.569] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[15:18:11.570] <TB2> INFO: PixTestReadback::doTest() done
[15:18:11.582] <TB2> INFO: enter test to run
[15:18:11.582] <TB2> INFO: test: exit no parameter change
[15:18:12.128] <TB2> QUIET: Connection to board 156 closed.
[15:18:12.208] <TB2> INFO: pXar: this is the end, my friend