Test Date: 2015-08-25 10:29
Analysis date: 2016-05-26 02:54
Logfile
LogfileView
[08:37:06.309] <TB1> INFO: *** Welcome to pxar ***
[08:37:06.309] <TB1> INFO: *** Today: 2015/08/25
[08:37:06.309] <TB1> INFO: readRocDacs: /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C15.dat
[08:37:06.310] <TB1> INFO: readTbmDacs: /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//tbmParameters_C0b.dat
[08:37:06.310] <TB1> INFO: readMaskFile: /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//defaultMaskFile.dat
[08:37:06.310] <TB1> INFO: readTrimFile: /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters_C15.dat
[08:37:06.378] <TB1> INFO: clk: 4
[08:37:06.378] <TB1> INFO: ctr: 4
[08:37:06.378] <TB1> INFO: sda: 19
[08:37:06.378] <TB1> INFO: tin: 9
[08:37:06.378] <TB1> INFO: level: 15
[08:37:06.378] <TB1> INFO: triggerdelay: 0
[08:37:06.378] <TB1> QUIET: Instanciating API for pxar prod-01+86~g1838649
[08:37:06.378] <TB1> INFO: Log level: INFO
[08:37:06.386] <TB1> INFO: Found DTB DTB_WXBYFL
[08:37:06.398] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[08:37:06.402] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[08:37:06.405] <TB1> INFO: RPC call hashes of host and DTB match: 447413373
[08:37:07.927] <TB1> INFO: DUT info:
[08:37:07.927] <TB1> INFO: The DUT currently contains the following objects:
[08:37:07.927] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[08:37:07.927] <TB1> INFO: TBM Core alpha (0): 7 registers set
[08:37:07.927] <TB1> INFO: TBM Core beta (1): 7 registers set
[08:37:07.927] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[08:37:07.927] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.927] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.927] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:07.928] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[08:37:08.330] <TB1> INFO: enter 'restricted' command line mode
[08:37:08.330] <TB1> INFO: enter test to run
[08:37:08.330] <TB1> INFO: test: pretest no parameter change
[08:37:08.330] <TB1> INFO: running: pretest
[08:37:08.337] <TB1> INFO: ######################################################################
[08:37:08.337] <TB1> INFO: PixTestPretest::doTest()
[08:37:08.337] <TB1> INFO: ######################################################################
[08:37:08.339] <TB1> INFO: ----------------------------------------------------------------------
[08:37:08.339] <TB1> INFO: PixTestPretest::programROC()
[08:37:08.339] <TB1> INFO: ----------------------------------------------------------------------
[08:37:26.361] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[08:37:26.362] <TB1> INFO: IA differences per ROC: 17.7 16.9 18.5 20.1 17.7 18.5 18.5 16.9 17.7 17.7 17.7 19.3 20.9 17.7 17.7 16.9
[08:37:26.458] <TB1> INFO: ----------------------------------------------------------------------
[08:37:26.458] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[08:37:26.458] <TB1> INFO: ----------------------------------------------------------------------
[08:37:46.052] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 385.9 mA = 24.1188 mA/ROC
[08:37:46.056] <TB1> INFO: ----------------------------------------------------------------------
[08:37:46.056] <TB1> INFO: PixTestPretest::findWorkingPixel()
[08:37:46.056] <TB1> INFO: ----------------------------------------------------------------------
[08:37:54.495] <TB1> INFO: Test took 8434ms.
[08:37:54.807] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[08:37:54.857] <TB1> INFO: ----------------------------------------------------------------------
[08:37:54.857] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[08:37:54.857] <TB1> INFO: ----------------------------------------------------------------------
[08:38:03.265] <TB1> INFO: Test took 8400ms.
[08:38:03.597] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[08:38:03.597] <TB1> INFO: CalDel: 132 137 130 115 168 158 162 144 129 135 130 152 141 139 137 119
[08:38:03.597] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[08:38:03.602] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C0.dat
[08:38:03.602] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C1.dat
[08:38:03.602] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C2.dat
[08:38:03.603] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C3.dat
[08:38:03.603] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C4.dat
[08:38:03.603] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C5.dat
[08:38:03.603] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C6.dat
[08:38:03.604] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C7.dat
[08:38:03.604] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C8.dat
[08:38:03.604] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C9.dat
[08:38:03.604] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C10.dat
[08:38:03.604] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C11.dat
[08:38:03.605] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C12.dat
[08:38:03.605] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C13.dat
[08:38:03.605] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C14.dat
[08:38:03.605] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters_C15.dat
[08:38:03.606] <TB1> INFO: write tbm parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//tbmParameters_C0a.dat
[08:38:03.606] <TB1> INFO: write tbm parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//tbmParameters_C0b.dat
[08:38:03.606] <TB1> INFO: PixTestPretest::doTest() done, duration: 55 seconds
[08:38:03.706] <TB1> INFO: enter test to run
[08:38:03.706] <TB1> INFO: test: fulltest no parameter change
[08:38:03.706] <TB1> INFO: running: fulltest
[08:38:03.706] <TB1> INFO: ######################################################################
[08:38:03.706] <TB1> INFO: PixTestFullTest::doTest()
[08:38:03.706] <TB1> INFO: ######################################################################
[08:38:03.707] <TB1> INFO: ######################################################################
[08:38:03.707] <TB1> INFO: PixTestAlive::doTest()
[08:38:03.707] <TB1> INFO: ######################################################################
[08:38:03.709] <TB1> INFO: ----------------------------------------------------------------------
[08:38:03.709] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[08:38:03.709] <TB1> INFO: ----------------------------------------------------------------------
[08:38:07.176] <TB1> INFO: Test took 3464ms.
[08:38:07.200] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:07.444] <TB1> INFO: PixTestAlive::aliveTest() done
[08:38:07.444] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 1 2 0 0 0 0 0 0 0 0 0 0 0
[08:38:07.447] <TB1> INFO: ----------------------------------------------------------------------
[08:38:07.447] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[08:38:07.447] <TB1> INFO: ----------------------------------------------------------------------
[08:38:10.187] <TB1> INFO: Test took 2737ms.
[08:38:10.191] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:10.191] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[08:38:10.433] <TB1> INFO: PixTestAlive::maskTest() done
[08:38:10.433] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[08:38:10.436] <TB1> INFO: ----------------------------------------------------------------------
[08:38:10.436] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[08:38:10.436] <TB1> INFO: ----------------------------------------------------------------------
[08:38:13.895] <TB1> INFO: Test took 3456ms.
[08:38:13.919] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:14.162] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[08:38:14.162] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[08:38:14.162] <TB1> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[08:38:14.172] <TB1> INFO: ######################################################################
[08:38:14.172] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[08:38:14.173] <TB1> INFO: ######################################################################
[08:38:14.177] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30/5) hits flags = 2 (plus default)
[08:38:14.188] <TB1> INFO: dacScan step from 0 .. 29
[08:38:14.188] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:38:14.188] <TB1> INFO: run 1 of 1
[08:38:35.776] <TB1> INFO: Test took 21588ms.
[08:38:35.808] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:35.808] <TB1> INFO: dacScan step from 30 .. 59
[08:38:35.809] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:38:35.809] <TB1> INFO: run 1 of 1
[08:38:59.039] <TB1> INFO: Test took 23230ms.
[08:38:59.151] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:59.164] <TB1> INFO: dacScan step from 60 .. 89
[08:38:59.164] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:38:59.164] <TB1> INFO: run 1 of 1
[08:39:28.325] <TB1> INFO: Test took 29160ms.
[08:39:28.595] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:39:28.638] <TB1> INFO: dacScan step from 90 .. 119
[08:39:28.638] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:39:28.638] <TB1> INFO: run 1 of 1
[08:39:57.958] <TB1> INFO: Test took 29320ms.
[08:39:58.223] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:39:58.270] <TB1> INFO: dacScan step from 120 .. 149
[08:39:58.270] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:39:58.270] <TB1> INFO: run 1 of 1
[08:40:22.939] <TB1> INFO: Test took 24669ms.
[08:40:23.142] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:40:46.738] <TB1> INFO: PixTestBBMap::doTest() done, duration: 152 seconds
[08:40:46.738] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 1 2 0 8
[08:40:46.738] <TB1> INFO: separation cut (per ROC): 80 79 92 109 72 80 88 79 83 97 82 92 97 72 93 96
[08:40:46.824] <TB1> INFO: ######################################################################
[08:40:46.824] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = 4, ntrig/step = 50
[08:40:46.824] <TB1> INFO: ######################################################################
[08:40:46.824] <TB1> INFO: ----------------------------------------------------------------------
[08:40:46.824] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = 4, ntrig/step = 50
[08:40:46.824] <TB1> INFO: ----------------------------------------------------------------------
[08:40:46.824] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4/50) hits flags = 16 (plus default)
[08:40:46.833] <TB1> INFO: dacScan step from 0 .. 3
[08:40:46.833] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:40:46.833] <TB1> INFO: run 1 of 1
[08:41:05.921] <TB1> INFO: Test took 19088ms.
[08:41:05.949] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:41:05.949] <TB1> INFO: dacScan step from 4 .. 7
[08:41:05.949] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:41:05.949] <TB1> INFO: run 1 of 1
[08:41:25.065] <TB1> INFO: Test took 19116ms.
[08:41:25.092] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:41:25.092] <TB1> INFO: dacScan step from 8 .. 11
[08:41:25.092] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:41:25.092] <TB1> INFO: run 1 of 1
[08:41:44.186] <TB1> INFO: Test took 19093ms.
[08:41:44.213] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:41:44.213] <TB1> INFO: dacScan step from 12 .. 15
[08:41:44.213] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:41:44.213] <TB1> INFO: run 1 of 1
[08:42:03.291] <TB1> INFO: Test took 19078ms.
[08:42:03.320] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:42:03.320] <TB1> INFO: dacScan step from 16 .. 19
[08:42:03.320] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:42:03.320] <TB1> INFO: run 1 of 1
[08:42:22.291] <TB1> INFO: Test took 18971ms.
[08:42:22.318] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:42:22.318] <TB1> INFO: dacScan step from 20 .. 23
[08:42:22.318] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:42:22.318] <TB1> INFO: run 1 of 1
[08:42:41.298] <TB1> INFO: Test took 18980ms.
[08:42:41.324] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:42:41.324] <TB1> INFO: dacScan step from 24 .. 27
[08:42:41.324] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:42:41.324] <TB1> INFO: run 1 of 1
[08:43:00.383] <TB1> INFO: Test took 19058ms.
[08:43:00.410] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:43:00.410] <TB1> INFO: dacScan step from 28 .. 31
[08:43:00.410] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:43:00.410] <TB1> INFO: run 1 of 1
[08:43:19.551] <TB1> INFO: Test took 19141ms.
[08:43:19.579] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:43:19.580] <TB1> INFO: dacScan step from 32 .. 35
[08:43:19.580] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:43:19.580] <TB1> INFO: run 1 of 1
[08:43:38.639] <TB1> INFO: Test took 19059ms.
[08:43:38.669] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:43:38.669] <TB1> INFO: dacScan step from 36 .. 39
[08:43:38.669] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:43:38.669] <TB1> INFO: run 1 of 1
[08:43:57.669] <TB1> INFO: Test took 19000ms.
[08:43:57.699] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:43:57.699] <TB1> INFO: dacScan step from 40 .. 43
[08:43:57.700] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:43:57.700] <TB1> INFO: run 1 of 1
[08:44:16.782] <TB1> INFO: Test took 19082ms.
[08:44:16.810] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:44:16.810] <TB1> INFO: dacScan step from 44 .. 47
[08:44:16.810] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:44:16.810] <TB1> INFO: run 1 of 1
[08:44:36.012] <TB1> INFO: Test took 19202ms.
[08:44:36.040] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:44:36.040] <TB1> INFO: dacScan step from 48 .. 51
[08:44:36.040] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:44:36.040] <TB1> INFO: run 1 of 1
[08:44:55.251] <TB1> INFO: Test took 19211ms.
[08:44:55.281] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:44:55.281] <TB1> INFO: dacScan step from 52 .. 55
[08:44:55.281] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:44:55.281] <TB1> INFO: run 1 of 1
[08:45:14.387] <TB1> INFO: Test took 19106ms.
[08:45:14.416] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:45:14.416] <TB1> INFO: dacScan step from 56 .. 59
[08:45:14.416] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:45:14.416] <TB1> INFO: run 1 of 1
[08:45:33.542] <TB1> INFO: Test took 19126ms.
[08:45:33.571] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:45:33.571] <TB1> INFO: dacScan step from 60 .. 63
[08:45:33.571] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:45:33.571] <TB1> INFO: run 1 of 1
[08:45:52.669] <TB1> INFO: Test took 19098ms.
[08:45:52.695] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:45:52.698] <TB1> INFO: dacScan step from 64 .. 67
[08:45:52.698] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:45:52.698] <TB1> INFO: run 1 of 1
[08:46:11.929] <TB1> INFO: Test took 19231ms.
[08:46:11.961] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:46:11.962] <TB1> INFO: dacScan step from 68 .. 71
[08:46:11.962] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:46:11.962] <TB1> INFO: run 1 of 1
[08:46:31.300] <TB1> INFO: Test took 19338ms.
[08:46:31.341] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:46:31.342] <TB1> INFO: dacScan step from 72 .. 75
[08:46:31.342] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:46:31.342] <TB1> INFO: run 1 of 1
[08:46:51.231] <TB1> INFO: Test took 19889ms.
[08:46:51.285] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:46:51.287] <TB1> INFO: dacScan step from 76 .. 79
[08:46:51.287] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:46:51.287] <TB1> INFO: run 1 of 1
[08:47:12.428] <TB1> INFO: Test took 21141ms.
[08:47:12.517] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:47:12.521] <TB1> INFO: dacScan step from 80 .. 83
[08:47:12.521] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:47:12.521] <TB1> INFO: run 1 of 1
[08:47:36.596] <TB1> INFO: Test took 24075ms.
[08:47:36.746] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:47:36.753] <TB1> INFO: dacScan step from 84 .. 87
[08:47:36.753] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:47:36.753] <TB1> INFO: run 1 of 1
[08:48:02.989] <TB1> INFO: Test took 26236ms.
[08:48:03.184] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:48:03.192] <TB1> INFO: dacScan step from 88 .. 91
[08:48:03.192] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:48:03.192] <TB1> INFO: run 1 of 1
[08:48:30.464] <TB1> INFO: Test took 27271ms.
[08:48:30.680] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:48:30.692] <TB1> INFO: dacScan step from 92 .. 95
[08:48:30.692] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:48:30.692] <TB1> INFO: run 1 of 1
[08:48:58.739] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[08:48:58.740] <TB1> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (95) != TBM ID (96)

