Test Date: 2015-07-24 10:42
Analysis date: 2016-05-25 23:08
Logfile
LogfileView
[11:30:09.418] <TB1> INFO: *** Welcome to pxar ***
[11:30:09.418] <TB1> INFO: *** Today: 2015/07/24
[11:30:09.418] <TB1> INFO: readRocDacs: /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C15.dat
[11:30:09.418] <TB1> INFO: readTbmDacs: /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//tbmParameters_C0b.dat
[11:30:09.419] <TB1> INFO: readMaskFile: /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//defaultMaskFile.dat
[11:30:09.419] <TB1> INFO: readTrimFile: /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters_C15.dat
[11:30:09.484] <TB1> INFO: clk: 4
[11:30:09.484] <TB1> INFO: ctr: 4
[11:30:09.484] <TB1> INFO: sda: 19
[11:30:09.484] <TB1> INFO: tin: 9
[11:30:09.484] <TB1> INFO: level: 15
[11:30:09.484] <TB1> INFO: triggerdelay: 0
[11:30:09.484] <TB1> QUIET: Instanciating API for pxar v2.2.5+46~gdbe75a1
[11:30:09.484] <TB1> INFO: Log level: INFO
[11:30:09.492] <TB1> INFO: Found DTB DTB_WXBYFL
[11:30:09.504] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[11:30:09.507] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[11:30:09.510] <TB1> INFO: RPC call hashes of host and DTB match: 447413373
[11:30:11.038] <TB1> INFO: DUT info:
[11:30:11.038] <TB1> INFO: The DUT currently contains the following objects:
[11:30:11.038] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[11:30:11.038] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:30:11.038] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:30:11.038] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:30:11.038] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.038] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.038] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.038] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.039] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:30:11.440] <TB1> INFO: enter 'restricted' command line mode
[11:30:11.440] <TB1> INFO: enter test to run
[11:30:11.440] <TB1> INFO: test: pretest no parameter change
[11:30:11.440] <TB1> INFO: running: pretest
[11:30:11.447] <TB1> INFO: ######################################################################
[11:30:11.447] <TB1> INFO: PixTestPretest::doTest()
[11:30:11.447] <TB1> INFO: ######################################################################
[11:30:11.448] <TB1> INFO: ----------------------------------------------------------------------
[11:30:11.449] <TB1> INFO: PixTestPretest::programROC()
[11:30:11.449] <TB1> INFO: ----------------------------------------------------------------------
[11:30:29.470] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:30:29.470] <TB1> INFO: IA differences per ROC: 18.5 17.7 19.3 18.5 20.1 19.3 19.3 19.3 16.9 19.3 20.9 21.7 18.5 19.3 20.1 18.5
[11:30:29.556] <TB1> INFO: ----------------------------------------------------------------------
[11:30:29.556] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:30:29.556] <TB1> INFO: ----------------------------------------------------------------------
[11:30:33.047] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 377 mA = 23.5625 mA/ROC
[11:30:33.051] <TB1> INFO: ----------------------------------------------------------------------
[11:30:33.051] <TB1> INFO: PixTestPretest::findWorkingPixel()
[11:30:33.051] <TB1> INFO: ----------------------------------------------------------------------
[11:30:41.444] <TB1> INFO: Test took 8389ms.
[11:30:41.754] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:30:41.806] <TB1> INFO: ----------------------------------------------------------------------
[11:30:41.806] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[11:30:41.806] <TB1> INFO: ----------------------------------------------------------------------
[11:30:50.115] <TB1> INFO: Test took 8301ms.
[11:30:50.439] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[11:30:50.439] <TB1> INFO: CalDel: 144 153 135 139 146 131 154 132 134 136 145 127 118 161 137 130
[11:30:50.439] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[11:30:50.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C0.dat
[11:30:50.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C1.dat
[11:30:50.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C2.dat
[11:30:50.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C3.dat
[11:30:50.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C4.dat
[11:30:50.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C5.dat
[11:30:50.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C6.dat
[11:30:50.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C7.dat
[11:30:50.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C8.dat
[11:30:50.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C9.dat
[11:30:50.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C10.dat
[11:30:50.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C11.dat
[11:30:50.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C12.dat
[11:30:50.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C13.dat
[11:30:50.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C14.dat
[11:30:50.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters_C15.dat
[11:30:50.445] <TB1> INFO: PixTestPretest::doTest() done, duration: 39 seconds
[11:30:50.532] <TB1> INFO: enter test to run
[11:30:50.532] <TB1> INFO: test: fulltest no parameter change
[11:30:50.532] <TB1> INFO: running: fulltest
[11:30:50.532] <TB1> INFO: ######################################################################
[11:30:50.532] <TB1> INFO: PixTestFullTest::doTest()
[11:30:50.532] <TB1> INFO: ######################################################################
[11:30:50.533] <TB1> INFO: ######################################################################
[11:30:50.533] <TB1> INFO: PixTestAlive::doTest()
[11:30:50.533] <TB1> INFO: ######################################################################
[11:30:50.535] <TB1> INFO: ----------------------------------------------------------------------
[11:30:50.535] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:30:50.535] <TB1> INFO: ----------------------------------------------------------------------
[11:30:54.030] <TB1> INFO: Test took 3493ms.
[11:30:54.054] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:54.303] <TB1> INFO: PixTestAlive::aliveTest() done
[11:30:54.303] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:30:54.305] <TB1> INFO: ----------------------------------------------------------------------
[11:30:54.305] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:30:54.305] <TB1> INFO: ----------------------------------------------------------------------
[11:30:57.049] <TB1> INFO: Test took 2742ms.
[11:30:57.051] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:57.052] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:30:57.298] <TB1> INFO: PixTestAlive::maskTest() done
[11:30:57.298] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:30:57.300] <TB1> INFO: ----------------------------------------------------------------------
[11:30:57.300] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:30:57.300] <TB1> INFO: ----------------------------------------------------------------------
[11:31:00.819] <TB1> INFO: Test took 3517ms.
[11:31:00.849] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:01.093] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[11:31:01.093] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:31:01.093] <TB1> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[11:31:01.105] <TB1> INFO: ######################################################################
[11:31:01.105] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:31:01.105] <TB1> INFO: ######################################################################
[11:31:01.110] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[11:31:01.269] <TB1> INFO: dacScan step from 0 .. 29
[11:31:22.755] <TB1> INFO: Test took 21485ms.
[11:31:22.790] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:22.790] <TB1> INFO: dacScan step from 30 .. 59
[11:31:46.865] <TB1> INFO: Test took 24075ms.
[11:31:46.987] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:47.018] <TB1> INFO: dacScan step from 60 .. 89
[11:32:16.663] <TB1> INFO: Test took 29645ms.
[11:32:16.943] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:17.004] <TB1> INFO: dacScan step from 90 .. 119
[11:32:46.624] <TB1> INFO: Test took 29620ms.
[11:32:46.882] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:46.943] <TB1> INFO: dacScan step from 120 .. 149
[11:33:11.793] <TB1> INFO: Test took 24850ms.
[11:33:11.974] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:36.191] <TB1> INFO: PixTestBBMap::doTest() done, duration: 155 seconds
[11:33:36.191] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 4 1 0 0 0 0 0 0 0
[11:33:36.191] <TB1> INFO: separation cut (per ROC): 71 76 92 85 76 84 67 87 87 89 66 96 88 96 89 76
[11:33:36.270] <TB1> INFO: ######################################################################
[11:33:36.270] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50
[11:33:36.270] <TB1> INFO: ######################################################################
[11:33:36.271] <TB1> INFO: ----------------------------------------------------------------------
[11:33:36.271] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[11:33:36.271] <TB1> INFO: ----------------------------------------------------------------------
[11:33:36.271] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[11:33:36.279] <TB1> INFO: dacScan step from 0 .. 3
[11:33:54.100] <TB1> INFO: Test took 17821ms.
[11:33:54.133] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:54.133] <TB1> INFO: dacScan step from 4 .. 7
[11:34:12.042] <TB1> INFO: Test took 17909ms.
[11:34:12.073] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:12.073] <TB1> INFO: dacScan step from 8 .. 11
[11:34:31.387] <TB1> INFO: Test took 19314ms.
[11:34:31.415] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:31.415] <TB1> INFO: dacScan step from 12 .. 15
[11:34:50.640] <TB1> INFO: Test took 19225ms.
[11:34:50.667] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:50.667] <TB1> INFO: dacScan step from 16 .. 19
[11:35:09.975] <TB1> INFO: Test took 19307ms.
[11:35:10.005] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:10.005] <TB1> INFO: dacScan step from 20 .. 23
[11:35:29.451] <TB1> INFO: Test took 19446ms.
[11:35:29.485] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:29.485] <TB1> INFO: dacScan step from 24 .. 27
[11:35:48.582] <TB1> INFO: Test took 19097ms.
[11:35:48.612] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:48.612] <TB1> INFO: dacScan step from 28 .. 31
[11:36:07.949] <TB1> INFO: Test took 19336ms.
[11:36:07.976] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:07.976] <TB1> INFO: dacScan step from 32 .. 35
[11:36:27.065] <TB1> INFO: Test took 19088ms.
[11:36:27.092] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:27.092] <TB1> INFO: dacScan step from 36 .. 39
[11:36:46.347] <TB1> INFO: Test took 19255ms.
[11:36:46.376] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:46.376] <TB1> INFO: dacScan step from 40 .. 43
[11:37:05.654] <TB1> INFO: Test took 19278ms.
[11:37:05.684] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:05.684] <TB1> INFO: dacScan step from 44 .. 47
[11:37:25.058] <TB1> INFO: Test took 19375ms.
[11:37:25.085] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:25.085] <TB1> INFO: dacScan step from 48 .. 51
[11:37:44.242] <TB1> INFO: Test took 19156ms.
[11:37:44.273] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:44.273] <TB1> INFO: dacScan step from 52 .. 55
[11:38:03.401] <TB1> INFO: Test took 19128ms.
[11:38:03.428] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:03.428] <TB1> INFO: dacScan step from 56 .. 59
[11:38:22.707] <TB1> INFO: Test took 19279ms.
[11:38:22.743] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:22.743] <TB1> INFO: dacScan step from 60 .. 63
[11:38:42.299] <TB1> INFO: Test took 19556ms.
[11:38:42.334] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:42.334] <TB1> INFO: dacScan step from 64 .. 67
[11:39:02.032] <TB1> INFO: Test took 19698ms.
[11:39:02.085] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:02.087] <TB1> INFO: dacScan step from 68 .. 71
[11:39:22.956] <TB1> INFO: Test took 20868ms.
[11:39:23.034] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:23.040] <TB1> INFO: dacScan step from 72 .. 75
[11:39:45.045] <TB1> INFO: Test took 22005ms.
[11:39:45.145] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:45.151] <TB1> INFO: dacScan step from 76 .. 79
[11:40:08.796] <TB1> INFO: Test took 23645ms.
[11:40:08.960] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:08.969] <TB1> INFO: dacScan step from 80 .. 83
[11:40:35.870] <TB1> INFO: Test took 26901ms.
[11:40:36.077] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:36.089] <TB1> INFO: dacScan step from 84 .. 87
[11:41:04.025] <TB1> INFO: Test took 27936ms.
[11:41:04.266] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:04.274] <TB1> INFO: dacScan step from 88 .. 91
[11:41:32.877] <TB1> INFO: Test took 28603ms.
[11:41:33.096] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:33.109] <TB1> INFO: dacScan step from 92 .. 95
[11:42:02.622] <TB1> INFO: Test took 29513ms.
[11:42:02.876] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:02.885] <TB1> INFO: dacScan step from 96 .. 99
[11:42:31.777] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[11:42:32.591] <TB1> INFO: Test took 29706ms.
[11:42:32.808] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:32.820] <TB1> INFO: dacScan step from 100 .. 103
[11:43:02.768] <TB1> INFO: Test took 29948ms.
[11:43:02.995] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:03.010] <TB1> INFO: dacScan step from 104 .. 107
[11:43:31.892] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[11:43:31.892] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (187) != TBM ID (188)

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

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

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

[11:43:33.210] <TB1> INFO: Test took 30200ms.
[11:43:33.448] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:33.461] <TB1> INFO: dacScan step from 108 .. 111
[11:44:02.138] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[11:44:02.138] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (109) != TBM ID (110)

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

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

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

[11:44:03.391] <TB1> INFO: Test took 29930ms.
[11:44:03.718] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:03.735] <TB1> INFO: dacScan step from 112 .. 115
[11:44:32.435] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (252) != TBM ID (0)

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

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

[11:44:33.740] <TB1> INFO: Test took 30005ms.
[11:44:34.022] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:34.033] <TB1> INFO: dacScan step from 116 .. 119
[11:45:02.778] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[11:45:04.119] <TB1> INFO: Test took 30086ms.
[11:45:04.388] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:04.402] <TB1> INFO: dacScan step from 120 .. 123
[11:45:33.133] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[11:45:34.440] <TB1> INFO: Test took 30038ms.
[11:45:34.687] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:34.698] <TB1> INFO: dacScan step from 124 .. 127
[11:46:04.742] <TB1> INFO: Test took 30044ms.
[11:46:05.051] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:05.063] <TB1> INFO: dacScan step from 128 .. 131
[11:46:35.002] <TB1> INFO: Test took 29939ms.
[11:46:35.251] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:35.265] <TB1> INFO: dacScan step from 132 .. 135
[11:47:05.007] <TB1> INFO: Test took 29742ms.
[11:47:05.233] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:05.244] <TB1> INFO: dacScan step from 136 .. 139
[11:47:35.058] <TB1> INFO: Test took 29814ms.
[11:47:35.356] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:35.366] <TB1> INFO: dacScan step from 140 .. 143
[11:48:05.312] <TB1> INFO: Test took 29946ms.
[11:48:05.591] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:05.604] <TB1> INFO: dacScan step from 144 .. 147
[11:48:33.673] <TB1> INFO: Test took 28069ms.
[11:48:33.951] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:33.962] <TB1> INFO: dacScan step from 148 .. 149
[11:48:49.326] <TB1> INFO: Test took 15364ms.
[11:48:49.452] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:49.458] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:48:50.976] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:48:52.526] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:48:54.020] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:48:55.549] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:48:57.107] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:48:58.775] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:00.326] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:01.912] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:03.314] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:04.929] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:06.369] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:07.709] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:09.095] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:10.712] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:12.260] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:49:13.790] <TB1> INFO: PixTestScurves::scurves() done
[11:49:13.790] <TB1> INFO: Vcal mean: 75.31 77.90 88.46 80.45 78.80 82.22 72.85 75.86 83.30 79.35 68.36 94.39 91.41 94.55 81.33 77.45
[11:49:13.790] <TB1> INFO: Vcal RMS: 4.22 5.07 5.59 4.34 4.36 4.70 4.60 4.88 4.75 5.20 4.52 6.39 6.22 5.67 4.94 4.47
[11:49:13.791] <TB1> INFO: PixTestScurves::fullTest() done, duration: 937 seconds
[11:49:13.863] <TB1> INFO: ######################################################################
[11:49:13.863] <TB1> INFO: PixTestTrim::doTest()
[11:49:13.863] <TB1> INFO: ######################################################################
[11:49:13.864] <TB1> INFO: ----------------------------------------------------------------------
[11:49:13.864] <TB1> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[11:49:13.864] <TB1> INFO: ----------------------------------------------------------------------
[11:49:13.947] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[11:49:13.947] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[11:49:13.955] <TB1> INFO: dacScan step from 0 .. 19
[11:49:29.246] <TB1> INFO: Test took 15291ms.
[11:49:29.270] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:29.270] <TB1> INFO: dacScan step from 20 .. 39
[11:49:44.513] <TB1> INFO: Test took 15243ms.
[11:49:44.538] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:44.538] <TB1> INFO: dacScan step from 40 .. 59
[11:49:59.737] <TB1> INFO: Test took 15199ms.
[11:49:59.761] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:59.761] <TB1> INFO: dacScan step from 60 .. 79
[11:50:15.024] <TB1> INFO: Test took 15263ms.
[11:50:15.051] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:15.051] <TB1> INFO: dacScan step from 80 .. 99
[11:50:31.866] <TB1> INFO: Test took 16815ms.
[11:50:31.956] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:31.971] <TB1> INFO: dacScan step from 100 .. 119
[11:50:51.627] <TB1> INFO: Test took 19656ms.
[11:50:51.798] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:51.832] <TB1> INFO: dacScan step from 120 .. 139
[11:51:09.294] <TB1> INFO: Test took 17462ms.
[11:51:09.440] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:09.467] <TB1> INFO: dacScan step from 140 .. 159
[11:51:25.229] <TB1> INFO: Test took 15762ms.
[11:51:25.297] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:47.821] <TB1> INFO: ROC 0 VthrComp = 80
[11:51:47.821] <TB1> INFO: ROC 1 VthrComp = 82
[11:51:47.822] <TB1> INFO: ROC 2 VthrComp = 96
[11:51:47.822] <TB1> INFO: ROC 3 VthrComp = 87
[11:51:47.822] <TB1> INFO: ROC 4 VthrComp = 85
[11:51:47.822] <TB1> INFO: ROC 5 VthrComp = 88
[11:51:47.822] <TB1> INFO: ROC 6 VthrComp = 77
[11:51:47.822] <TB1> INFO: ROC 7 VthrComp = 80
[11:51:47.822] <TB1> INFO: ROC 8 VthrComp = 89
[11:51:47.822] <TB1> INFO: ROC 9 VthrComp = 84
[11:51:47.823] <TB1> INFO: ROC 10 VthrComp = 75
[11:51:47.823] <TB1> INFO: ROC 11 VthrComp = 98
[11:51:47.823] <TB1> INFO: ROC 12 VthrComp = 93
[11:51:47.823] <TB1> INFO: ROC 13 VthrComp = 98
[11:51:47.823] <TB1> INFO: ROC 14 VthrComp = 87
[11:51:47.823] <TB1> INFO: ROC 15 VthrComp = 83
[11:51:47.823] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:51:47.823] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[11:51:47.831] <TB1> INFO: dacScan step from 0 .. 19
[11:52:02.279] <TB1> INFO: Test took 14447ms.
[11:52:02.300] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:02.300] <TB1> INFO: dacScan step from 20 .. 39
[11:52:17.673] <TB1> INFO: Test took 15372ms.
[11:52:17.709] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:17.713] <TB1> INFO: dacScan step from 40 .. 59
[11:52:36.962] <TB1> INFO: Test took 19249ms.
[11:52:37.113] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:37.157] <TB1> INFO: dacScan step from 60 .. 79
[11:52:57.811] <TB1> INFO: Test took 20654ms.
[11:52:57.981] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:58.023] <TB1> INFO: dacScan step from 80 .. 99
[11:53:18.513] <TB1> INFO: Test took 20490ms.
[11:53:18.685] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:18.725] <TB1> INFO: dacScan step from 100 .. 119
[11:53:39.141] <TB1> INFO: Test took 20416ms.
[11:53:39.303] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:39.344] <TB1> INFO: dacScan step from 120 .. 139
[11:53:58.418] <TB1> INFO: Test took 19074ms.
[11:53:58.683] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:58.754] <TB1> INFO: dacScan step from 140 .. 159
[11:54:18.131] <TB1> INFO: Test took 19377ms.
[11:54:18.314] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:46.674] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 56.6454 for pixel 25/76 mean/min/max = 45.0057/33.218/56.7934
[11:54:46.675] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 59.7085 for pixel 5/18 mean/min/max = 45.7316/31.6403/59.8229
[11:54:46.684] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 58.8935 for pixel 12/0 mean/min/max = 45.1405/31.0066/59.2743
[11:54:46.684] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 56.2756 for pixel 38/74 mean/min/max = 44.2832/32.1983/56.3681
[11:54:46.684] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 57.0808 for pixel 36/51 mean/min/max = 44.5326/31.8998/57.1653
[11:54:46.684] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 58.1584 for pixel 22/37 mean/min/max = 45.7363/33.2568/58.2157
[11:54:46.685] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 57.8959 for pixel 6/2 mean/min/max = 46.2766/34.5123/58.041
[11:54:46.685] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 58.3076 for pixel 3/79 mean/min/max = 45.6792/32.9702/58.3881
[11:54:46.685] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 58.1632 for pixel 51/0 mean/min/max = 45.356/32.5403/58.1718
[11:54:46.685] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 60.1574 for pixel 4/67 mean/min/max = 45.9151/31.6369/60.1932
[11:54:46.686] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 56.3623 for pixel 0/56 mean/min/max = 45.8051/35.2076/56.4026
[11:54:46.686] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 61.6793 for pixel 0/75 mean/min/max = 46.3447/30.8972/61.7922
[11:54:46.686] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 63.3571 for pixel 15/72 mean/min/max = 47.3664/31.3734/63.3594
[11:54:46.686] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 60.9315 for pixel 8/8 mean/min/max = 46.4558/31.9238/60.9879
[11:54:46.687] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 58.2463 for pixel 26/79 mean/min/max = 44.9804/31.5288/58.4319
[11:54:46.687] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 57.917 for pixel 27/79 mean/min/max = 44.8992/31.8546/57.9438
[11:54:46.687] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:56:24.363] <TB1> INFO: Test took 97676ms.
[11:56:25.953] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[11:56:25.961] <TB1> INFO: dacScan step from 0 .. 19
[11:56:49.328] <TB1> INFO: Test took 23367ms.
[11:56:49.383] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:49.385] <TB1> INFO: dacScan step from 20 .. 39
[11:57:18.465] <TB1> INFO: Test took 29080ms.
[11:57:18.693] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:18.723] <TB1> INFO: dacScan step from 40 .. 59
[11:57:50.543] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[11:57:51.628] <TB1> INFO: Test took 32904ms.
[11:57:51.908] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:51.957] <TB1> INFO: dacScan step from 60 .. 79
[11:58:23.074] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[11:58:24.234] <TB1> INFO: Test took 32277ms.
[11:58:24.558] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:24.605] <TB1> INFO: dacScan step from 80 .. 99
[11:58:58.317] <TB1> INFO: Test took 33712ms.
[11:58:58.593] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:58.635] <TB1> INFO: dacScan step from 100 .. 119
[11:59:31.272] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[11:59:32.640] <TB1> INFO: Test took 34005ms.
[11:59:32.944] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:33.013] <TB1> INFO: dacScan step from 120 .. 139
[12:00:06.879] <TB1> INFO: Test took 33866ms.
[12:00:07.230] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:07.275] <TB1> INFO: dacScan step from 140 .. 159
[12:00:40.057] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:00:41.360] <TB1> INFO: Test took 34084ms.
[12:00:41.640] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:41.689] <TB1> INFO: dacScan step from 160 .. 179
[12:01:15.153] <TB1> INFO: Test took 33464ms.
[12:01:15.433] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:15.485] <TB1> INFO: dacScan step from 180 .. 199
[12:01:46.790] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:01:46.790] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (255) != TBM ID (0)