[08:48:58.740] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 31 readouts!

[08:48:58.740] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 31 readouts!

[08:48:58.740] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[08:48:59.040] <TB1> INFO: Test took 28348ms.
[08:48:59.261] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:48:59.270] <TB1> INFO: dacScan step from 96 .. 99
[08:48:59.270] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:48:59.270] <TB1> INFO: run 1 of 1
[08:49:27.564] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[08:49:28.510] <TB1> INFO: Test took 29240ms.
[08:49:28.766] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:49:28.775] <TB1> INFO: dacScan step from 100 .. 103
[08:49:28.775] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:49:28.775] <TB1> INFO: run 1 of 1
[08:49:57.118] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[08:49:57.118] <TB1> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (15) != TBM ID (16)

[08:49:57.118] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 31 readouts!

[08:49:57.118] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 31 readouts!

[08:49:57.119] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[08:49:58.328] <TB1> INFO: Test took 29553ms.
[08:49:58.579] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:49:58.588] <TB1> INFO: dacScan step from 104 .. 107
[08:49:58.588] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:49:58.588] <TB1> INFO: run 1 of 1
[08:50:26.842] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[08:50:28.032] <TB1> INFO: Test took 29443ms.
[08:50:28.273] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:50:28.283] <TB1> INFO: dacScan step from 108 .. 111
[08:50:28.283] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:50:28.283] <TB1> INFO: run 1 of 1
[08:50:57.755] <TB1> INFO: Test took 29472ms.
[08:50:57.981] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:50:57.990] <TB1> INFO: dacScan step from 112 .. 115
[08:50:57.990] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:50:57.990] <TB1> INFO: run 1 of 1
[08:51:26.168] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[08:51:26.168] <TB1> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (217) != TBM ID (218)

[08:51:26.168] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[08:51:26.168] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[08:51:27.455] <TB1> INFO: Test took 29465ms.
[08:51:27.712] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:51:27.721] <TB1> INFO: dacScan step from 116 .. 119
[08:51:27.721] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:51:27.721] <TB1> INFO: run 1 of 1
[08:51:55.781] <TB1> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (196) != TBM ID (0)

[08:51:55.782] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L470> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[08:51:55.782] <TB1> ERROR: <datapipe.cc/CheckEventID:L453> Channel 3 Event ID mismatch: local ID (1) != TBM ID (197)