[12:01:46.795] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 31 readouts!

[12:01:46.795] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 31 readouts!

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

[12:01:47.945] <TB1> INFO: Test took 32460ms.
[12:01:48.398] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:13.391] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.071008 .. 255.000000
[12:02:13.468] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[12:02:13.476] <TB1> INFO: dacScan step from 0 .. 19
[12:02:27.038] <TB1> INFO: Test took 13562ms.
[12:02:27.067] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:27.067] <TB1> INFO: dacScan step from 20 .. 39
[12:02:41.988] <TB1> INFO: Test took 14920ms.
[12:02:42.084] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:42.106] <TB1> INFO: dacScan step from 40 .. 59
[12:02:59.865] <TB1> INFO: Test took 17759ms.
[12:03:00.051] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:00.091] <TB1> INFO: dacScan step from 60 .. 79
[12:03:18.051] <TB1> INFO: Test took 17960ms.
[12:03:18.230] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:18.283] <TB1> INFO: dacScan step from 80 .. 99
[12:03:36.018] <TB1> INFO: Test took 17735ms.
[12:03:36.183] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:36.221] <TB1> INFO: dacScan step from 100 .. 119
[12:03:54.092] <TB1> INFO: Test took 17871ms.
[12:03:54.238] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:54.276] <TB1> INFO: dacScan step from 120 .. 139
[12:04:12.060] <TB1> INFO: Test took 17784ms.
[12:04:12.209] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:12.246] <TB1> INFO: dacScan step from 140 .. 159
[12:04:30.029] <TB1> INFO: Test took 17782ms.
[12:04:30.176] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:30.217] <TB1> INFO: dacScan step from 160 .. 179
[12:04:48.148] <TB1> INFO: Test took 17932ms.
[12:04:48.292] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:48.330] <TB1> INFO: dacScan step from 180 .. 199
[12:05:07.112] <TB1> INFO: Test took 18782ms.
[12:05:07.261] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:07.315] <TB1> INFO: dacScan step from 200 .. 219
[12:05:24.486] <TB1> INFO: Test took 17171ms.
[12:05:24.628] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:24.672] <TB1> INFO: dacScan step from 220 .. 239
[12:05:41.461] <TB1> INFO: Test took 16789ms.
[12:05:41.610] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:41.657] <TB1> INFO: dacScan step from 240 .. 255
[12:05:55.652] <TB1> INFO: Test took 13995ms.
[12:05:55.765] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:28.871] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 14.607231 .. 47.193119
[12:06:28.970] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 4 .. 57 (20) hits flags = 16 (plus default)
[12:06:28.979] <TB1> INFO: dacScan step from 4 .. 23
[12:06:42.715] <TB1> INFO: Test took 13736ms.
[12:06:42.734] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:42.735] <TB1> INFO: dacScan step from 24 .. 43
[12:06:58.355] <TB1> INFO: Test took 15620ms.
[12:06:58.457] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:58.483] <TB1> INFO: dacScan step from 44 .. 57
[12:07:10.969] <TB1> INFO: Test took 12486ms.
[12:07:11.074] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:27.341] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 21.111141 .. 44.900788
[12:07:27.437] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 11 .. 54 (20) hits flags = 16 (plus default)
[12:07:27.445] <TB1> INFO: dacScan step from 11 .. 30
[12:07:41.164] <TB1> INFO: Test took 13719ms.
[12:07:41.190] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:41.191] <TB1> INFO: dacScan step from 31 .. 50
[12:07:58.057] <TB1> INFO: Test took 16866ms.
[12:07:58.267] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:58.325] <TB1> INFO: dacScan step from 51 .. 54
[12:08:03.920] <TB1> INFO: Test took 5594ms.
[12:08:03.948] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:20.262] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 3.700669 .. 44.654919
[12:08:20.349] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 3 .. 54 (20) hits flags = 16 (plus default)
[12:08:20.357] <TB1> INFO: dacScan step from 3 .. 22
[12:08:34.091] <TB1> INFO: Test took 13734ms.
[12:08:34.118] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:34.118] <TB1> INFO: dacScan step from 23 .. 42
[12:08:48.559] <TB1> INFO: Test took 14440ms.
[12:08:48.652] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:48.676] <TB1> INFO: dacScan step from 43 .. 54
[12:09:00.025] <TB1> INFO: Test took 11348ms.
[12:09:00.143] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:16.426] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:09:16.426] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[12:09:16.434] <TB1> INFO: dacScan step from 15 .. 34
[12:09:40.108] <TB1> INFO: Test took 23674ms.
[12:09:40.173] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:40.181] <TB1> INFO: dacScan step from 35 .. 54
[12:10:11.395] <TB1> INFO: Test took 31214ms.
[12:10:11.686] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:11.728] <TB1> INFO: dacScan step from 55 .. 55
[12:10:16.059] <TB1> INFO: Test took 4330ms.
[12:10:16.075] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:30.348] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:10:30.348] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:10:30.348] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:10:30.348] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:10:30.349] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:10:30.349] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:10:30.349] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:10:30.349] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:10:30.349] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:10:30.349] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:10:30.349] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:10:30.349] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:10:30.349] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:10:30.350] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:10:30.350] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:10:30.350] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:10:30.350] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C0.dat
[12:10:30.358] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C1.dat
[12:10:30.367] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C2.dat
[12:10:30.376] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C3.dat
[12:10:30.384] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C4.dat
[12:10:30.393] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C5.dat
[12:10:30.401] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C6.dat
[12:10:30.410] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C7.dat
[12:10:30.420] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C8.dat
[12:10:30.430] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C9.dat
[12:10:30.439] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C10.dat
[12:10:30.452] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C11.dat
[12:10:30.462] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C12.dat
[12:10:30.472] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C13.dat
[12:10:30.481] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C14.dat
[12:10:30.491] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//trimParameters35_C15.dat
[12:10:30.500] <TB1> INFO: PixTestTrim::trimTest() done
[12:10:30.500] <TB1> INFO: vtrim: 96 104 105 106 100 111 113 105 99 135 111 114 127 118 118 101
[12:10:30.500] <TB1> INFO: vthrcomp: 80 82 96 87 85 88 77 80 89 84 75 98 93 98 87 83
[12:10:30.500] <TB1> INFO: vcal mean: 35.03 35.04 35.04 35.01 34.98 34.99 35.04 35.03 35.05 34.98 35.04 35.04 34.99 35.02 34.97 35.01
[12:10:30.500] <TB1> INFO: vcal RMS: 0.97 1.04 1.08 0.98 0.98 0.99 0.97 0.98 1.08 1.02 0.90 1.18 1.39 1.18 0.98 0.97
[12:10:30.500] <TB1> INFO: bits mean: 10.01 10.23 9.90 10.27 10.26 9.57 9.53 9.53 9.30 10.14 9.12 9.81 10.21 9.98 9.67 9.83
[12:10:30.500] <TB1> INFO: bits RMS: 2.31 2.41 2.68 2.41 2.42 2.53 2.30 2.57 2.74 2.47 2.39 2.65 2.31 2.45 2.70 2.58
[12:10:30.510] <TB1> INFO: ----------------------------------------------------------------------
[12:10:30.511] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[12:10:30.511] <TB1> INFO: ----------------------------------------------------------------------
[12:10:30.515] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:10:30.526] <TB1> INFO: dacScan step from 0 .. 19
[12:10:51.939] <TB1> INFO: Test took 21412ms.
[12:10:51.973] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:51.973] <TB1> INFO: dacScan step from 20 .. 39
[12:11:14.858] <TB1> INFO: Test took 22884ms.
[12:11:14.895] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:14.895] <TB1> INFO: dacScan step from 40 .. 59
[12:11:37.903] <TB1> INFO: Test took 23008ms.
[12:11:37.944] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:37.944] <TB1> INFO: dacScan step from 60 .. 79
[12:11:59.859] <TB1> INFO: Test took 21915ms.
[12:11:59.896] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:59.896] <TB1> INFO: dacScan step from 80 .. 99
[12:12:24.228] <TB1> INFO: Test took 24332ms.
[12:12:24.324] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:24.333] <TB1> INFO: dacScan step from 100 .. 119
[12:12:54.546] <TB1> INFO: Test took 30213ms.
[12:12:54.799] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:54.834] <TB1> INFO: dacScan step from 120 .. 139
[12:13:27.667] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[12:13:28.688] <TB1> INFO: Test took 33854ms.
[12:13:28.955] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:28.996] <TB1> INFO: dacScan step from 140 .. 159
[12:14:00.372] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:14:01.503] <TB1> INFO: Test took 32507ms.
[12:14:01.791] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:01.833] <TB1> INFO: dacScan step from 160 .. 179
[12:14:35.596] <TB1> INFO: Test took 33763ms.
[12:14:35.873] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:35.914] <TB1> INFO: dacScan step from 180 .. 199
[12:15:07.736] <TB1> INFO: Test took 31822ms.
[12:15:08.029] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:35.825] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 200 (20) hits flags = 16 (plus default)
[12:15:35.833] <TB1> INFO: dacScan step from 0 .. 19
[12:15:58.622] <TB1> INFO: Test took 22789ms.
[12:15:58.660] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:58.660] <TB1> INFO: dacScan step from 20 .. 39
[12:16:21.550] <TB1> INFO: Test took 22890ms.
[12:16:21.583] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:21.583] <TB1> INFO: dacScan step from 40 .. 59
[12:16:43.114] <TB1> INFO: Test took 21530ms.
[12:16:43.149] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:43.149] <TB1> INFO: dacScan step from 60 .. 79
[12:17:05.534] <TB1> INFO: Test took 22385ms.
[12:17:05.583] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:05.583] <TB1> INFO: dacScan step from 80 .. 99
[12:17:32.583] <TB1> INFO: Test took 27000ms.
[12:17:32.756] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:32.776] <TB1> INFO: dacScan step from 100 .. 119
[12:18:05.538] <TB1> INFO: Test took 32762ms.
[12:18:05.878] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:05.922] <TB1> INFO: dacScan step from 120 .. 139
[12:18:38.540] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:18:38.540] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (86) != TBM ID (87)

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

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

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

[12:18:39.853] <TB1> INFO: Test took 33931ms.
[12:18:40.126] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:40.162] <TB1> INFO: dacScan step from 140 .. 159
[12:19:12.672] <TB1> INFO: Test took 32510ms.
[12:19:12.961] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:13.006] <TB1> INFO: dacScan step from 160 .. 179
[12:19:45.246] <TB1> INFO: Test took 32240ms.
[12:19:45.551] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:45.602] <TB1> INFO: dacScan step from 180 .. 199
[12:20:20.070] <TB1> INFO: Test took 34468ms.
[12:20:20.348] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:20.393] <TB1> INFO: dacScan step from 200 .. 200
[12:20:24.792] <TB1> INFO: Test took 4399ms.
[12:20:24.813] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:52.458] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 182 (20) hits flags = 16 (plus default)
[12:20:52.466] <TB1> INFO: dacScan step from 0 .. 19
[12:21:13.845] <TB1> INFO: Test took 21378ms.
[12:21:13.879] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:13.879] <TB1> INFO: dacScan step from 20 .. 39
[12:21:36.846] <TB1> INFO: Test took 22967ms.
[12:21:36.883] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:36.883] <TB1> INFO: dacScan step from 40 .. 59
[12:21:59.877] <TB1> INFO: Test took 22994ms.
[12:21:59.921] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:59.921] <TB1> INFO: dacScan step from 60 .. 79
[12:22:23.130] <TB1> INFO: Test took 23210ms.
[12:22:23.173] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:23.173] <TB1> INFO: dacScan step from 80 .. 99
[12:22:50.531] <TB1> INFO: Test took 27357ms.
[12:22:50.715] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:50.739] <TB1> INFO: dacScan step from 100 .. 119
[12:23:21.399] <TB1> INFO: Test took 30660ms.
[12:23:21.703] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:21.741] <TB1> INFO: dacScan step from 120 .. 139
[12:23:55.386] <TB1> INFO: Test took 33645ms.
[12:23:55.650] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:55.713] <TB1> INFO: dacScan step from 140 .. 159
[12:24:29.438] <TB1> INFO: Test took 33725ms.
[12:24:29.714] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:29.754] <TB1> INFO: dacScan step from 160 .. 179
[12:25:01.644] <TB1> INFO: Test took 31890ms.
[12:25:01.940] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:01.989] <TB1> INFO: dacScan step from 180 .. 182
[12:25:08.984] <TB1> INFO: Test took 6995ms.
[12:25:09.025] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:32.978] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 183 (20) hits flags = 16 (plus default)
[12:25:32.986] <TB1> INFO: dacScan step from 0 .. 19
[12:25:54.502] <TB1> INFO: Test took 21515ms.
[12:25:54.536] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:54.536] <TB1> INFO: dacScan step from 20 .. 39
[12:26:17.571] <TB1> INFO: Test took 23035ms.
[12:26:17.612] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:17.613] <TB1> INFO: dacScan step from 40 .. 59
[12:26:40.579] <TB1> INFO: Test took 22966ms.
[12:26:40.615] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:40.615] <TB1> INFO: dacScan step from 60 .. 79
[12:27:03.760] <TB1> INFO: Test took 23145ms.
[12:27:03.800] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:03.800] <TB1> INFO: dacScan step from 80 .. 99
[12:27:28.490] <TB1> INFO: Test took 24689ms.
[12:27:28.661] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:28.680] <TB1> INFO: dacScan step from 100 .. 119
[12:28:01.520] <TB1> INFO: Test took 32840ms.
[12:28:01.866] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:01.905] <TB1> INFO: dacScan step from 120 .. 139
[12:28:34.345] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:28:34.345] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (41) != TBM ID (42)

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

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

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