[08:51:57.044] <TB1> INFO: Test took 29323ms.
[08:51:57.263] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:51:57.272] <TB1> INFO: dacScan step from 120 .. 123
[08:51:57.272] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:51:57.272] <TB1> INFO: run 1 of 1
[08:52:26.736] <TB1> INFO: Test took 29464ms.
[08:52:26.971] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:52:26.981] <TB1> INFO: dacScan step from 124 .. 127
[08:52:26.981] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:52:26.981] <TB1> INFO: run 1 of 1
[08:52:56.331] <TB1> INFO: Test took 29350ms.
[08:52:56.557] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:52:56.566] <TB1> INFO: dacScan step from 128 .. 131
[08:52:56.566] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:52:56.566] <TB1> INFO: run 1 of 1
[08:53:25.981] <TB1> INFO: Test took 29415ms.
[08:53:26.200] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:53:26.211] <TB1> INFO: dacScan step from 132 .. 135
[08:53:26.212] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:53:26.212] <TB1> INFO: run 1 of 1
[08:53:55.491] <TB1> INFO: Test took 29279ms.
[08:53:55.741] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:53:55.750] <TB1> INFO: dacScan step from 136 .. 139
[08:53:55.750] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:53:55.750] <TB1> INFO: run 1 of 1
[08:54:22.867] <TB1> INFO: Test took 27117ms.
[08:54:23.107] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:54:23.118] <TB1> INFO: dacScan step from 140 .. 143
[08:54:23.118] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:54:23.118] <TB1> INFO: run 1 of 1
[08:54:49.870] <TB1> INFO: Test took 26751ms.
[08:54:50.098] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:54:50.108] <TB1> INFO: dacScan step from 144 .. 147
[08:54:50.108] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:54:50.108] <TB1> INFO: run 1 of 1
[08:55:17.133] <TB1> INFO: Test took 27025ms.
[08:55:17.361] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:55:17.379] <TB1> INFO: dacScan step from 148 .. 149
[08:55:17.379] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[08:55:17.379] <TB1> INFO: run 1 of 1
[08:55:31.972] <TB1> INFO: Test took 14593ms.
[08:55:32.112] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:55:32.119] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:33.652] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:35.091] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:36.556] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:38.130] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:40.008] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:41.517] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:42.984] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:44.451] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:45.864] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:47.318] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:48.839] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:50.325] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:51.812] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:53.355] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:54.855] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[08:55:56.361] <TB1> INFO: PixTestScurves::scurves() done
[08:55:56.361] <TB1> INFO: Vcal mean: 78.52 81.92 79.46 98.61 82.78 90.84 88.89 85.25 82.38 94.25 80.87 85.21 91.40 76.68 84.92 84.88
[08:55:56.361] <TB1> INFO: Vcal RMS: 4.59 4.24 4.39 6.43 5.13 5.96 5.53 4.97 4.63 6.24 4.21 4.62 6.04 4.36 5.33 4.80
[08:55:56.361] <TB1> INFO: PixTestScurves::fullTest() done, duration: 909 seconds
[08:55:56.436] <TB1> INFO: ######################################################################
[08:55:56.436] <TB1> INFO: PixTestTrim::doTest()
[08:55:56.436] <TB1> INFO: ######################################################################
[08:55:56.437] <TB1> INFO: ----------------------------------------------------------------------
[08:55:56.438] <TB1> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[08:55:56.438] <TB1> INFO: ----------------------------------------------------------------------
[08:55:56.533] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[08:55:56.533] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[08:55:56.541] <TB1> INFO: dacScan step from 0 .. 19
[08:55:56.541] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:55:56.541] <TB1> INFO: run 1 of 1
[08:56:11.678] <TB1> INFO: Test took 15137ms.
[08:56:11.704] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:11.704] <TB1> INFO: dacScan step from 20 .. 39
[08:56:11.704] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:56:11.704] <TB1> INFO: run 1 of 1
[08:56:26.878] <TB1> INFO: Test took 15174ms.
[08:56:26.903] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:26.903] <TB1> INFO: dacScan step from 40 .. 59
[08:56:26.903] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:56:26.903] <TB1> INFO: run 1 of 1
[08:56:41.275] <TB1> INFO: Test took 14372ms.
[08:56:41.296] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:41.296] <TB1> INFO: dacScan step from 60 .. 79
[08:56:41.296] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:56:41.296] <TB1> INFO: run 1 of 1
[08:56:55.737] <TB1> INFO: Test took 14441ms.
[08:56:55.759] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:55.759] <TB1> INFO: dacScan step from 80 .. 99
[08:56:55.759] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:56:55.759] <TB1> INFO: run 1 of 1
[08:57:11.380] <TB1> INFO: Test took 15620ms.
[08:57:11.443] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:57:11.452] <TB1> INFO: dacScan step from 100 .. 119
[08:57:11.452] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:57:11.452] <TB1> INFO: run 1 of 1
[08:57:30.690] <TB1> INFO: Test took 19238ms.
[08:57:30.852] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:57:30.879] <TB1> INFO: dacScan step from 120 .. 139
[08:57:30.879] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:57:30.879] <TB1> INFO: run 1 of 1
[08:57:49.242] <TB1> INFO: Test took 18363ms.
[08:57:49.396] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:57:49.422] <TB1> INFO: dacScan step from 140 .. 159
[08:57:49.422] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:57:49.422] <TB1> INFO: run 1 of 1
[08:58:05.953] <TB1> INFO: Test took 16530ms.
[08:58:06.041] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:58:31.978] <TB1> INFO: ROC 0 VthrComp = 82
[08:58:31.978] <TB1> INFO: ROC 1 VthrComp = 88
[08:58:31.978] <TB1> INFO: ROC 2 VthrComp = 90
[08:58:31.978] <TB1> INFO: ROC 3 VthrComp = 102
[08:58:31.978] <TB1> INFO: ROC 4 VthrComp = 82
[08:58:31.979] <TB1> INFO: ROC 5 VthrComp = 91
[08:58:31.979] <TB1> INFO: ROC 6 VthrComp = 93
[08:58:31.979] <TB1> INFO: ROC 7 VthrComp = 87
[08:58:31.979] <TB1> INFO: ROC 8 VthrComp = 87
[08:58:31.979] <TB1> INFO: ROC 9 VthrComp = 97
[08:58:31.979] <TB1> INFO: ROC 10 VthrComp = 88
[08:58:31.979] <TB1> INFO: ROC 11 VthrComp = 94
[08:58:31.979] <TB1> INFO: ROC 12 VthrComp = 98
[08:58:31.980] <TB1> INFO: ROC 13 VthrComp = 82
[08:58:31.980] <TB1> INFO: ROC 14 VthrComp = 96
[08:58:31.980] <TB1> INFO: ROC 15 VthrComp = 95
[08:58:31.980] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[08:58:31.980] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20/-1) hits flags = 16 (plus default)
[08:58:31.989] <TB1> INFO: dacScan step from 0 .. 19
[08:58:31.989] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:58:31.989] <TB1> INFO: run 1 of 1
[08:58:47.189] <TB1> INFO: Test took 15200ms.
[08:58:47.213] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:58:47.213] <TB1> INFO: dacScan step from 20 .. 39
[08:58:47.213] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:58:47.213] <TB1> INFO: run 1 of 1
[08:59:02.169] <TB1> INFO: Test took 14956ms.
[08:59:02.205] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:59:02.208] <TB1> INFO: dacScan step from 40 .. 59
[08:59:02.208] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:59:02.208] <TB1> INFO: run 1 of 1
[08:59:20.261] <TB1> INFO: Test took 18053ms.
[08:59:20.415] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:59:20.448] <TB1> INFO: dacScan step from 60 .. 79
[08:59:20.448] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:59:20.448] <TB1> INFO: run 1 of 1
[08:59:39.203] <TB1> INFO: Test took 18755ms.
[08:59:39.395] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:59:39.437] <TB1> INFO: dacScan step from 80 .. 99
[08:59:39.437] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[08:59:39.437] <TB1> INFO: run 1 of 1
[08:59:59.779] <TB1> INFO: Test took 20342ms.
[08:59:59.975] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:00:00.013] <TB1> INFO: dacScan step from 100 .. 119
[09:00:00.013] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[09:00:00.014] <TB1> INFO: run 1 of 1
[09:00:20.292] <TB1> INFO: Test took 20278ms.
[09:00:20.492] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:00:20.529] <TB1> INFO: dacScan step from 120 .. 139
[09:00:20.529] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[09:00:20.529] <TB1> INFO: run 1 of 1
[09:00:40.976] <TB1> INFO: Test took 20447ms.
[09:00:41.161] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:00:41.192] <TB1> INFO: dacScan step from 140 .. 159
[09:00:41.193] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[09:00:41.193] <TB1> INFO: run 1 of 1
[09:01:01.543] <TB1> INFO: Test took 20350ms.
[09:01:01.708] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:01:26.240] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 57.917 for pixel 12/79 mean/min/max = 44.824/31.6959/57.9521
[09:01:26.241] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 57.7897 for pixel 0/25 mean/min/max = 45.6315/33.3871/57.8758
[09:01:26.241] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 56.6485 for pixel 0/78 mean/min/max = 44.7111/32.7094/56.7128
[09:01:26.241] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 62.9507 for pixel 1/78 mean/min/max = 47.5208/31.6213/63.4204
[09:01:26.241] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 59.6771 for pixel 28/41 mean/min/max = 46.3351/32.9717/59.6984
[09:01:26.241] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 61.6785 for pixel 14/36 mean/min/max = 47.1016/32.3125/61.8906
[09:01:26.242] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 60.1962 for pixel 6/1 mean/min/max = 46.3014/32.3612/60.2417
[09:01:26.242] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 58.9971 for pixel 14/1 mean/min/max = 45.2775/31.4913/59.0637
[09:01:26.242] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 57.6077 for pixel 39/1 mean/min/max = 44.7348/31.8525/57.6172
[09:01:26.242] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 61.1659 for pixel 14/67 mean/min/max = 46.4252/31.6541/61.1964
[09:01:26.243] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 57.1518 for pixel 10/8 mean/min/max = 45.3999/33.6158/57.184
[09:01:26.243] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 56.6866 for pixel 21/4 mean/min/max = 44.6765/32.5512/56.8017
[09:01:26.243] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 58.7235 for pixel 0/18 mean/min/max = 45.2931/31.6444/58.9418
[09:01:26.243] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 57.3157 for pixel 1/62 mean/min/max = 44.8107/32.2083/57.4131
[09:01:26.244] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 58.3105 for pixel 12/9 mean/min/max = 44.7492/31.1602/58.3383
[09:01:26.244] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 56.5857 for pixel 0/75 mean/min/max = 44.1885/31.7702/56.6067
[09:01:26.244] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:02:57.298] <TB1> INFO: Test took 91054ms.
[09:02:58.717] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[09:02:58.725] <TB1> INFO: dacScan step from 0 .. 19
[09:02:58.725] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:02:58.725] <TB1> INFO: run 1 of 2
[09:03:14.102] <TB1> INFO: Test took 15378ms.
[09:03:14.147] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:03:14.149] <TB1> INFO: run 2 of 2
[09:03:29.594] <TB1> INFO: Test took 15444ms.
[09:03:29.638] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:03:29.640] <TB1> INFO: dacScan step from 20 .. 39
[09:03:29.640] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:03:29.640] <TB1> INFO: run 1 of 2
[09:03:48.004] <TB1> INFO: Test took 18364ms.
[09:03:48.148] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:03:48.173] <TB1> INFO: run 2 of 2
[09:04:06.432] <TB1> INFO: Test took 18259ms.
[09:04:06.606] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:04:06.637] <TB1> INFO: dacScan step from 40 .. 59
[09:04:06.637] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:04:06.637] <TB1> INFO: run 1 of 2
[09:04:26.834] <TB1> INFO: Test took 20197ms.
[09:04:26.994] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:04:27.031] <TB1> INFO: run 2 of 2
[09:04:45.791] <TB1> INFO: Test took 18760ms.
[09:04:45.978] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:04:46.024] <TB1> INFO: dacScan step from 60 .. 79
[09:04:46.024] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:04:46.024] <TB1> INFO: run 1 of 2
[09:05:06.395] <TB1> INFO: Test took 20371ms.
[09:05:06.606] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:05:06.651] <TB1> INFO: run 2 of 2
[09:05:27.026] <TB1> INFO: Test took 20375ms.
[09:05:27.198] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:05:27.232] <TB1> INFO: dacScan step from 80 .. 99
[09:05:27.232] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:05:27.232] <TB1> INFO: run 1 of 2
[09:05:47.490] <TB1> INFO: Test took 20258ms.
[09:05:47.675] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:05:47.715] <TB1> INFO: run 2 of 2
[09:06:08.070] <TB1> INFO: Test took 20354ms.
[09:06:08.268] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:06:08.312] <TB1> INFO: dacScan step from 100 .. 119
[09:06:08.312] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:06:08.312] <TB1> INFO: run 1 of 2
[09:06:28.372] <TB1> INFO: Test took 20060ms.
[09:06:28.543] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:06:28.572] <TB1> INFO: run 2 of 2
[09:06:48.923] <TB1> INFO: Test took 20351ms.
[09:06:49.114] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:06:49.146] <TB1> INFO: dacScan step from 120 .. 139
[09:06:49.146] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:06:49.146] <TB1> INFO: run 1 of 2
[09:07:09.610] <TB1> INFO: Test took 20464ms.
[09:07:09.827] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:09.874] <TB1> INFO: run 2 of 2
[09:07:30.273] <TB1> INFO: Test took 20399ms.
[09:07:30.486] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:30.535] <TB1> INFO: dacScan step from 140 .. 159
[09:07:30.535] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:07:30.535] <TB1> INFO: run 1 of 2
[09:07:51.087] <TB1> INFO: Test took 20552ms.
[09:07:51.268] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:51.315] <TB1> INFO: run 2 of 2
[09:08:11.849] <TB1> INFO: Test took 20534ms.
[09:08:12.056] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:08:12.100] <TB1> INFO: dacScan step from 160 .. 179
[09:08:12.100] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:08:12.100] <TB1> INFO: run 1 of 2
[09:08:32.772] <TB1> INFO: Test took 20672ms.
[09:08:32.956] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:08:32.998] <TB1> INFO: run 2 of 2
[09:08:53.722] <TB1> INFO: Test took 20724ms.
[09:08:53.897] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:08:53.931] <TB1> INFO: dacScan step from 180 .. 199
[09:08:53.931] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:08:53.931] <TB1> INFO: run 1 of 2
[09:09:15.395] <TB1> INFO: Test took 21464ms.
[09:09:15.588] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:09:15.633] <TB1> INFO: run 2 of 2
[09:09:36.979] <TB1> INFO: Test took 21346ms.
[09:09:37.178] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:10:02.782] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.005436 .. 255.000000
[09:10:02.862] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20/-1) hits flags = 16 (plus default)
[09:10:02.870] <TB1> INFO: dacScan step from 0 .. 19
[09:10:02.870] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:10:02.870] <TB1> INFO: run 1 of 1
[09:10:16.479] <TB1> INFO: Test took 13609ms.
[09:10:16.503] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:10:16.503] <TB1> INFO: dacScan step from 20 .. 39
[09:10:16.503] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:10:16.503] <TB1> INFO: run 1 of 1
[09:10:31.416] <TB1> INFO: Test took 14912ms.
[09:10:31.494] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:10:31.512] <TB1> INFO: dacScan step from 40 .. 59
[09:10:31.512] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:10:31.512] <TB1> INFO: run 1 of 1
[09:10:49.309] <TB1> INFO: Test took 17797ms.
[09:10:49.498] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:10:49.542] <TB1> INFO: dacScan step from 60 .. 79
[09:10:49.542] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:10:49.542] <TB1> INFO: run 1 of 1
[09:11:07.428] <TB1> INFO: Test took 17886ms.
[09:11:07.576] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:11:07.609] <TB1> INFO: dacScan step from 80 .. 99
[09:11:07.609] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:11:07.609] <TB1> INFO: run 1 of 1
[09:11:24.140] <TB1> INFO: Test took 16531ms.
[09:11:24.280] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:11:24.315] <TB1> INFO: dacScan step from 100 .. 119
[09:11:24.315] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:11:24.315] <TB1> INFO: run 1 of 1
[09:11:41.145] <TB1> INFO: Test took 16830ms.
[09:11:41.353] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:11:41.394] <TB1> INFO: dacScan step from 120 .. 139
[09:11:41.394] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:11:41.394] <TB1> INFO: run 1 of 1
[09:11:58.430] <TB1> INFO: Test took 17036ms.
[09:11:58.605] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:11:58.644] <TB1> INFO: dacScan step from 140 .. 159
[09:11:58.644] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:11:58.644] <TB1> INFO: run 1 of 1
[09:12:16.327] <TB1> INFO: Test took 17683ms.
[09:12:16.473] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:12:16.511] <TB1> INFO: dacScan step from 160 .. 179
[09:12:16.511] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:12:16.511] <TB1> INFO: run 1 of 1
[09:12:34.415] <TB1> INFO: Test took 17904ms.
[09:12:34.555] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:12:34.589] <TB1> INFO: dacScan step from 180 .. 199
[09:12:34.590] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:12:34.590] <TB1> INFO: run 1 of 1
[09:12:53.270] <TB1> INFO: Test took 18680ms.
[09:12:53.449] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:12:53.479] <TB1> INFO: dacScan step from 200 .. 219
[09:12:53.479] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:12:53.479] <TB1> INFO: run 1 of 1
[09:13:10.020] <TB1> INFO: Test took 16541ms.
[09:13:10.191] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:13:10.233] <TB1> INFO: dacScan step from 220 .. 239
[09:13:10.233] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:13:10.233] <TB1> INFO: run 1 of 1
[09:13:27.513] <TB1> INFO: Test took 17280ms.
[09:13:27.683] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:13:27.713] <TB1> INFO: dacScan step from 240 .. 255
[09:13:27.713] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:13:27.713] <TB1> INFO: run 1 of 1
[09:13:42.513] <TB1> INFO: Test took 14800ms.
[09:13:42.637] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:13.381] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 0.219509 .. 69.857124
[09:14:13.463] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 0 .. 79 (20/-1) hits flags = 16 (plus default)
[09:14:13.474] <TB1> INFO: dacScan step from 0 .. 19
[09:14:13.474] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:14:13.474] <TB1> INFO: run 1 of 1
[09:14:27.105] <TB1> INFO: Test took 13631ms.
[09:14:27.132] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:27.132] <TB1> INFO: dacScan step from 20 .. 39
[09:14:27.132] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:14:27.132] <TB1> INFO: run 1 of 1
[09:14:41.972] <TB1> INFO: Test took 14840ms.
[09:14:42.044] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:42.059] <TB1> INFO: dacScan step from 40 .. 59
[09:14:42.059] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:14:42.059] <TB1> INFO: run 1 of 1
[09:14:59.871] <TB1> INFO: Test took 17812ms.
[09:15:00.043] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:00.078] <TB1> INFO: dacScan step from 60 .. 79
[09:15:00.078] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:15:00.078] <TB1> INFO: run 1 of 1
[09:15:17.803] <TB1> INFO: Test took 17725ms.
[09:15:17.966] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:40.611] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 19.223677 .. 69.857124
[09:15:40.709] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 9 .. 79 (20/-1) hits flags = 16 (plus default)
[09:15:40.718] <TB1> INFO: dacScan step from 9 .. 28
[09:15:40.718] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:15:40.718] <TB1> INFO: run 1 of 1
[09:15:53.907] <TB1> INFO: Test took 13188ms.
[09:15:53.930] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:53.931] <TB1> INFO: dacScan step from 29 .. 48
[09:15:53.931] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:15:53.931] <TB1> INFO: run 1 of 1
[09:16:09.380] <TB1> INFO: Test took 15449ms.
[09:16:09.512] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:09.566] <TB1> INFO: dacScan step from 49 .. 68
[09:16:09.566] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:16:09.566] <TB1> INFO: run 1 of 1
[09:16:27.427] <TB1> INFO: Test took 17861ms.
[09:16:27.574] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:27.607] <TB1> INFO: dacScan step from 69 .. 79
[09:16:27.607] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:16:27.607] <TB1> INFO: run 1 of 1
[09:16:38.712] <TB1> INFO: Test took 11105ms.
[09:16:38.814] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:00.699] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 2.891168 .. 69.857124
[09:17:00.796] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 2 .. 79 (20/-1) hits flags = 16 (plus default)
[09:17:00.805] <TB1> INFO: dacScan step from 2 .. 21
[09:17:00.805] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:17:00.805] <TB1> INFO: run 1 of 1
[09:17:13.848] <TB1> INFO: Test took 13043ms.
[09:17:13.871] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:13.871] <TB1> INFO: dacScan step from 22 .. 41
[09:17:13.871] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:17:13.871] <TB1> INFO: run 1 of 1
[09:17:28.215] <TB1> INFO: Test took 14344ms.
[09:17:28.311] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:28.344] <TB1> INFO: dacScan step from 42 .. 61
[09:17:28.344] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:17:28.344] <TB1> INFO: run 1 of 1
[09:17:44.890] <TB1> INFO: Test took 16546ms.
[09:17:45.044] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:45.084] <TB1> INFO: dacScan step from 62 .. 79
[09:17:45.084] <TB1> INFO: dacScan split into 1 runs with ntrig = 4
[09:17:45.084] <TB1> INFO: run 1 of 1
[09:18:01.384] <TB1> INFO: Test took 16300ms.
[09:18:01.547] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:18:25.094] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[09:18:25.094] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20/5) hits flags = 16 (plus default)
[09:18:25.104] <TB1> INFO: dacScan step from 15 .. 34
[09:18:25.104] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:18:25.104] <TB1> INFO: run 1 of 2
[09:18:39.880] <TB1> INFO: Test took 14776ms.
[09:18:39.934] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:18:39.943] <TB1> INFO: run 2 of 2
[09:18:55.204] <TB1> INFO: Test took 15261ms.
[09:18:55.247] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:18:55.254] <TB1> INFO: dacScan step from 35 .. 54
[09:18:55.254] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:18:55.254] <TB1> INFO: run 1 of 2
[09:19:13.911] <TB1> INFO: Test took 18657ms.
[09:19:14.079] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:14.115] <TB1> INFO: run 2 of 2
[09:19:34.423] <TB1> INFO: Test took 20308ms.
[09:19:34.670] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:34.713] <TB1> INFO: dacScan step from 55 .. 55
[09:19:34.713] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:19:34.713] <TB1> INFO: run 1 of 2
[09:19:38.447] <TB1> INFO: Test took 3734ms.
[09:19:38.462] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:38.466] <TB1> INFO: run 2 of 2
[09:19:42.195] <TB1> INFO: Test took 3729ms.
[09:19:42.212] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:56.107] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C0.dat
[09:19:56.107] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C1.dat
[09:19:56.107] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C2.dat
[09:19:56.107] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C3.dat
[09:19:56.108] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C4.dat
[09:19:56.108] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C5.dat
[09:19:56.108] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C6.dat
[09:19:56.108] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C7.dat
[09:19:56.108] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C8.dat
[09:19:56.108] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C9.dat
[09:19:56.108] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C10.dat
[09:19:56.108] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C11.dat
[09:19:56.108] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C12.dat
[09:19:56.109] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C13.dat
[09:19:56.109] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C14.dat
[09:19:56.109] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C15.dat
[09:19:56.109] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C0.dat
[09:19:56.117] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C1.dat
[09:19:56.123] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C2.dat
[09:19:56.129] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C3.dat
[09:19:56.135] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C4.dat
[09:19:56.141] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C5.dat
[09:19:56.147] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C6.dat
[09:19:56.155] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C7.dat
[09:19:56.163] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C8.dat
[09:19:56.171] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C9.dat
[09:19:56.179] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C10.dat
[09:19:56.187] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C11.dat
[09:19:56.196] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C12.dat
[09:19:56.203] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C13.dat
[09:19:56.209] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C14.dat
[09:19:56.217] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//trimParameters35_C15.dat
[09:19:56.225] <TB1> INFO: PixTestTrim::trimTest() done
[09:19:56.225] <TB1> INFO: vtrim: 107 95 107 128 107 208 104 114 100 126 98 104 106 112 106 158
[09:19:56.225] <TB1> INFO: vthrcomp: 82 88 90 102 82 91 93 87 87 97 88 94 98 82 96 95
[09:19:56.225] <TB1> INFO: vcal mean: 34.98 35.02 35.02 35.04 35.04 34.92 35.04 34.99 35.02 35.00 35.05 35.02 35.04 35.06 35.17 34.98
[09:19:56.225] <TB1> INFO: vcal RMS: 0.96 0.97 0.91 1.20 1.31 4.41 1.04 1.09 1.04 1.07 0.98 0.94 0.96 1.03 1.04 1.55
[09:19:56.225] <TB1> INFO: bits mean: 9.74 9.34 10.15 9.59 9.67 11.89 9.73 10.07 10.05 9.75 9.67 9.90 9.62 10.23 9.98 11.91
[09:19:56.225] <TB1> INFO: bits RMS: 2.63 2.58 2.38 2.59 2.42 1.55 2.50 2.43 2.50 2.55 2.46 2.50 2.72 2.38 2.63 1.60
[09:19:56.235] <TB1> INFO: ----------------------------------------------------------------------
[09:19:56.235] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[09:19:56.235] <TB1> INFO: ----------------------------------------------------------------------
[09:19:56.240] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20/5) hits flags = 16 (plus default)
[09:19:56.250] <TB1> INFO: dacScan step from 0 .. 19
[09:19:56.250] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:19:56.250] <TB1> INFO: run 1 of 2
[09:20:10.874] <TB1> INFO: Test took 14624ms.
[09:20:10.896] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:10.896] <TB1> INFO: run 2 of 2
[09:20:26.095] <TB1> INFO: Test took 15199ms.
[09:20:26.125] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:26.125] <TB1> INFO: dacScan step from 20 .. 39
[09:20:26.125] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:20:26.125] <TB1> INFO: run 1 of 2
[09:20:41.338] <TB1> INFO: Test took 15213ms.
[09:20:41.366] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:41.366] <TB1> INFO: run 2 of 2
[09:20:56.477] <TB1> INFO: Test took 15111ms.
[09:20:56.502] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:56.503] <TB1> INFO: dacScan step from 40 .. 59
[09:20:56.503] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:20:56.503] <TB1> INFO: run 1 of 2
[09:21:11.001] <TB1> INFO: Test took 14498ms.
[09:21:11.023] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:11.023] <TB1> INFO: run 2 of 2
[09:21:25.872] <TB1> INFO: Test took 14849ms.
[09:21:25.900] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:25.900] <TB1> INFO: dacScan step from 60 .. 79
[09:21:25.900] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:21:25.901] <TB1> INFO: run 1 of 2
[09:21:41.028] <TB1> INFO: Test took 15127ms.
[09:21:41.053] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:41.053] <TB1> INFO: run 2 of 2
[09:21:56.212] <TB1> INFO: Test took 15159ms.
[09:21:56.237] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:56.237] <TB1> INFO: dacScan step from 80 .. 99
[09:21:56.237] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:21:56.237] <TB1> INFO: run 1 of 2
[09:22:11.545] <TB1> INFO: Test took 15308ms.
[09:22:11.582] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:11.584] <TB1> INFO: run 2 of 2
[09:22:27.041] <TB1> INFO: Test took 15457ms.
[09:22:27.074] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:27.076] <TB1> INFO: dacScan step from 100 .. 119
[09:22:27.076] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:22:27.076] <TB1> INFO: run 1 of 2
[09:22:44.222] <TB1> INFO: Test took 17146ms.
[09:22:44.378] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:44.400] <TB1> INFO: run 2 of 2
[09:23:02.256] <TB1> INFO: Test took 17855ms.
[09:23:02.424] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:02.452] <TB1> INFO: dacScan step from 120 .. 139
[09:23:02.452] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:23:02.452] <TB1> INFO: run 1 of 2
[09:23:22.769] <TB1> INFO: Test took 20317ms.
[09:23:22.947] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:22.979] <TB1> INFO: run 2 of 2
[09:23:43.249] <TB1> INFO: Test took 20270ms.
[09:23:43.465] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:23:43.506] <TB1> INFO: dacScan step from 140 .. 159
[09:23:43.506] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:23:43.506] <TB1> INFO: run 1 of 2
[09:24:03.808] <TB1> INFO: Test took 20302ms.
[09:24:03.982] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:04.065] <TB1> INFO: run 2 of 2
[09:24:23.181] <TB1> INFO: Test took 19116ms.
[09:24:23.437] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:23.537] <TB1> INFO: dacScan step from 160 .. 179
[09:24:23.537] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:24:23.537] <TB1> INFO: run 1 of 2
[09:24:42.683] <TB1> INFO: Test took 19146ms.
[09:24:42.982] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:43.038] <TB1> INFO: run 2 of 2
[09:25:02.373] <TB1> INFO: Test took 19336ms.
[09:25:02.587] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:25:02.637] <TB1> INFO: dacScan step from 180 .. 199
[09:25:02.637] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:25:02.637] <TB1> INFO: run 1 of 2
[09:25:22.587] <TB1> INFO: Test took 19949ms.
[09:25:22.761] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:25:22.820] <TB1> INFO: run 2 of 2
[09:25:43.667] <TB1> INFO: Test took 20847ms.
[09:25:43.849] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:26:11.251] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 168 (20/5) hits flags = 16 (plus default)
[09:26:11.259] <TB1> INFO: dacScan step from 0 .. 19
[09:26:11.259] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:26:11.259] <TB1> INFO: run 1 of 2
[09:26:25.610] <TB1> INFO: Test took 14351ms.
[09:26:25.632] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:26:25.632] <TB1> INFO: run 2 of 2
[09:26:40.302] <TB1> INFO: Test took 14670ms.
[09:26:40.327] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:26:40.327] <TB1> INFO: dacScan step from 20 .. 39
[09:26:40.327] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:26:40.327] <TB1> INFO: run 1 of 2
[09:26:55.505] <TB1> INFO: Test took 15178ms.
[09:26:55.535] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:26:55.535] <TB1> INFO: run 2 of 2
[09:27:10.738] <TB1> INFO: Test took 15203ms.
[09:27:10.764] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:27:10.764] <TB1> INFO: dacScan step from 40 .. 59
[09:27:10.764] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:27:10.764] <TB1> INFO: run 1 of 2
[09:27:25.942] <TB1> INFO: Test took 15178ms.
[09:27:25.968] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:27:25.968] <TB1> INFO: run 2 of 2
[09:27:41.211] <TB1> INFO: Test took 15243ms.
[09:27:41.242] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:27:41.243] <TB1> INFO: dacScan step from 60 .. 79
[09:27:41.243] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:27:41.243] <TB1> INFO: run 1 of 2
[09:27:56.457] <TB1> INFO: Test took 15214ms.
[09:27:56.483] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:27:56.483] <TB1> INFO: run 2 of 2
[09:28:11.715] <TB1> INFO: Test took 15232ms.
[09:28:11.742] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:11.743] <TB1> INFO: dacScan step from 80 .. 99
[09:28:11.743] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:28:11.743] <TB1> INFO: run 1 of 2
[09:28:28.124] <TB1> INFO: Test took 16381ms.
[09:28:28.198] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:28.208] <TB1> INFO: run 2 of 2
[09:28:44.645] <TB1> INFO: Test took 16437ms.
[09:28:44.731] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:44.742] <TB1> INFO: dacScan step from 100 .. 119
[09:28:44.742] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:28:44.742] <TB1> INFO: run 1 of 2
[09:29:03.039] <TB1> INFO: Test took 18297ms.
[09:29:03.218] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:29:03.248] <TB1> INFO: run 2 of 2
[09:29:21.718] <TB1> INFO: Test took 18470ms.
[09:29:21.893] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:29:21.926] <TB1> INFO: dacScan step from 120 .. 139
[09:29:21.926] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:29:21.926] <TB1> INFO: run 1 of 2
[09:29:41.245] <TB1> INFO: Test took 19319ms.
[09:29:41.414] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:29:41.444] <TB1> INFO: run 2 of 2
[09:30:01.778] <TB1> INFO: Test took 20334ms.
[09:30:01.970] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:02.004] <TB1> INFO: dacScan step from 140 .. 159
[09:30:02.004] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:30:02.004] <TB1> INFO: run 1 of 2
[09:30:22.313] <TB1> INFO: Test took 20309ms.
[09:30:22.521] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:22.558] <TB1> INFO: run 2 of 2
[09:30:42.735] <TB1> INFO: Test took 20177ms.
[09:30:42.929] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:42.967] <TB1> INFO: dacScan step from 160 .. 168
[09:30:42.967] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:30:42.967] <TB1> INFO: run 1 of 2
[09:30:53.845] <TB1> INFO: Test took 10878ms.
[09:30:53.933] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:53.952] <TB1> INFO: run 2 of 2
[09:31:04.718] <TB1> INFO: Test took 10765ms.
[09:31:04.815] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:31:33.145] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 156 (20/5) hits flags = 16 (plus default)
[09:31:33.154] <TB1> INFO: dacScan step from 0 .. 19
[09:31:33.154] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:31:33.154] <TB1> INFO: run 1 of 2
[09:31:48.315] <TB1> INFO: Test took 15161ms.
[09:31:48.345] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:31:48.345] <TB1> INFO: run 2 of 2
[09:32:03.529] <TB1> INFO: Test took 15184ms.
[09:32:03.557] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:03.557] <TB1> INFO: dacScan step from 20 .. 39
[09:32:03.557] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:32:03.557] <TB1> INFO: run 1 of 2
[09:32:18.689] <TB1> INFO: Test took 15131ms.
[09:32:18.714] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:18.714] <TB1> INFO: run 2 of 2
[09:32:33.892] <TB1> INFO: Test took 15178ms.
[09:32:33.922] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:33.922] <TB1> INFO: dacScan step from 40 .. 59
[09:32:33.922] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:32:33.922] <TB1> INFO: run 1 of 2
[09:32:49.123] <TB1> INFO: Test took 15201ms.
[09:32:49.148] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:49.148] <TB1> INFO: run 2 of 2
[09:33:04.324] <TB1> INFO: Test took 15176ms.
[09:33:04.346] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:04.346] <TB1> INFO: dacScan step from 60 .. 79
[09:33:04.346] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:33:04.346] <TB1> INFO: run 1 of 2
[09:33:19.521] <TB1> INFO: Test took 15175ms.
[09:33:19.551] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:19.551] <TB1> INFO: run 2 of 2
[09:33:34.760] <TB1> INFO: Test took 15209ms.
[09:33:34.787] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:34.787] <TB1> INFO: dacScan step from 80 .. 99
[09:33:34.787] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:33:34.787] <TB1> INFO: run 1 of 2
[09:33:51.014] <TB1> INFO: Test took 16227ms.
[09:33:51.104] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:51.115] <TB1> INFO: run 2 of 2
[09:34:07.337] <TB1> INFO: Test took 16222ms.
[09:34:07.411] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:07.421] <TB1> INFO: dacScan step from 100 .. 119
[09:34:07.421] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:34:07.421] <TB1> INFO: run 1 of 2
[09:34:27.028] <TB1> INFO: Test took 19607ms.
[09:34:27.196] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:27.225] <TB1> INFO: run 2 of 2
[09:34:46.266] <TB1> INFO: Test took 19041ms.
[09:34:46.427] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:46.456] <TB1> INFO: dacScan step from 120 .. 139
[09:34:46.456] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:34:46.456] <TB1> INFO: run 1 of 2
[09:35:05.521] <TB1> INFO: Test took 19065ms.
[09:35:05.679] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:05.709] <TB1> INFO: run 2 of 2
[09:35:26.100] <TB1> INFO: Test took 20390ms.
[09:35:26.299] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:26.338] <TB1> INFO: dacScan step from 140 .. 156
[09:35:26.338] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:35:26.338] <TB1> INFO: run 1 of 2
[09:35:44.118] <TB1> INFO: Test took 17780ms.
[09:35:44.283] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:44.318] <TB1> INFO: run 2 of 2
[09:36:02.025] <TB1> INFO: Test took 17707ms.
[09:36:02.168] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:24.835] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 152 (20/5) hits flags = 16 (plus default)
[09:36:24.844] <TB1> INFO: dacScan step from 0 .. 19
[09:36:24.844] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:36:24.844] <TB1> INFO: run 1 of 2
[09:36:39.936] <TB1> INFO: Test took 15092ms.
[09:36:39.963] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:39.963] <TB1> INFO: run 2 of 2
[09:36:55.041] <TB1> INFO: Test took 15078ms.
[09:36:55.064] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:55.064] <TB1> INFO: dacScan step from 20 .. 39
[09:36:55.064] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:36:55.064] <TB1> INFO: run 1 of 2
[09:37:10.208] <TB1> INFO: Test took 15144ms.
[09:37:10.236] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:10.236] <TB1> INFO: run 2 of 2
[09:37:25.444] <TB1> INFO: Test took 15208ms.
[09:37:25.473] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:25.473] <TB1> INFO: dacScan step from 40 .. 59
[09:37:25.473] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:37:25.473] <TB1> INFO: run 1 of 2
[09:37:40.699] <TB1> INFO: Test took 15226ms.
[09:37:40.726] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:40.726] <TB1> INFO: run 2 of 2
[09:37:55.973] <TB1> INFO: Test took 15247ms.
[09:37:56.002] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:56.002] <TB1> INFO: dacScan step from 60 .. 79
[09:37:56.002] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:37:56.002] <TB1> INFO: run 1 of 2
[09:38:11.198] <TB1> INFO: Test took 15196ms.
[09:38:11.226] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:11.226] <TB1> INFO: run 2 of 2
[09:38:26.337] <TB1> INFO: Test took 15111ms.
[09:38:26.364] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:26.364] <TB1> INFO: dacScan step from 80 .. 99
[09:38:26.364] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:38:26.364] <TB1> INFO: run 1 of 2
[09:38:42.615] <TB1> INFO: Test took 16251ms.
[09:38:42.695] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:42.706] <TB1> INFO: run 2 of 2
[09:38:59.044] <TB1> INFO: Test took 16338ms.
[09:38:59.130] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:38:59.141] <TB1> INFO: dacScan step from 100 .. 119
[09:38:59.141] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:38:59.141] <TB1> INFO: run 1 of 2
[09:39:18.992] <TB1> INFO: Test took 19850ms.
[09:39:19.195] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:19.231] <TB1> INFO: run 2 of 2
[09:39:38.944] <TB1> INFO: Test took 19713ms.
[09:39:39.122] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:39.160] <TB1> INFO: dacScan step from 120 .. 139
[09:39:39.160] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:39:39.160] <TB1> INFO: run 1 of 2
[09:39:58.037] <TB1> INFO: Test took 18877ms.
[09:39:58.198] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:39:58.230] <TB1> INFO: run 2 of 2
[09:40:17.163] <TB1> INFO: Test took 18933ms.
[09:40:17.321] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:17.350] <TB1> INFO: dacScan step from 140 .. 152
[09:40:17.350] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:40:17.351] <TB1> INFO: run 1 of 2
[09:40:31.748] <TB1> INFO: Test took 14397ms.
[09:40:31.861] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:31.883] <TB1> INFO: run 2 of 2
[09:40:46.123] <TB1> INFO: Test took 14240ms.
[09:40:46.235] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:09.506] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 153 (20/5) hits flags = 16 (plus default)
[09:41:09.515] <TB1> INFO: dacScan step from 0 .. 19
[09:41:09.515] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:41:09.515] <TB1> INFO: run 1 of 2
[09:41:24.706] <TB1> INFO: Test took 15191ms.
[09:41:24.733] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:24.733] <TB1> INFO: run 2 of 2
[09:41:39.944] <TB1> INFO: Test took 15211ms.
[09:41:39.974] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:39.974] <TB1> INFO: dacScan step from 20 .. 39
[09:41:39.974] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:41:39.974] <TB1> INFO: run 1 of 2
[09:41:55.123] <TB1> INFO: Test took 15149ms.
[09:41:55.151] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:55.151] <TB1> INFO: run 2 of 2
[09:42:10.351] <TB1> INFO: Test took 15200ms.
[09:42:10.378] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:10.378] <TB1> INFO: dacScan step from 40 .. 59
[09:42:10.378] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:42:10.378] <TB1> INFO: run 1 of 2
[09:42:25.592] <TB1> INFO: Test took 15214ms.
[09:42:25.618] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:25.618] <TB1> INFO: run 2 of 2
[09:42:40.800] <TB1> INFO: Test took 15182ms.
[09:42:40.824] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:40.824] <TB1> INFO: dacScan step from 60 .. 79
[09:42:40.824] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:42:40.824] <TB1> INFO: run 1 of 2
[09:42:55.952] <TB1> INFO: Test took 15128ms.
[09:42:55.976] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:55.976] <TB1> INFO: run 2 of 2
[09:43:11.166] <TB1> INFO: Test took 15190ms.
[09:43:11.196] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:43:11.196] <TB1> INFO: dacScan step from 80 .. 99
[09:43:11.196] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:43:11.196] <TB1> INFO: run 1 of 2
[09:43:27.551] <TB1> INFO: Test took 16355ms.
[09:43:27.638] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:43:27.651] <TB1> INFO: run 2 of 2
[09:43:43.960] <TB1> INFO: Test took 16309ms.
[09:43:44.032] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:43:44.042] <TB1> INFO: dacScan step from 100 .. 119
[09:43:44.042] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:43:44.042] <TB1> INFO: run 1 of 2
[09:44:03.885] <TB1> INFO: Test took 19843ms.
[09:44:04.061] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:04.090] <TB1> INFO: run 2 of 2
[09:44:23.515] <TB1> INFO: Test took 19425ms.
[09:44:23.681] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:23.710] <TB1> INFO: dacScan step from 120 .. 139
[09:44:23.710] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:44:23.710] <TB1> INFO: run 1 of 2
[09:44:42.611] <TB1> INFO: Test took 18901ms.
[09:44:42.853] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:42.885] <TB1> INFO: run 2 of 2
[09:45:03.387] <TB1> INFO: Test took 20502ms.
[09:45:03.553] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:03.583] <TB1> INFO: dacScan step from 140 .. 153
[09:45:03.583] <TB1> INFO: dacScan split into 2 runs with ntrig = 5
[09:45:03.583] <TB1> INFO: run 1 of 2
[09:45:17.827] <TB1> INFO: Test took 14244ms.
[09:45:17.938] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:17.968] <TB1> INFO: run 2 of 2
[09:45:32.053] <TB1> INFO: Test took 14085ms.
[09:45:32.167] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:55.406] <TB1> INFO: PixTestTrim::trimBitTest() done
[09:45:55.408] <TB1> INFO: PixTestTrim::doTest() done, duration: 2998 seconds
[09:45:56.116] <TB1> INFO: ######################################################################
[09:45:56.116] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[09:45:56.116] <TB1> INFO: ######################################################################
[09:45:59.437] <TB1> INFO: Test took 3319ms.
[09:45:59.458] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:02.976] <TB1> INFO: Test took 3318ms.
[09:46:03.038] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:06.417] <TB1> INFO: Test took 3365ms.
[09:46:06.502] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:06.509] <TB1> INFO: The DUT currently contains the following objects:
[09:46:06.509] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:06.509] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:06.509] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:06.509] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:06.509] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.509] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.510] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.510] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.510] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.510] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:06.510] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.621] <TB1> INFO: Test took 1111ms.
[09:46:07.622] <TB1> INFO: The DUT currently contains the following objects:
[09:46:07.622] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:07.622] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:07.622] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:07.622] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:07.622] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.622] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:07.623] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.733] <TB1> INFO: Test took 1110ms.
[09:46:08.735] <TB1> INFO: The DUT currently contains the following objects:
[09:46:08.736] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:08.736] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:08.736] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:08.736] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:08.736] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:08.736] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.845] <TB1> INFO: Test took 1109ms.
[09:46:09.847] <TB1> INFO: The DUT currently contains the following objects:
[09:46:09.847] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:09.847] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:09.847] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:09.847] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:09.847] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:09.847] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.957] <TB1> INFO: Test took 1110ms.
[09:46:10.959] <TB1> INFO: The DUT currently contains the following objects:
[09:46:10.959] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:10.959] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:10.959] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:10.959] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:10.959] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:10.959] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.068] <TB1> INFO: Test took 1109ms.
[09:46:12.069] <TB1> INFO: The DUT currently contains the following objects:
[09:46:12.069] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:12.069] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:12.069] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:12.069] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:12.069] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.069] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.069] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.069] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.069] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.069] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.069] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.069] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.070] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.070] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.070] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.070] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.070] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.070] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.070] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:12.070] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.174] <TB1> INFO: Test took 1104ms.
[09:46:13.174] <TB1> INFO: The DUT currently contains the following objects:
[09:46:13.174] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:13.174] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:13.174] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:13.174] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:13.174] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.174] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.174] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.174] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.174] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.174] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:13.175] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.287] <TB1> INFO: Test took 1112ms.
[09:46:14.288] <TB1> INFO: The DUT currently contains the following objects:
[09:46:14.288] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:14.288] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:14.288] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:14.288] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:14.288] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:14.289] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.399] <TB1> INFO: Test took 1110ms.
[09:46:15.401] <TB1> INFO: The DUT currently contains the following objects:
[09:46:15.401] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:15.401] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:15.401] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:15.401] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:15.401] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.401] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:15.402] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.512] <TB1> INFO: Test took 1110ms.
[09:46:16.513] <TB1> INFO: The DUT currently contains the following objects:
[09:46:16.513] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:16.513] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:16.513] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:16.513] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:16.513] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.513] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.513] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.513] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.513] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:16.514] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.626] <TB1> INFO: Test took 1112ms.
[09:46:17.627] <TB1> INFO: The DUT currently contains the following objects:
[09:46:17.627] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:17.628] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:17.628] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:17.628] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:17.628] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:17.628] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.739] <TB1> INFO: Test took 1111ms.
[09:46:18.741] <TB1> INFO: The DUT currently contains the following objects:
[09:46:18.741] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:18.741] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:18.741] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:18.741] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:18.741] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.741] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:18.742] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.846] <TB1> INFO: Test took 1104ms.
[09:46:19.847] <TB1> INFO: The DUT currently contains the following objects:
[09:46:19.847] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:19.847] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:19.847] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:19.847] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:19.847] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:19.847] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.958] <TB1> INFO: Test took 1111ms.
[09:46:20.959] <TB1> INFO: The DUT currently contains the following objects:
[09:46:20.959] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:20.959] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:20.959] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:20.959] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:20.959] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.959] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.960] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.960] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.960] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:20.960] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.070] <TB1> INFO: Test took 1111ms.
[09:46:22.072] <TB1> INFO: The DUT currently contains the following objects:
[09:46:22.072] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:22.072] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:22.072] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:22.072] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:22.072] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.072] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.072] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.072] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.072] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.072] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.072] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.073] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.073] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.073] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.073] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.073] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.073] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.073] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.073] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:22.073] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.184] <TB1> INFO: Test took 1111ms.
[09:46:23.185] <TB1> INFO: The DUT currently contains the following objects:
[09:46:23.185] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[09:46:23.185] <TB1> INFO: TBM Core alpha (0): 7 registers set
[09:46:23.185] <TB1> INFO: TBM Core beta (1): 7 registers set
[09:46:23.185] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[09:46:23.186] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:23.186] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[09:46:24.297] <TB1> INFO: Test took 1111ms.
[09:46:24.303] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:50:12.071] <TB1> INFO: Test took 227769ms.
[09:50:13.703] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:00.945] <TB1> INFO: Test took 227243ms.
[09:54:03.081] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.089] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.098] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.106] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.114] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.123] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.131] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.138] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.146] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.153] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.160] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[09:54:03.168] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.176] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.184] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.191] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.198] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.207] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[09:54:03.264] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C0.dat
[09:54:03.264] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C1.dat
[09:54:03.265] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C2.dat
[09:54:03.265] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C3.dat
[09:54:03.265] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C4.dat
[09:54:03.265] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C5.dat
[09:54:03.265] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C6.dat
[09:54:03.265] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C7.dat
[09:54:03.265] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C8.dat
[09:54:03.265] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C9.dat
[09:54:03.266] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C10.dat
[09:54:03.266] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C11.dat
[09:54:03.266] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C12.dat
[09:54:03.266] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C13.dat
[09:54:03.266] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C14.dat
[09:54:03.266] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//dacParameters35_C15.dat
[09:54:06.667] <TB1> INFO: Test took 3396ms.
[09:54:10.299] <TB1> INFO: Test took 3348ms.
[09:54:13.972] <TB1> INFO: Test took 3395ms.
[09:54:14.290] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:15.207] <TB1> INFO: Test took 917ms.
[09:54:15.210] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:16.315] <TB1> INFO: Test took 1105ms.
[09:54:16.318] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:17.422] <TB1> INFO: Test took 1104ms.
[09:54:17.425] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:18.529] <TB1> INFO: Test took 1104ms.
[09:54:18.532] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:19.637] <TB1> INFO: Test took 1105ms.
[09:54:19.640] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:20.746] <TB1> INFO: Test took 1106ms.
[09:54:20.749] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:21.853] <TB1> INFO: Test took 1104ms.
[09:54:21.856] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:22.960] <TB1> INFO: Test took 1104ms.
[09:54:22.963] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:24.066] <TB1> INFO: Test took 1103ms.
[09:54:24.069] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:25.173] <TB1> INFO: Test took 1104ms.
[09:54:25.176] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:26.281] <TB1> INFO: Test took 1105ms.
[09:54:26.284] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:27.389] <TB1> INFO: Test took 1105ms.
[09:54:27.392] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:28.497] <TB1> INFO: Test took 1105ms.
[09:54:28.500] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:29.613] <TB1> INFO: Test took 1113ms.
[09:54:29.616] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:30.721] <TB1> INFO: Test took 1105ms.
[09:54:30.724] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:31.829] <TB1> INFO: Test took 1105ms.
[09:54:31.832] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:32.939] <TB1> INFO: Test took 1107ms.
[09:54:32.943] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:34.047] <TB1> INFO: Test took 1104ms.
[09:54:34.050] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:35.154] <TB1> INFO: Test took 1104ms.
[09:54:35.157] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:36.262] <TB1> INFO: Test took 1105ms.
[09:54:36.265] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:37.369] <TB1> INFO: Test took 1104ms.
[09:54:37.372] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:38.479] <TB1> INFO: Test took 1107ms.
[09:54:38.484] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:39.590] <TB1> INFO: Test took 1106ms.
[09:54:39.593] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:40.698] <TB1> INFO: Test took 1105ms.
[09:54:40.701] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:41.810] <TB1> INFO: Test took 1109ms.
[09:54:41.814] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:42.918] <TB1> INFO: Test took 1104ms.
[09:54:42.922] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:44.026] <TB1> INFO: Test took 1104ms.
[09:54:44.029] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:45.133] <TB1> INFO: Test took 1104ms.
[09:54:45.136] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:46.240] <TB1> INFO: Test took 1104ms.
[09:54:46.244] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:47.348] <TB1> INFO: Test took 1104ms.
[09:54:47.351] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:48.458] <TB1> INFO: Test took 1107ms.
[09:54:48.463] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:54:49.567] <TB1> INFO: Test took 1105ms.
[09:54:50.139] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 534 seconds
[09:54:50.139] <TB1> INFO: PH scale (per ROC): 89 87 94 82 85 70 80 90 89 80 88 91 77 84 89 100
[09:54:50.139] <TB1> INFO: PH offset (per ROC): 156 143 145 151 155 160 151 158 164 159 126 149 164 149 140 131
[09:54:50.350] <TB1> INFO: ######################################################################
[09:54:50.350] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[09:54:50.350] <TB1> INFO: ######################################################################
[09:54:50.362] <TB1> INFO: scanning low vcal = 10
[09:54:54.171] <TB1> INFO: Test took 3809ms.
[09:54:54.176] <TB1> INFO: scanning low vcal = 20
[09:54:58.005] <TB1> INFO: Test took 3829ms.
[09:54:58.010] <TB1> INFO: scanning low vcal = 30
[09:55:01.889] <TB1> INFO: Test took 3879ms.
[09:55:01.899] <TB1> INFO: scanning low vcal = 40
[09:55:06.168] <TB1> INFO: Test took 4269ms.
[09:55:06.270] <TB1> INFO: scanning low vcal = 50
[09:55:10.577] <TB1> INFO: Test took 4307ms.
[09:55:10.638] <TB1> INFO: scanning low vcal = 60
[09:55:14.911] <TB1> INFO: Test took 4273ms.
[09:55:15.008] <TB1> INFO: scanning low vcal = 70
[09:55:19.273] <TB1> INFO: Test took 4265ms.
[09:55:19.351] <TB1> INFO: scanning low vcal = 80
[09:55:23.617] <TB1> INFO: Test took 4266ms.
[09:55:23.682] <TB1> INFO: scanning low vcal = 90
[09:55:27.943] <TB1> INFO: Test took 4261ms.
[09:55:28.043] <TB1> INFO: scanning low vcal = 100
[09:55:32.318] <TB1> INFO: Test took 4275ms.
[09:55:32.381] <TB1> INFO: scanning low vcal = 110
[09:55:36.646] <TB1> INFO: Test took 4265ms.
[09:55:36.707] <TB1> INFO: scanning low vcal = 120
[09:55:41.095] <TB1> INFO: Test took 4388ms.
[09:55:41.161] <TB1> INFO: scanning low vcal = 130
[09:55:45.543] <TB1> INFO: Test took 4382ms.
[09:55:45.622] <TB1> INFO: scanning low vcal = 140
[09:55:49.997] <TB1> INFO: Test took 4375ms.
[09:55:50.070] <TB1> INFO: scanning low vcal = 150
[09:55:54.455] <TB1> INFO: Test took 4385ms.
[09:55:54.524] <TB1> INFO: scanning low vcal = 160
[09:55:58.901] <TB1> INFO: Test took 4377ms.
[09:55:58.979] <TB1> INFO: scanning low vcal = 170
[09:56:03.388] <TB1> INFO: Test took 4409ms.
[09:56:03.467] <TB1> INFO: scanning low vcal = 180
[09:56:07.879] <TB1> INFO: Test took 4412ms.
[09:56:07.953] <TB1> INFO: scanning low vcal = 190
[09:56:12.484] <TB1> INFO: Test took 4531ms.
[09:56:12.569] <TB1> INFO: scanning low vcal = 200
[09:56:16.945] <TB1> INFO: Test took 4376ms.
[09:56:17.018] <TB1> INFO: scanning low vcal = 210
[09:56:21.375] <TB1> INFO: Test took 4357ms.
[09:56:21.437] <TB1> INFO: scanning low vcal = 220
[09:56:25.768] <TB1> INFO: Test took 4331ms.
[09:56:25.834] <TB1> INFO: scanning low vcal = 230
[09:56:30.165] <TB1> INFO: Test took 4331ms.
[09:56:30.228] <TB1> INFO: scanning low vcal = 240
[09:56:34.569] <TB1> INFO: Test took 4341ms.
[09:56:34.631] <TB1> INFO: scanning low vcal = 250
[09:56:39.033] <TB1> INFO: Test took 4402ms.
[09:56:39.111] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[09:56:43.511] <TB1> INFO: Test took 4400ms.
[09:56:43.569] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[09:56:47.931] <TB1> INFO: Test took 4362ms.
[09:56:48.001] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[09:56:52.361] <TB1> INFO: Test took 4360ms.
[09:56:52.435] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[09:56:56.855] <TB1> INFO: Test took 4420ms.
[09:56:56.935] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[09:57:01.332] <TB1> INFO: Test took 4397ms.
[09:57:01.847] <TB1> INFO: PixTestGainPedestal::measure() done
[09:57:34.632] <TB1> INFO: PixTestGainPedestal::fit() done
[09:57:34.632] <TB1> INFO: non-linearity mean: 0.953 0.953 0.951 0.955 0.956 0.958 0.958 0.960 0.949 0.959 0.952 0.953 0.958 0.950 0.954 0.952
[09:57:34.632] <TB1> INFO: non-linearity RMS: 0.006 0.006 0.006 0.006 0.006 0.013 0.005 0.005 0.007 0.005 0.006 0.005 0.004 0.006 0.005 0.007
[09:57:34.632] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[09:57:34.652] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[09:57:34.672] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[09:57:34.693] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[09:57:34.713] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[09:57:34.732] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[09:57:34.752] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[09:57:34.772] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[09:57:34.792] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[09:57:34.811] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[09:57:34.831] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[09:57:34.851] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[09:57:34.871] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[09:57:34.891] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[09:57:34.911] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[09:57:34.931] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[09:57:34.951] <TB1> INFO: PixTestGainPedestal::doTest() done, duration: 164 seconds
[09:57:34.958] <TB1> INFO: readReadbackCal: /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C0.dat .. /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C15.dat
[09:57:34.959] <TB1> INFO: PixTestReadback::doTest() start.
[09:57:34.960] <TB1> INFO: PixTestReadback::RES sent once
[09:57:54.921] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C0.dat
[09:57:54.921] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C1.dat
[09:57:54.921] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C2.dat
[09:57:54.921] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C3.dat
[09:57:54.921] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C4.dat
[09:57:54.921] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C5.dat
[09:57:54.921] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C6.dat
[09:57:54.922] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C7.dat
[09:57:54.922] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C8.dat
[09:57:54.922] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C9.dat
[09:57:54.922] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C10.dat
[09:57:54.922] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C11.dat
[09:57:54.922] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C12.dat
[09:57:54.922] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C13.dat
[09:57:54.922] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C14.dat
[09:57:54.922] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C15.dat
[09:57:54.968] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[09:57:54.969] <TB1> INFO: PixTestReadback::RES sent once
[09:58:11.466] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C0.dat
[09:58:11.467] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C1.dat
[09:58:11.467] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C2.dat
[09:58:11.467] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C3.dat
[09:58:11.467] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C4.dat
[09:58:11.467] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C5.dat
[09:58:11.467] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C6.dat
[09:58:11.467] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C7.dat
[09:58:11.467] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C8.dat
[09:58:11.468] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C9.dat
[09:58:11.468] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C10.dat
[09:58:11.468] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C11.dat
[09:58:11.468] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C12.dat
[09:58:11.468] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C13.dat
[09:58:11.468] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C14.dat
[09:58:11.468] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C15.dat
[09:58:11.514] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[09:58:11.515] <TB1> INFO: PixTestReadback::RES sent once
[09:58:24.299] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[09:58:24.299] <TB1> INFO: Vbg will be calibrated using Vd calibration
[09:58:24.299] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 155calibrated Vbg = 1.16725 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 150.1calibrated Vbg = 1.16483 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 151.1calibrated Vbg = 1.17461 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 255calibrated Vbg = 1.1725 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 151.7calibrated Vbg = 1.17937 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 150.5calibrated Vbg = 1.18824 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 149.3calibrated Vbg = 1.17742 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 255calibrated Vbg = 1.1725 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 151.8calibrated Vbg = 1.1851 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 148.3calibrated Vbg = 1.18581 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 149.7calibrated Vbg = 1.18787 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 255calibrated Vbg = 1.1725 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 150calibrated Vbg = 1.18054 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 150.5calibrated Vbg = 1.16761 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 152calibrated Vbg = 1.17365 :::*/*/*/*/
[09:58:24.300] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 245.4calibrated Vbg = 1.08422 :::*/*/*/*/
[09:58:24.303] <TB1> INFO: PixTestReadback::RES sent once
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C0.dat
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C1.dat
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C2.dat
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C3.dat
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C4.dat
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C5.dat
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C6.dat
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C7.dat
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C8.dat
[10:02:19.907] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C9.dat
[10:02:19.908] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C10.dat
[10:02:19.908] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C11.dat
[10:02:19.908] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C12.dat
[10:02:19.908] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C13.dat
[10:02:19.908] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C14.dat
[10:02:19.908] <TB1> INFO: write readback calibration parameters into /usr/local/coldboxDATA/M2085_FullQualification_2015-08-25_10h29m_1440491371//000_FulltestPxar_m20//readbackCal_C15.dat
[10:02:19.953] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[10:02:19.955] <TB1> INFO: PixTestReadback::doTest() done
[10:02:19.967] <TB1> INFO: enter test to run
[10:02:19.967] <TB1> INFO: test: exit no parameter change
[10:02:20.594] <TB1> QUIET: Connection to board 153 closed.
[10:02:20.674] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master