[12:28:35.658] <TB1> INFO: Test took 33753ms.
[12:28:35.926] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:35.968] <TB1> INFO: dacScan step from 140 .. 159
[12:29:06.218] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:29:06.218] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (67) != TBM ID (68)

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

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

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

[12:29:07.508] <TB1> INFO: Test took 31539ms.
[12:29:07.789] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:07.831] <TB1> INFO: dacScan step from 160 .. 179
[12:29:41.504] <TB1> INFO: Test took 33673ms.
[12:29:41.797] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:41.843] <TB1> INFO: dacScan step from 180 .. 183
[12:29:50.854] <TB1> INFO: Test took 9011ms.
[12:29:50.917] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:19.546] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 157 (20) hits flags = 16 (plus default)
[12:30:19.555] <TB1> INFO: dacScan step from 0 .. 19
[12:30:42.573] <TB1> INFO: Test took 23018ms.
[12:30:42.612] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:42.612] <TB1> INFO: dacScan step from 20 .. 39
[12:31:04.738] <TB1> INFO: Test took 22126ms.
[12:31:04.776] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:04.776] <TB1> INFO: dacScan step from 40 .. 59
[12:31:26.767] <TB1> INFO: Test took 21991ms.
[12:31:26.805] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:26.805] <TB1> INFO: dacScan step from 60 .. 79
[12:31:49.863] <TB1> INFO: Test took 23058ms.
[12:31:49.905] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:49.906] <TB1> INFO: dacScan step from 80 .. 99
[12:32:17.199] <TB1> INFO: Test took 27293ms.
[12:32:17.391] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:17.413] <TB1> INFO: dacScan step from 100 .. 119
[12:32:48.049] <TB1> INFO: Test took 30636ms.
[12:32:48.395] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:48.436] <TB1> INFO: dacScan step from 120 .. 139
[12:33:21.124] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[12:33:22.390] <TB1> INFO: Test took 33954ms.
[12:33:22.679] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:22.723] <TB1> INFO: dacScan step from 140 .. 157
[12:33:53.345] <TB1> INFO: Test took 30622ms.
[12:33:53.662] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:15.202] <TB1> INFO: PixTestTrim::trimBitTest() done
[12:34:15.203] <TB1> INFO: PixTestTrim::doTest() done, duration: 2701 seconds
[12:34:15.925] <TB1> INFO: ######################################################################
[12:34:15.925] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:34:15.925] <TB1> INFO: ######################################################################
[12:34:19.413] <TB1> INFO: Test took 3487ms.
[12:34:19.435] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:23.089] <TB1> INFO: Test took 3455ms.
[12:34:23.155] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:26.629] <TB1> INFO: Test took 3461ms.
[12:34:26.719] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:26.728] <TB1> INFO: The DUT currently contains the following objects:
[12:34:26.728] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:26.728] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:26.728] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:26.728] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:26.728] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:26.728] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.840] <TB1> INFO: Test took 1112ms.
[12:34:27.841] <TB1> INFO: The DUT currently contains the following objects:
[12:34:27.841] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:27.841] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:27.841] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:27.841] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:27.841] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.841] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.841] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.841] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.841] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.841] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.841] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.842] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.842] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.842] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.842] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.842] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.842] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.842] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.842] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:27.842] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.953] <TB1> INFO: Test took 1111ms.
[12:34:28.955] <TB1> INFO: The DUT currently contains the following objects:
[12:34:28.955] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:28.955] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:28.955] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:28.955] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:28.955] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.955] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.955] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.955] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.955] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.955] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.955] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.955] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.955] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.955] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.956] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.956] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.956] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.956] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.956] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:28.956] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.067] <TB1> INFO: Test took 1111ms.
[12:34:30.068] <TB1> INFO: The DUT currently contains the following objects:
[12:34:30.068] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:30.068] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:30.068] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:30.069] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:30.069] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:30.069] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.194] <TB1> INFO: Test took 1125ms.
[12:34:31.195] <TB1> INFO: The DUT currently contains the following objects:
[12:34:31.195] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:31.195] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:31.195] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:31.195] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:31.195] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.195] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.195] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.195] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.195] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.195] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.195] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.195] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.195] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.195] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.196] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.196] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.196] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.196] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.196] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:31.196] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.306] <TB1> INFO: Test took 1110ms.
[12:34:32.307] <TB1> INFO: The DUT currently contains the following objects:
[12:34:32.308] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:32.308] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:32.308] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:32.308] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:32.308] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:32.308] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.418] <TB1> INFO: Test took 1110ms.
[12:34:33.419] <TB1> INFO: The DUT currently contains the following objects:
[12:34:33.419] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:33.419] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:33.419] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:33.419] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:33.419] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.419] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.420] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:33.420] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.529] <TB1> INFO: Test took 1109ms.
[12:34:34.531] <TB1> INFO: The DUT currently contains the following objects:
[12:34:34.531] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:34.531] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:34.531] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:34.531] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:34.531] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:34.531] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.643] <TB1> INFO: Test took 1112ms.
[12:34:35.645] <TB1> INFO: The DUT currently contains the following objects:
[12:34:35.645] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:35.645] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:35.645] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:35.645] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:35.645] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.645] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:35.646] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.750] <TB1> INFO: Test took 1104ms.
[12:34:36.751] <TB1> INFO: The DUT currently contains the following objects:
[12:34:36.751] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:36.751] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:36.751] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:36.751] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:36.751] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:36.751] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.877] <TB1> INFO: Test took 1126ms.
[12:34:37.879] <TB1> INFO: The DUT currently contains the following objects:
[12:34:37.879] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:37.879] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:37.879] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:37.879] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:37.879] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:37.879] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.991] <TB1> INFO: Test took 1112ms.
[12:34:38.992] <TB1> INFO: The DUT currently contains the following objects:
[12:34:38.992] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:38.992] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:38.992] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:38.992] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:38.992] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:38.993] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.104] <TB1> INFO: Test took 1111ms.
[12:34:40.106] <TB1> INFO: The DUT currently contains the following objects:
[12:34:40.106] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:40.106] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:40.106] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:40.106] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:40.106] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.106] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.106] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.106] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.106] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.106] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.106] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.106] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.106] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.107] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.107] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.107] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.107] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.107] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.107] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:40.107] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.218] <TB1> INFO: Test took 1111ms.
[12:34:41.220] <TB1> INFO: The DUT currently contains the following objects:
[12:34:41.220] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:41.220] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:41.220] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:41.220] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:41.220] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.220] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.221] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.221] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:41.221] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.326] <TB1> INFO: Test took 1105ms.
[12:34:42.327] <TB1> INFO: The DUT currently contains the following objects:
[12:34:42.327] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:42.327] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:42.327] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:42.327] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:42.327] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:42.327] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.432] <TB1> INFO: Test took 1105ms.
[12:34:43.433] <TB1> INFO: The DUT currently contains the following objects:
[12:34:43.433] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[12:34:43.433] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:34:43.433] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:34:43.433] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:34:43.433] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:43.433] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:34:44.538] <TB1> INFO: Test took 1105ms.
[12:34:44.543] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:38:34.863] <TB1> INFO: Test took 230320ms.
[12:38:36.557] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:23.848] <TB1> INFO: Test took 227291ms.
[12:42:25.769] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.777] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.786] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:42:25.794] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:42:25.802] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:42:25.811] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[12:42:25.819] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[12:42:25.827] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.835] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.843] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.852] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.859] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.867] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.874] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.882] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.889] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.896] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.903] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.909] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:42:25.916] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:42:25.923] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.930] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.936] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:42:25.991] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:42:25.992] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:42:25.992] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:42:25.992] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:42:25.992] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:42:25.992] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:42:25.992] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:42:25.992] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:42:25.992] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:42:25.993] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:42:25.993] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:42:25.993] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:42:25.993] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:42:25.993] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:42:25.993] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:42:25.993] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:42:29.406] <TB1> INFO: Test took 3408ms.
[12:42:33.030] <TB1> INFO: Test took 3300ms.
[12:42:36.637] <TB1> INFO: Test took 3323ms.
[12:42:36.963] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:37.878] <TB1> INFO: Test took 915ms.
[12:42:37.881] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:38.986] <TB1> INFO: Test took 1105ms.
[12:42:38.989] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:40.093] <TB1> INFO: Test took 1104ms.
[12:42:40.096] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:41.200] <TB1> INFO: Test took 1104ms.
[12:42:41.203] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:42.307] <TB1> INFO: Test took 1104ms.
[12:42:42.310] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:43.413] <TB1> INFO: Test took 1103ms.
[12:42:43.417] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:44.519] <TB1> INFO: Test took 1102ms.
[12:42:44.522] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:45.625] <TB1> INFO: Test took 1103ms.
[12:42:45.628] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:46.732] <TB1> INFO: Test took 1104ms.
[12:42:46.735] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:47.854] <TB1> INFO: Test took 1119ms.
[12:42:47.857] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:48.960] <TB1> INFO: Test took 1103ms.
[12:42:48.964] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:50.068] <TB1> INFO: Test took 1104ms.
[12:42:50.070] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:51.174] <TB1> INFO: Test took 1104ms.
[12:42:51.177] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:52.281] <TB1> INFO: Test took 1104ms.
[12:42:52.284] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:53.387] <TB1> INFO: Test took 1103ms.
[12:42:53.390] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:54.493] <TB1> INFO: Test took 1103ms.
[12:42:54.496] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:55.600] <TB1> INFO: Test took 1104ms.
[12:42:55.603] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:56.707] <TB1> INFO: Test took 1104ms.
[12:42:56.710] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:57.814] <TB1> INFO: Test took 1104ms.
[12:42:57.817] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:42:58.920] <TB1> INFO: Test took 1103ms.
[12:42:58.923] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:00.027] <TB1> INFO: Test took 1104ms.
[12:43:00.030] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:01.140] <TB1> INFO: Test took 1110ms.
[12:43:01.144] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:02.256] <TB1> INFO: Test took 1113ms.
[12:43:02.260] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:03.372] <TB1> INFO: Test took 1112ms.
[12:43:03.377] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:04.486] <TB1> INFO: Test took 1110ms.
[12:43:04.490] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:05.600] <TB1> INFO: Test took 1110ms.
[12:43:05.605] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:06.713] <TB1> INFO: Test took 1109ms.
[12:43:06.717] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:07.827] <TB1> INFO: Test took 1110ms.
[12:43:07.830] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:08.939] <TB1> INFO: Test took 1109ms.
[12:43:08.943] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:10.054] <TB1> INFO: Test took 1111ms.
[12:43:10.058] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:11.168] <TB1> INFO: Test took 1110ms.
[12:43:11.172] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:43:12.283] <TB1> INFO: Test took 1111ms.
[12:43:12.881] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 536 seconds
[12:43:12.881] <TB1> INFO: PH scale (per ROC): 93 93 90 83 82 92 83 89 79 86 92 80 80 93 87 85
[12:43:12.881] <TB1> INFO: PH offset (per ROC): 142 144 142 151 159 174 142 132 155 151 144 174 175 160 151 144
[12:43:13.109] <TB1> INFO: ######################################################################
[12:43:13.109] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:43:13.109] <TB1> INFO: ######################################################################
[12:43:13.121] <TB1> INFO: scanning low vcal = 10
[12:43:16.952] <TB1> INFO: Test took 3831ms.
[12:43:16.956] <TB1> INFO: scanning low vcal = 20
[12:43:20.857] <TB1> INFO: Test took 3901ms.
[12:43:20.861] <TB1> INFO: scanning low vcal = 30
[12:43:24.754] <TB1> INFO: Test took 3893ms.
[12:43:24.764] <TB1> INFO: scanning low vcal = 40
[12:43:29.149] <TB1> INFO: Test took 4385ms.
[12:43:29.214] <TB1> INFO: scanning low vcal = 50
[12:43:33.629] <TB1> INFO: Test took 4415ms.
[12:43:33.698] <TB1> INFO: scanning low vcal = 60
[12:43:38.181] <TB1> INFO: Test took 4483ms.
[12:43:38.253] <TB1> INFO: scanning low vcal = 70
[12:43:42.649] <TB1> INFO: Test took 4396ms.
[12:43:42.746] <TB1> INFO: scanning low vcal = 80
[12:43:47.136] <TB1> INFO: Test took 4390ms.
[12:43:47.226] <TB1> INFO: scanning low vcal = 90
[12:43:51.489] <TB1> INFO: Test took 4263ms.
[12:43:51.546] <TB1> INFO: scanning low vcal = 100
[12:43:55.750] <TB1> INFO: Test took 4204ms.
[12:43:55.808] <TB1> INFO: scanning low vcal = 110
[12:44:00.054] <TB1> INFO: Test took 4246ms.
[12:44:00.110] <TB1> INFO: scanning low vcal = 120
[12:44:04.359] <TB1> INFO: Test took 4248ms.
[12:44:04.454] <TB1> INFO: scanning low vcal = 130
[12:44:08.694] <TB1> INFO: Test took 4240ms.
[12:44:08.754] <TB1> INFO: scanning low vcal = 140
[12:44:12.989] <TB1> INFO: Test took 4235ms.
[12:44:13.046] <TB1> INFO: scanning low vcal = 150
[12:44:17.274] <TB1> INFO: Test took 4228ms.
[12:44:17.337] <TB1> INFO: scanning low vcal = 160
[12:44:21.714] <TB1> INFO: Test took 4377ms.
[12:44:21.819] <TB1> INFO: scanning low vcal = 170
[12:44:26.288] <TB1> INFO: Test took 4469ms.
[12:44:26.351] <TB1> INFO: scanning low vcal = 180
[12:44:30.726] <TB1> INFO: Test took 4375ms.
[12:44:30.786] <TB1> INFO: scanning low vcal = 190
[12:44:35.291] <TB1> INFO: Test took 4505ms.
[12:44:35.354] <TB1> INFO: scanning low vcal = 200
[12:44:39.763] <TB1> INFO: Test took 4409ms.
[12:44:39.823] <TB1> INFO: scanning low vcal = 210
[12:44:44.183] <TB1> INFO: Test took 4360ms.
[12:44:44.287] <TB1> INFO: scanning low vcal = 220
[12:44:48.672] <TB1> INFO: Test took 4385ms.
[12:44:48.733] <TB1> INFO: scanning low vcal = 230
[12:44:53.131] <TB1> INFO: Test took 4398ms.
[12:44:53.194] <TB1> INFO: scanning low vcal = 240
[12:44:57.563] <TB1> INFO: Test took 4369ms.
[12:44:57.644] <TB1> INFO: scanning low vcal = 250
[12:45:02.151] <TB1> INFO: Test took 4507ms.
[12:45:02.236] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[12:45:06.632] <TB1> INFO: Test took 4396ms.
[12:45:06.708] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[12:45:11.119] <TB1> INFO: Test took 4411ms.
[12:45:11.183] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[12:45:15.567] <TB1> INFO: Test took 4384ms.
[12:45:15.623] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[12:45:20.081] <TB1> INFO: Test took 4458ms.
[12:45:20.172] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:45:24.627] <TB1> INFO: Test took 4455ms.
[12:45:25.178] <TB1> INFO: PixTestGainPedestal::measure() done
[12:45:56.322] <TB1> INFO: PixTestGainPedestal::fit() done
[12:45:56.322] <TB1> INFO: non-linearity mean: 0.952 0.961 0.960 0.957 0.956 0.953 0.956 0.951 0.952 0.951 0.958 0.957 0.964 0.960 0.953 0.957
[12:45:56.322] <TB1> INFO: non-linearity RMS: 0.006 0.004 0.004 0.006 0.005 0.006 0.005 0.006 0.006 0.006 0.005 0.009 0.006 0.006 0.006 0.006
[12:45:56.323] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[12:45:56.343] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[12:45:56.363] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[12:45:56.384] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[12:45:56.404] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[12:45:56.424] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[12:45:56.445] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[12:45:56.464] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[12:45:56.484] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[12:45:56.503] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[12:45:56.523] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[12:45:56.543] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[12:45:56.563] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[12:45:56.583] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[12:45:56.603] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[12:45:56.623] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//002_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[12:45:56.643] <TB1> INFO: PixTestGainPedestal::doTest() done, duration: 163 seconds
[12:45:56.649] <TB1> INFO: enter test to run
[12:45:56.649] <TB1> INFO: test: exit no parameter change
[12:45:57.115] <TB1> QUIET: Connection to board 153 closed.
[12:45:57.195] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master