Test Date: 2015-08-19 10:30
Analysis date: 2016-05-25 22:56
Logfile
LogfileView
[11:19:37.599] <TB2> INFO: *** Welcome to pxar ***
[11:19:37.599] <TB2> INFO: *** Today: 2015/08/19
[11:19:37.599] <TB2> INFO: readRocDacs: /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C15.dat
[11:19:37.601] <TB2> INFO: readTbmDacs: /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//tbmParameters_C0b.dat
[11:19:37.601] <TB2> INFO: readMaskFile: /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//defaultMaskFile.dat
[11:19:37.601] <TB2> INFO: readTrimFile: /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters_C15.dat
[11:19:37.676] <TB2> INFO: clk: 4
[11:19:37.676] <TB2> INFO: ctr: 4
[11:19:37.676] <TB2> INFO: sda: 19
[11:19:37.676] <TB2> INFO: tin: 9
[11:19:37.676] <TB2> INFO: level: 15
[11:19:37.676] <TB2> INFO: triggerdelay: 0
[11:19:37.676] <TB2> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[11:19:37.676] <TB2> INFO: Log level: INFO
[11:19:37.684] <TB2> INFO: Found DTB DTB_WXC55Z
[11:19:37.692] <TB2> QUIET: Connection to board DTB_WXC55Z opened.
[11:19:37.695] <TB2> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 156
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXC55Z
MAC address: 40D85511809C
Hostname: pixelDTB156
Comment:
------------------------------------------------------
[11:19:37.698] <TB2> INFO: RPC call hashes of host and DTB match: 447413373
[11:19:39.273] <TB2> INFO: DUT info:
[11:19:39.273] <TB2> INFO: The DUT currently contains the following objects:
[11:19:39.273] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[11:19:39.273] <TB2> INFO: TBM Core alpha (0): 7 registers set
[11:19:39.273] <TB2> INFO: TBM Core beta (1): 7 registers set
[11:19:39.273] <TB2> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:19:39.273] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.273] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:39.675] <TB2> INFO: enter 'restricted' command line mode
[11:19:39.675] <TB2> INFO: enter test to run
[11:19:39.675] <TB2> INFO: test: pretest no parameter change
[11:19:39.675] <TB2> INFO: running: pretest
[11:19:39.682] <TB2> INFO: ######################################################################
[11:19:39.682] <TB2> INFO: PixTestPretest::doTest()
[11:19:39.682] <TB2> INFO: ######################################################################
[11:19:39.683] <TB2> INFO: ----------------------------------------------------------------------
[11:19:39.683] <TB2> INFO: PixTestPretest::programROC()
[11:19:39.683] <TB2> INFO: ----------------------------------------------------------------------
[11:19:57.700] <TB2> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:19:57.701] <TB2> INFO: IA differences per ROC: 19.3 19.3 20.1 20.1 20.1 17.7 20.1 19.3 18.5 20.1 16.9 19.3 20.9 19.3 18.5 18.5
[11:19:57.787] <TB2> INFO: ----------------------------------------------------------------------
[11:19:57.788] <TB2> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:19:57.788] <TB2> INFO: ----------------------------------------------------------------------
[11:20:03.071] <TB2> INFO: PixTestPretest::setVana() done, Module Ia 378.6 mA = 23.6625 mA/ROC
[11:20:03.074] <TB2> INFO: ----------------------------------------------------------------------
[11:20:03.074] <TB2> INFO: PixTestPretest::findWorkingPixel()
[11:20:03.074] <TB2> INFO: ----------------------------------------------------------------------
[11:20:11.566] <TB2> INFO: Test took 8487ms.
[11:20:11.877] <TB2> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:20:11.915] <TB2> INFO: ----------------------------------------------------------------------
[11:20:11.915] <TB2> INFO: PixTestPretest::setVthrCompCalDel()
[11:20:11.915] <TB2> INFO: ----------------------------------------------------------------------
[11:20:20.245] <TB2> INFO: Test took 8323ms.
[11:20:20.566] <TB2> INFO: PixTestPretest::setVthrCompCalDel() done
[11:20:20.566] <TB2> INFO: CalDel: 146 155 157 144 137 127 163 143 114 162 143 150 136 148 149 138
[11:20:20.566] <TB2> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[11:20:20.571] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C0.dat
[11:20:20.572] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C1.dat
[11:20:20.572] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C2.dat
[11:20:20.572] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C3.dat
[11:20:20.572] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C4.dat
[11:20:20.573] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C5.dat
[11:20:20.573] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C6.dat
[11:20:20.573] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C7.dat
[11:20:20.574] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C8.dat
[11:20:20.574] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C9.dat
[11:20:20.574] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C10.dat
[11:20:20.575] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C11.dat
[11:20:20.575] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C12.dat
[11:20:20.575] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C13.dat
[11:20:20.576] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C14.dat
[11:20:20.576] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters_C15.dat
[11:20:20.576] <TB2> INFO: PixTestPretest::doTest() done, duration: 40 seconds
[11:20:20.678] <TB2> INFO: enter test to run
[11:20:20.678] <TB2> INFO: test: fulltest no parameter change
[11:20:20.678] <TB2> INFO: running: fulltest
[11:20:20.678] <TB2> INFO: ######################################################################
[11:20:20.678] <TB2> INFO: PixTestFullTest::doTest()
[11:20:20.678] <TB2> INFO: ######################################################################
[11:20:20.679] <TB2> INFO: ######################################################################
[11:20:20.679] <TB2> INFO: PixTestAlive::doTest()
[11:20:20.679] <TB2> INFO: ######################################################################
[11:20:20.681] <TB2> INFO: ----------------------------------------------------------------------
[11:20:20.681] <TB2> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:20:20.681] <TB2> INFO: ----------------------------------------------------------------------
[11:20:24.160] <TB2> INFO: Test took 3478ms.
[11:20:24.193] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:24.422] <TB2> INFO: PixTestAlive::aliveTest() done
[11:20:24.422] <TB2> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0
[11:20:24.425] <TB2> INFO: ----------------------------------------------------------------------
[11:20:24.425] <TB2> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:20:24.425] <TB2> INFO: ----------------------------------------------------------------------
[11:20:27.207] <TB2> INFO: Test took 2780ms.
[11:20:27.211] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:27.211] <TB2> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:20:27.441] <TB2> INFO: PixTestAlive::maskTest() done
[11:20:27.441] <TB2> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:20:27.443] <TB2> INFO: ----------------------------------------------------------------------
[11:20:27.443] <TB2> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:20:27.443] <TB2> INFO: ----------------------------------------------------------------------
[11:20:31.176] <TB2> INFO: Test took 3731ms.
[11:20:31.199] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:31.432] <TB2> INFO: PixTestAlive::addressDecodingTest() done
[11:20:31.432] <TB2> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:20:31.432] <TB2> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[11:20:31.447] <TB2> INFO: ######################################################################
[11:20:31.447] <TB2> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:20:31.447] <TB2> INFO: ######################################################################
[11:20:31.453] <TB2> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[11:20:31.470] <TB2> INFO: dacScan step from 0 .. 29
[11:20:53.718] <TB2> INFO: Test took 22248ms.
[11:20:53.759] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:53.759] <TB2> INFO: dacScan step from 30 .. 59
[11:21:18.587] <TB2> INFO: Test took 24828ms.
[11:21:18.710] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:18.729] <TB2> INFO: dacScan step from 60 .. 89
[11:21:48.441] <TB2> INFO: Test took 29712ms.
[11:21:48.725] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:21:48.809] <TB2> INFO: dacScan step from 90 .. 119
[11:22:18.448] <TB2> INFO: Test took 29639ms.
[11:22:18.733] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:22:18.808] <TB2> INFO: dacScan step from 120 .. 149
[11:22:42.012] <TB2> INFO: Test took 23204ms.
[11:22:42.181] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:05.572] <TB2> INFO: PixTestBBMap::doTest() done, duration: 154 seconds
[11:23:05.572] <TB2> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 1 4
[11:23:05.572] <TB2> INFO: separation cut (per ROC): 86 89 96 95 97 94 88 70 68 74 75 73 90 86 68 72
[11:23:05.650] <TB2> INFO: ######################################################################
[11:23:05.650] <TB2> INFO: PixTestScurves::fullTest() ntrig = 50
[11:23:05.650] <TB2> INFO: ######################################################################
[11:23:05.650] <TB2> INFO: ----------------------------------------------------------------------
[11:23:05.650] <TB2> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[11:23:05.650] <TB2> INFO: ----------------------------------------------------------------------
[11:23:05.650] <TB2> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[11:23:05.659] <TB2> INFO: dacScan step from 0 .. 3
[11:23:24.573] <TB2> INFO: Test took 18914ms.
[11:23:24.599] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:24.599] <TB2> INFO: dacScan step from 4 .. 7
[11:23:44.785] <TB2> INFO: Test took 20186ms.
[11:23:44.817] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:23:44.817] <TB2> INFO: dacScan step from 8 .. 11
[11:24:05.065] <TB2> INFO: Test took 20248ms.
[11:24:05.098] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:05.098] <TB2> INFO: dacScan step from 12 .. 15
[11:24:25.337] <TB2> INFO: Test took 20239ms.
[11:24:25.362] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:25.362] <TB2> INFO: dacScan step from 16 .. 19
[11:24:45.768] <TB2> INFO: Test took 20406ms.
[11:24:45.797] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:24:45.797] <TB2> INFO: dacScan step from 20 .. 23
[11:25:05.955] <TB2> INFO: Test took 20158ms.
[11:25:05.983] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:05.983] <TB2> INFO: dacScan step from 24 .. 27
[11:25:26.178] <TB2> INFO: Test took 20195ms.
[11:25:26.206] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:26.206] <TB2> INFO: dacScan step from 28 .. 31
[11:25:46.456] <TB2> INFO: Test took 20250ms.
[11:25:46.487] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:46.487] <TB2> INFO: dacScan step from 32 .. 35
[11:26:06.636] <TB2> INFO: Test took 20148ms.
[11:26:06.666] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:06.666] <TB2> INFO: dacScan step from 36 .. 39
[11:26:26.848] <TB2> INFO: Test took 20182ms.
[11:26:26.878] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:26.878] <TB2> INFO: dacScan step from 40 .. 43
[11:26:47.276] <TB2> INFO: Test took 20398ms.
[11:26:47.306] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:47.306] <TB2> INFO: dacScan step from 44 .. 47
[11:27:08.008] <TB2> INFO: Test took 20702ms.
[11:27:08.034] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:08.034] <TB2> INFO: dacScan step from 48 .. 51
[11:27:28.765] <TB2> INFO: Test took 20731ms.
[11:27:28.799] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:28.799] <TB2> INFO: dacScan step from 52 .. 55
[11:27:49.794] <TB2> INFO: Test took 20995ms.
[11:27:49.827] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:49.828] <TB2> INFO: dacScan step from 56 .. 59
[11:28:10.823] <TB2> INFO: Test took 20995ms.
[11:28:10.862] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:10.862] <TB2> INFO: dacScan step from 60 .. 63
[11:28:32.658] <TB2> INFO: Test took 21796ms.
[11:28:32.707] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:32.708] <TB2> INFO: dacScan step from 64 .. 67
[11:28:55.230] <TB2> INFO: Test took 22522ms.
[11:28:55.297] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:55.299] <TB2> INFO: dacScan step from 68 .. 71
[11:29:19.430] <TB2> INFO: Test took 24131ms.
[11:29:19.522] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:19.526] <TB2> INFO: dacScan step from 72 .. 75
[11:29:45.369] <TB2> INFO: Test took 25843ms.
[11:29:45.481] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:45.486] <TB2> INFO: dacScan step from 76 .. 79
[11:30:13.209] <TB2> INFO: Test took 27723ms.
[11:30:13.371] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:13.378] <TB2> INFO: dacScan step from 80 .. 83
[11:30:42.989] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:30:42.989] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:30:43.016] <TB2> INFO: Test took 29638ms.
[11:30:43.206] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:30:43.215] <TB2> INFO: dacScan step from 84 .. 87
[11:31:15.301] <TB2> INFO: Test took 32086ms.
[11:31:15.539] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:15.550] <TB2> INFO: dacScan step from 88 .. 91
[11:31:47.550] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (122) != TBM ID (0)

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

[11:31:47.550] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (123)

[11:31:48.575] <TB2> INFO: Test took 33025ms.
[11:31:48.805] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:48.817] <TB2> INFO: dacScan step from 92 .. 95
[11:32:20.898] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (153) != TBM ID (0)

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

[11:32:20.898] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (154)

[11:32:22.099] <TB2> INFO: Test took 33282ms.
[11:32:22.384] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:22.399] <TB2> INFO: dacScan step from 96 .. 99
[11:32:54.314] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:32:54.314] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:32:55.576] <TB2> INFO: Test took 33177ms.
[11:32:55.875] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:32:55.891] <TB2> INFO: dacScan step from 100 .. 103
[11:33:28.142] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:33:28.143] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:33:29.418] <TB2> INFO: Test took 33527ms.
[11:33:29.670] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:29.687] <TB2> INFO: dacScan step from 104 .. 107
[11:34:01.521] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:34:01.521] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:34:02.795] <TB2> INFO: Test took 33108ms.
[11:34:03.070] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:03.086] <TB2> INFO: dacScan step from 108 .. 111
[11:34:35.063] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:34:35.063] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:34:36.368] <TB2> INFO: Test took 33282ms.
[11:34:36.675] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:36.691] <TB2> INFO: dacScan step from 112 .. 115
[11:35:08.489] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[11:35:08.489] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (195) != TBM ID (196)

[11:35:08.489] <TB2> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[11:35:08.489] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[11:35:08.489] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:35:09.786] <TB2> INFO: Test took 33095ms.
[11:35:10.041] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:10.053] <TB2> INFO: dacScan step from 116 .. 119
[11:35:43.176] <TB2> INFO: Test took 33122ms.
[11:35:43.443] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:43.458] <TB2> INFO: dacScan step from 120 .. 123
[11:36:16.142] <TB2> INFO: Test took 32684ms.
[11:36:16.391] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:16.405] <TB2> INFO: dacScan step from 124 .. 127
[11:36:49.624] <TB2> INFO: Test took 33219ms.
[11:36:49.930] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:49.946] <TB2> INFO: dacScan step from 128 .. 131
[11:37:22.682] <TB2> INFO: Test took 32735ms.
[11:37:22.938] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:22.952] <TB2> INFO: dacScan step from 132 .. 135
[11:37:55.562] <TB2> INFO: Test took 32609ms.
[11:37:55.866] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:55.881] <TB2> INFO: dacScan step from 136 .. 139
[11:38:27.411] <TB2> INFO: Test took 31530ms.
[11:38:27.654] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:27.667] <TB2> INFO: dacScan step from 140 .. 143
[11:38:57.600] <TB2> INFO: Test took 29933ms.
[11:38:57.829] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:38:57.841] <TB2> INFO: dacScan step from 144 .. 147
[11:39:25.554] <TB2> INFO: Test took 27713ms.
[11:39:25.824] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:25.839] <TB2> INFO: dacScan step from 148 .. 149
[11:39:41.723] <TB2> INFO: Test took 15883ms.
[11:39:41.848] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:41.857] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:43.463] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:44.948] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:46.571] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:48.134] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:49.544] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:51.098] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:52.730] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:54.410] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:56.134] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:57.687] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:39:59.414] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:40:01.165] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:40:02.788] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:40:04.519] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:40:06.274] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[11:40:08.054] <TB2> INFO: PixTestScurves::scurves() done
[11:40:08.054] <TB2> INFO: Vcal mean: 82.32 78.69 89.01 82.05 88.24 79.84 92.78 63.92 71.65 78.87 80.44 73.95 83.13 77.10 69.57 71.57
[11:40:08.054] <TB2> INFO: Vcal RMS: 4.84 4.94 5.64 5.29 5.05 4.74 5.60 5.14 4.62 4.50 5.30 5.33 5.57 4.59 4.56 5.26
[11:40:08.054] <TB2> INFO: PixTestScurves::fullTest() done, duration: 1022 seconds
[11:40:08.142] <TB2> INFO: ######################################################################
[11:40:08.142] <TB2> INFO: PixTestTrim::doTest()
[11:40:08.142] <TB2> INFO: ######################################################################
[11:40:08.144] <TB2> INFO: ----------------------------------------------------------------------
[11:40:08.144] <TB2> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[11:40:08.144] <TB2> INFO: ----------------------------------------------------------------------
[11:40:08.241] <TB2> INFO: ---> VthrComp thr map (minimal VthrComp)
[11:40:08.241] <TB2> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[11:40:08.250] <TB2> INFO: dacScan step from 0 .. 19
[11:40:23.392] <TB2> INFO: Test took 15142ms.
[11:40:23.413] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:23.413] <TB2> INFO: dacScan step from 20 .. 39
[11:40:38.550] <TB2> INFO: Test took 15137ms.
[11:40:38.574] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:38.574] <TB2> INFO: dacScan step from 40 .. 59
[11:40:53.263] <TB2> INFO: Test took 14689ms.
[11:40:53.284] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:53.284] <TB2> INFO: dacScan step from 60 .. 79
[11:41:08.637] <TB2> INFO: Test took 15353ms.
[11:41:08.660] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:08.661] <TB2> INFO: dacScan step from 80 .. 99
[11:41:26.087] <TB2> INFO: Test took 17426ms.
[11:41:26.201] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:26.223] <TB2> INFO: dacScan step from 100 .. 119
[11:41:46.519] <TB2> INFO: Test took 20296ms.
[11:41:46.704] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:46.743] <TB2> INFO: dacScan step from 120 .. 139
[11:42:03.722] <TB2> INFO: Test took 16979ms.
[11:42:03.841] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:03.864] <TB2> INFO: dacScan step from 140 .. 159
[11:42:20.182] <TB2> INFO: Test took 16318ms.
[11:42:20.233] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:45.587] <TB2> INFO: ROC 0 VthrComp = 86
[11:42:45.587] <TB2> INFO: ROC 1 VthrComp = 83
[11:42:45.587] <TB2> INFO: ROC 2 VthrComp = 93
[11:42:45.587] <TB2> INFO: ROC 3 VthrComp = 89
[11:42:45.587] <TB2> INFO: ROC 4 VthrComp = 95
[11:42:45.587] <TB2> INFO: ROC 5 VthrComp = 88
[11:42:45.588] <TB2> INFO: ROC 6 VthrComp = 94
[11:42:45.588] <TB2> INFO: ROC 7 VthrComp = 70
[11:42:45.588] <TB2> INFO: ROC 8 VthrComp = 78
[11:42:45.588] <TB2> INFO: ROC 9 VthrComp = 86
[11:42:45.589] <TB2> INFO: ROC 10 VthrComp = 80
[11:42:45.589] <TB2> INFO: ROC 11 VthrComp = 77
[11:42:45.589] <TB2> INFO: ROC 12 VthrComp = 88
[11:42:45.589] <TB2> INFO: ROC 13 VthrComp = 82
[11:42:45.589] <TB2> INFO: ROC 14 VthrComp = 75
[11:42:45.589] <TB2> INFO: ROC 15 VthrComp = 75
[11:42:45.590] <TB2> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:42:45.590] <TB2> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[11:42:45.599] <TB2> INFO: dacScan step from 0 .. 19
[11:43:01.027] <TB2> INFO: Test took 15427ms.
[11:43:01.056] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:01.056] <TB2> INFO: dacScan step from 20 .. 39
[11:43:17.715] <TB2> INFO: Test took 16659ms.
[11:43:17.746] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:17.749] <TB2> INFO: dacScan step from 40 .. 59
[11:43:38.649] <TB2> INFO: Test took 20900ms.
[11:43:38.796] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:38.834] <TB2> INFO: dacScan step from 60 .. 79
[11:44:00.582] <TB2> INFO: Test took 21748ms.
[11:44:00.850] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:00.938] <TB2> INFO: dacScan step from 80 .. 99
[11:44:21.595] <TB2> INFO: Test took 20657ms.
[11:44:21.763] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:21.832] <TB2> INFO: dacScan step from 100 .. 119
[11:44:44.416] <TB2> INFO: Test took 22584ms.
[11:44:44.582] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:44.639] <TB2> INFO: dacScan step from 120 .. 139
[11:45:03.749] <TB2> INFO: Test took 19110ms.
[11:45:03.912] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:03.971] <TB2> INFO: dacScan step from 140 .. 159
[11:45:24.940] <TB2> INFO: Test took 20969ms.
[11:45:25.124] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:53.067] <TB2> INFO: roc 0 with ID = 0 has maximal Vcal 58.6083 for pixel 0/60 mean/min/max = 45.306/31.9554/58.6567
[11:45:53.067] <TB2> INFO: roc 1 with ID = 1 has maximal Vcal 59.3493 for pixel 13/75 mean/min/max = 45.4455/31.5083/59.3826
[11:45:53.068] <TB2> INFO: roc 2 with ID = 2 has maximal Vcal 59.8683 for pixel 0/12 mean/min/max = 46.2427/32.5877/59.8977
[11:45:53.068] <TB2> INFO: roc 3 with ID = 3 has maximal Vcal 59.9504 for pixel 4/69 mean/min/max = 45.9842/31.9158/60.0526
[11:45:53.068] <TB2> INFO: roc 4 with ID = 4 has maximal Vcal 57.4672 for pixel 21/78 mean/min/max = 44.6578/31.8373/57.4784
[11:45:53.068] <TB2> INFO: roc 5 with ID = 5 has maximal Vcal 58.157 for pixel 0/75 mean/min/max = 45.3974/32.5808/58.2141
[11:45:53.069] <TB2> INFO: roc 6 with ID = 6 has maximal Vcal 60.0288 for pixel 11/13 mean/min/max = 46.0067/31.9414/60.0721
[11:45:53.069] <TB2> INFO: roc 7 with ID = 7 has maximal Vcal 59.3334 for pixel 2/7 mean/min/max = 45.9284/32.383/59.4739
[11:45:53.069] <TB2> INFO: roc 8 with ID = 8 has maximal Vcal 56.6772 for pixel 0/5 mean/min/max = 45.9748/35.1541/56.7955
[11:45:53.069] <TB2> INFO: roc 9 with ID = 9 has maximal Vcal 57.4376 for pixel 10/1 mean/min/max = 44.7949/31.9186/57.6713
[11:45:53.070] <TB2> INFO: roc 10 with ID = 10 has maximal Vcal 61.3287 for pixel 18/79 mean/min/max = 46.5829/31.6954/61.4705
[11:45:53.070] <TB2> INFO: roc 11 with ID = 11 has maximal Vcal 61.7378 for pixel 0/55 mean/min/max = 47.5717/33.372/61.7714
[11:45:53.070] <TB2> INFO: roc 12 with ID = 12 has maximal Vcal 61.3548 for pixel 0/54 mean/min/max = 46.8518/32.2297/61.4739
[11:45:53.071] <TB2> INFO: roc 13 with ID = 13 has maximal Vcal 58.3536 for pixel 15/79 mean/min/max = 45.389/32.2221/58.5559
[11:45:53.071] <TB2> INFO: roc 14 with ID = 14 has maximal Vcal 57.1942 for pixel 5/17 mean/min/max = 46.3386/35.3523/57.3249
[11:45:53.071] <TB2> INFO: roc 15 with ID = 15 has maximal Vcal 60.9882 for pixel 0/64 mean/min/max = 47.5938/34.1658/61.0218
[11:45:53.071] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:47:32.491] <TB2> INFO: Test took 99420ms.
[11:47:33.843] <TB2> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[11:47:33.852] <TB2> INFO: dacScan step from 0 .. 19
[11:47:56.705] <TB2> INFO: Test took 22853ms.
[11:47:56.755] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:56.756] <TB2> INFO: dacScan step from 20 .. 39
[11:48:24.807] <TB2> INFO: Test took 28050ms.
[11:48:25.031] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:25.079] <TB2> INFO: dacScan step from 40 .. 59
[11:48:58.243] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (0)

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

[11:48:58.243] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (10)

[11:48:59.331] <TB2> INFO: Test took 34252ms.
[11:48:59.614] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:59.679] <TB2> INFO: dacScan step from 60 .. 79
[11:49:32.604] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (218) != TBM ID (0)

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

[11:49:32.604] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (219)

[11:49:33.898] <TB2> INFO: Test took 34219ms.
[11:49:34.186] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:34.240] <TB2> INFO: dacScan step from 80 .. 99
[11:50:09.748] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:50:09.748] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[11:50:11.048] <TB2> INFO: Test took 36808ms.
[11:50:11.332] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:11.389] <TB2> INFO: dacScan step from 100 .. 119
[11:50:46.259] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:50:46.259] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:50:47.576] <TB2> INFO: Test took 36187ms.
[11:50:47.863] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:47.909] <TB2> INFO: dacScan step from 120 .. 139
[11:51:20.975] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:51:20.975] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:51:22.021] <TB2> INFO: Test took 34112ms.
[11:51:22.312] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:22.360] <TB2> INFO: dacScan step from 140 .. 159
[11:51:56.787] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (227) != TBM ID (0)

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

[11:51:56.787] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (228)

[11:51:58.045] <TB2> INFO: Test took 35684ms.
[11:51:58.336] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:58.382] <TB2> INFO: dacScan step from 160 .. 179
[11:52:33.274] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:52:33.274] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:52:34.385] <TB2> INFO: Test took 36003ms.
[11:52:34.797] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:34.850] <TB2> INFO: dacScan step from 180 .. 199
[11:53:05.704] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[11:53:05.704] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[11:53:06.979] <TB2> INFO: Test took 32129ms.
[11:53:07.326] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:36.171] <TB2> INFO: ---> TrimStepCorr4 extremal thresholds: 0.124766 .. 255.000000
[11:53:36.267] <TB2> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[11:53:36.276] <TB2> INFO: dacScan step from 0 .. 19
[11:53:49.971] <TB2> INFO: Test took 13695ms.
[11:53:49.998] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:49.998] <TB2> INFO: dacScan step from 20 .. 39
[11:54:05.336] <TB2> INFO: Test took 15337ms.
[11:54:05.415] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:05.432] <TB2> INFO: dacScan step from 40 .. 59
[11:54:24.497] <TB2> INFO: Test took 19064ms.
[11:54:24.649] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:24.695] <TB2> INFO: dacScan step from 60 .. 79
[11:54:43.625] <TB2> INFO: Test took 18930ms.
[11:54:43.771] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:43.816] <TB2> INFO: dacScan step from 80 .. 99
[11:55:02.420] <TB2> INFO: Test took 18604ms.
[11:55:02.565] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:02.612] <TB2> INFO: dacScan step from 100 .. 119
[11:55:20.873] <TB2> INFO: Test took 18261ms.
[11:55:21.102] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:21.172] <TB2> INFO: dacScan step from 120 .. 139
[11:55:39.299] <TB2> INFO: Test took 18127ms.
[11:55:39.441] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:39.489] <TB2> INFO: dacScan step from 140 .. 159
[11:55:58.612] <TB2> INFO: Test took 19123ms.
[11:55:58.764] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:58.807] <TB2> INFO: dacScan step from 160 .. 179
[11:56:17.947] <TB2> INFO: Test took 19139ms.
[11:56:18.103] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:18.154] <TB2> INFO: dacScan step from 180 .. 199
[11:56:37.497] <TB2> INFO: Test took 19333ms.
[11:56:37.638] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:37.683] <TB2> INFO: dacScan step from 200 .. 219
[11:56:54.960] <TB2> INFO: Test took 17277ms.
[11:56:55.096] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:55.144] <TB2> INFO: dacScan step from 220 .. 239
[11:57:11.862] <TB2> INFO: Test took 16718ms.
[11:57:12.004] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:12.054] <TB2> INFO: dacScan step from 240 .. 255
[11:57:25.986] <TB2> INFO: Test took 13932ms.
[11:57:26.101] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:56.966] <TB2> INFO: ---> TrimStepCorr2 extremal thresholds: 11.856178 .. 46.652484
[11:57:57.042] <TB2> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 1 .. 56 (20) hits flags = 16 (plus default)
[11:57:57.051] <TB2> INFO: dacScan step from 1 .. 20
[11:58:10.068] <TB2> INFO: Test took 13017ms.
[11:58:10.087] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:10.087] <TB2> INFO: dacScan step from 21 .. 40
[11:58:24.453] <TB2> INFO: Test took 14366ms.
[11:58:24.530] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:24.548] <TB2> INFO: dacScan step from 41 .. 56
[11:58:39.337] <TB2> INFO: Test took 14789ms.
[11:58:39.468] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:55.680] <TB2> INFO: ---> TrimStepCorr1a extremal thresholds: 17.573365 .. 42.455171
[11:58:55.761] <TB2> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 7 .. 52 (20) hits flags = 16 (plus default)
[11:58:55.770] <TB2> INFO: dacScan step from 7 .. 26
[11:59:08.938] <TB2> INFO: Test took 13168ms.
[11:59:08.957] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:08.957] <TB2> INFO: dacScan step from 27 .. 46
[11:59:25.854] <TB2> INFO: Test took 16897ms.
[11:59:25.967] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:25.999] <TB2> INFO: dacScan step from 47 .. 52
[11:59:32.947] <TB2> INFO: Test took 6947ms.
[11:59:32.994] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:49.782] <TB2> INFO: ---> TrimStepCorr1b extremal thresholds: 1.909365 .. 40.898182
[11:59:49.871] <TB2> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 50 (20) hits flags = 16 (plus default)
[11:59:49.881] <TB2> INFO: dacScan step from 1 .. 20
[12:00:02.951] <TB2> INFO: Test took 13070ms.
[12:00:02.970] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:02.970] <TB2> INFO: dacScan step from 21 .. 40
[12:00:18.118] <TB2> INFO: Test took 15148ms.
[12:00:18.203] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:18.222] <TB2> INFO: dacScan step from 41 .. 50
[12:00:29.440] <TB2> INFO: Test took 11218ms.
[12:00:29.514] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:46.047] <TB2> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:00:46.047] <TB2> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[12:00:46.056] <TB2> INFO: dacScan step from 15 .. 34
[12:01:09.691] <TB2> INFO: Test took 23635ms.
[12:01:09.752] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:09.762] <TB2> INFO: dacScan step from 35 .. 54
[12:01:42.349] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[12:01:42.349] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (80) != TBM ID (81)

[12:01:42.349] <TB2> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[12:01:42.349] <TB2> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[12:01:42.349] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:01:43.194] <TB2> INFO: Test took 33432ms.
[12:01:43.490] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:43.534] <TB2> INFO: dacScan step from 55 .. 55
[12:01:47.901] <TB2> INFO: Test took 4367ms.
[12:01:47.925] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:02.427] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:02:02.428] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:02:02.428] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:02:02.428] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:02:02.428] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:02:02.429] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:02:02.429] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:02:02.429] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:02:02.429] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:02:02.429] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:02:02.430] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:02:02.430] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:02:02.430] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:02:02.430] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:02:02.430] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:02:02.431] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:02:02.431] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C0.dat
[12:02:02.440] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C1.dat
[12:02:02.447] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C2.dat
[12:02:02.454] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C3.dat
[12:02:02.461] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C4.dat
[12:02:02.467] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C5.dat
[12:02:02.473] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C6.dat
[12:02:02.480] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C7.dat
[12:02:02.486] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C8.dat
[12:02:02.493] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C9.dat
[12:02:02.499] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C10.dat
[12:02:02.506] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C11.dat
[12:02:02.512] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C12.dat
[12:02:02.519] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C13.dat
[12:02:02.525] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C14.dat
[12:02:02.531] <TB2> INFO: write trim parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//trimParameters35_C15.dat
[12:02:02.538] <TB2> INFO: PixTestTrim::trimTest() done
[12:02:02.538] <TB2> INFO: vtrim: 106 106 101 115 107 96 119 106 100 100 100 108 170 99 96 106
[12:02:02.538] <TB2> INFO: vthrcomp: 86 83 93 89 95 88 94 70 78 86 80 77 88 82 75 75
[12:02:02.538] <TB2> INFO: vcal mean: 35.02 35.04 35.03 35.04 35.00 35.01 35.04 35.03 35.04 35.01 35.07 35.05 35.05 35.02 35.06 35.04
[12:02:02.538] <TB2> INFO: vcal RMS: 0.99 1.00 1.00 0.96 1.00 0.96 1.09 1.03 1.04 1.01 1.03 0.95 1.26 1.14 0.95 1.04
[12:02:02.538] <TB2> INFO: bits mean: 9.75 10.07 9.25 9.66 10.15 9.57 10.11 10.15 8.90 9.94 9.48 8.76 11.05 9.93 9.14 9.21
[12:02:02.538] <TB2> INFO: bits RMS: 2.62 2.50 2.70 2.60 2.48 2.59 2.42 2.36 2.51 2.54 2.70 2.70 1.85 2.52 2.37 2.46
[12:02:02.545] <TB2> INFO: ----------------------------------------------------------------------
[12:02:02.545] <TB2> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[12:02:02.545] <TB2> INFO: ----------------------------------------------------------------------
[12:02:02.547] <TB2> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:02:02.557] <TB2> INFO: dacScan step from 0 .. 19
[12:02:26.412] <TB2> INFO: Test took 23855ms.
[12:02:26.455] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:26.455] <TB2> INFO: dacScan step from 20 .. 39
[12:02:50.104] <TB2> INFO: Test took 23649ms.
[12:02:50.146] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:50.146] <TB2> INFO: dacScan step from 40 .. 59
[12:03:14.196] <TB2> INFO: Test took 24049ms.
[12:03:14.237] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:14.237] <TB2> INFO: dacScan step from 60 .. 79
[12:03:38.020] <TB2> INFO: Test took 23783ms.
[12:03:38.063] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:38.063] <TB2> INFO: dacScan step from 80 .. 99
[12:04:01.380] <TB2> INFO: Test took 23317ms.
[12:04:01.489] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:01.498] <TB2> INFO: dacScan step from 100 .. 119
[12:04:31.543] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:04:31.548] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[12:04:31.556] <TB2> INFO: Test took 30057ms.
[12:04:31.823] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:31.860] <TB2> INFO: dacScan step from 120 .. 139
[12:05:06.235] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:05:06.235] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:05:07.505] <TB2> INFO: Test took 35645ms.
[12:05:07.824] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:07.873] <TB2> INFO: dacScan step from 140 .. 159
[12:05:42.705] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:05:42.705] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:05:44.026] <TB2> INFO: Test took 36153ms.
[12:05:44.332] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:05:44.376] <TB2> INFO: dacScan step from 160 .. 179
[12:06:19.409] <TB2> INFO: Test took 35032ms.
[12:06:19.689] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:19.738] <TB2> INFO: dacScan step from 180 .. 199
[12:06:52.347] <TB2> INFO: Test took 32609ms.
[12:06:52.652] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:21.560] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 155 (20) hits flags = 16 (plus default)
[12:07:21.571] <TB2> INFO: dacScan step from 0 .. 19
[12:07:45.260] <TB2> INFO: Test took 23689ms.
[12:07:45.305] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:45.305] <TB2> INFO: dacScan step from 20 .. 39
[12:08:09.772] <TB2> INFO: Test took 24467ms.
[12:08:09.809] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:09.809] <TB2> INFO: dacScan step from 40 .. 59
[12:08:34.525] <TB2> INFO: Test took 24715ms.
[12:08:34.563] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:34.564] <TB2> INFO: dacScan step from 60 .. 79
[12:08:57.123] <TB2> INFO: Test took 22559ms.
[12:08:57.175] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:57.176] <TB2> INFO: dacScan step from 80 .. 99
[12:09:25.617] <TB2> INFO: Test took 28441ms.
[12:09:25.821] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:25.843] <TB2> INFO: dacScan step from 100 .. 119
[12:09:59.053] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:09:59.053] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:10:00.256] <TB2> INFO: Test took 34413ms.
[12:10:00.557] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:00.598] <TB2> INFO: dacScan step from 120 .. 139
[12:10:34.534] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[12:10:34.534] <TB2> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[12:10:35.983] <TB2> INFO: Test took 35385ms.
[12:10:36.299] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:36.350] <TB2> INFO: dacScan step from 140 .. 155
[12:11:01.624] <TB2> INFO: Test took 25274ms.
[12:11:01.989] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:24.357] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 146 (20) hits flags = 16 (plus default)
[12:11:24.366] <TB2> INFO: dacScan step from 0 .. 19
[12:11:49.326] <TB2> INFO: Test took 24960ms.
[12:11:49.362] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:49.362] <TB2> INFO: dacScan step from 20 .. 39
[12:12:13.946] <TB2> INFO: Test took 24584ms.
[12:12:13.987] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:13.987] <TB2> INFO: dacScan step from 40 .. 59
[12:12:38.886] <TB2> INFO: Test took 24899ms.
[12:12:38.926] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:38.926] <TB2> INFO: dacScan step from 60 .. 79
[12:13:03.728] <TB2> INFO: Test took 24802ms.
[12:13:03.780] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:03.781] <TB2> INFO: dacScan step from 80 .. 99
[12:13:34.738] <TB2> INFO: Test took 30957ms.
[12:13:34.942] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:34.962] <TB2> INFO: dacScan step from 100 .. 119
[12:14:09.132] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (185) != TBM ID (0)

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

[12:14:09.132] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (186)

[12:14:10.390] <TB2> INFO: Test took 35428ms.
[12:14:10.685] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:10.733] <TB2> INFO: dacScan step from 120 .. 139
[12:14:44.303] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:14:45.417] <TB2> INFO: Test took 34684ms.
[12:14:45.714] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:45.773] <TB2> INFO: dacScan step from 140 .. 146
[12:14:58.126] <TB2> INFO: Test took 12353ms.
[12:14:58.226] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:19.949] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 146 (20) hits flags = 16 (plus default)
[12:15:19.958] <TB2> INFO: dacScan step from 0 .. 19
[12:15:43.710] <TB2> INFO: Test took 23752ms.
[12:15:43.750] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:43.750] <TB2> INFO: dacScan step from 20 .. 39
[12:16:07.344] <TB2> INFO: Test took 23594ms.
[12:16:07.381] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:07.381] <TB2> INFO: dacScan step from 40 .. 59
[12:16:30.951] <TB2> INFO: Test took 23570ms.
[12:16:30.989] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:30.989] <TB2> INFO: dacScan step from 60 .. 79
[12:16:52.996] <TB2> INFO: Test took 22007ms.
[12:16:53.048] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:53.049] <TB2> INFO: dacScan step from 80 .. 99
[12:17:23.227] <TB2> INFO: Test took 30177ms.
[12:17:23.426] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:23.447] <TB2> INFO: dacScan step from 100 .. 119
[12:17:56.845] <TB2> INFO: Test took 33398ms.
[12:17:57.153] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:57.199] <TB2> INFO: dacScan step from 120 .. 139
[12:18:28.717] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:18:29.889] <TB2> INFO: Test took 32690ms.
[12:18:30.197] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:30.254] <TB2> INFO: dacScan step from 140 .. 146
[12:18:42.721] <TB2> INFO: Test took 12467ms.
[12:18:42.821] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:05.322] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 146 (20) hits flags = 16 (plus default)
[12:19:05.331] <TB2> INFO: dacScan step from 0 .. 19
[12:19:26.709] <TB2> INFO: Test took 21378ms.
[12:19:26.745] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:26.745] <TB2> INFO: dacScan step from 20 .. 39
[12:19:49.206] <TB2> INFO: Test took 22461ms.
[12:19:49.240] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:49.240] <TB2> INFO: dacScan step from 40 .. 59
[12:20:12.153] <TB2> INFO: Test took 22913ms.
[12:20:12.190] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:12.190] <TB2> INFO: dacScan step from 60 .. 79
[12:20:33.632] <TB2> INFO: Test took 21442ms.
[12:20:33.684] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:33.686] <TB2> INFO: dacScan step from 80 .. 99
[12:21:02.259] <TB2> INFO: Test took 28573ms.
[12:21:02.460] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:02.481] <TB2> INFO: dacScan step from 100 .. 119
[12:21:35.818] <TB2> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (32) != TBM ID (0)

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

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

[12:21:36.967] <TB2> INFO: Test took 34486ms.
[12:21:37.239] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:37.284] <TB2> INFO: dacScan step from 120 .. 139
[12:22:11.065] <TB2> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[12:22:12.476] <TB2> INFO: Test took 35192ms.
[12:22:12.795] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:12.849] <TB2> INFO: dacScan step from 140 .. 146
[12:22:25.455] <TB2> INFO: Test took 12606ms.
[12:22:25.558] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:48.399] <TB2> INFO: PixTestTrim::trimBitTest() done
[12:22:48.401] <TB2> INFO: PixTestTrim::doTest() done, duration: 2560 seconds
[12:22:49.076] <TB2> INFO: ######################################################################
[12:22:49.076] <TB2> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:22:49.076] <TB2> INFO: ######################################################################
[12:22:52.542] <TB2> INFO: Test took 3465ms.
[12:22:52.571] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:56.305] <TB2> INFO: Test took 3536ms.
[12:22:56.377] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:59.840] <TB2> INFO: Test took 3450ms.
[12:22:59.909] <TB2> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:59.916] <TB2> INFO: The DUT currently contains the following objects:
[12:22:59.916] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:22:59.916] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:22:59.916] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:22:59.916] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:22:59.916] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:22:59.916] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.024] <TB2> INFO: Test took 1108ms.
[12:23:01.026] <TB2> INFO: The DUT currently contains the following objects:
[12:23:01.026] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:01.026] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:01.026] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:01.026] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:01.026] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.026] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.027] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.027] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.027] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.027] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:01.027] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.134] <TB2> INFO: Test took 1107ms.
[12:23:02.137] <TB2> INFO: The DUT currently contains the following objects:
[12:23:02.138] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:02.138] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:02.138] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:02.138] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:02.138] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:02.138] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.258] <TB2> INFO: Test took 1120ms.
[12:23:03.259] <TB2> INFO: The DUT currently contains the following objects:
[12:23:03.259] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:03.259] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:03.259] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:03.259] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:03.259] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.259] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:03.260] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.367] <TB2> INFO: Test took 1107ms.
[12:23:04.368] <TB2> INFO: The DUT currently contains the following objects:
[12:23:04.368] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:04.368] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:04.368] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:04.368] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:04.368] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:04.368] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.475] <TB2> INFO: Test took 1107ms.
[12:23:05.476] <TB2> INFO: The DUT currently contains the following objects:
[12:23:05.476] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:05.476] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:05.476] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:05.476] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:05.476] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.476] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.477] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.477] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:05.477] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.586] <TB2> INFO: Test took 1109ms.
[12:23:06.588] <TB2> INFO: The DUT currently contains the following objects:
[12:23:06.588] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:06.588] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:06.588] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:06.588] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:06.588] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.588] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:06.589] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.696] <TB2> INFO: Test took 1107ms.
[12:23:07.697] <TB2> INFO: The DUT currently contains the following objects:
[12:23:07.697] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:07.697] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:07.697] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:07.697] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:07.697] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.697] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.698] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.698] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.698] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:07.698] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.804] <TB2> INFO: Test took 1106ms.
[12:23:08.805] <TB2> INFO: The DUT currently contains the following objects:
[12:23:08.805] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:08.805] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:08.805] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:08.805] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:08.805] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.805] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:08.806] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.912] <TB2> INFO: Test took 1106ms.
[12:23:09.913] <TB2> INFO: The DUT currently contains the following objects:
[12:23:09.913] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:09.913] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:09.914] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:09.914] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:09.914] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:09.914] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.036] <TB2> INFO: Test took 1122ms.
[12:23:11.037] <TB2> INFO: The DUT currently contains the following objects:
[12:23:11.037] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:11.037] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:11.037] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:11.037] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:11.037] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.037] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.037] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.037] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.037] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.037] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.037] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.037] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.038] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.038] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.038] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.038] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.038] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.038] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.038] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:11.038] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.145] <TB2> INFO: Test took 1107ms.
[12:23:12.146] <TB2> INFO: The DUT currently contains the following objects:
[12:23:12.146] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:12.146] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:12.146] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:12.146] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:12.146] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.146] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.147] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.147] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.147] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:12.147] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.254] <TB2> INFO: Test took 1107ms.
[12:23:13.256] <TB2> INFO: The DUT currently contains the following objects:
[12:23:13.256] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:13.256] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:13.256] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:13.256] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:13.256] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.256] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.257] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.257] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.257] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:13.257] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.364] <TB2> INFO: Test took 1107ms.
[12:23:14.365] <TB2> INFO: The DUT currently contains the following objects:
[12:23:14.365] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:14.365] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:14.365] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:14.365] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:14.365] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.365] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.366] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.366] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.366] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.366] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:14.366] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.473] <TB2> INFO: Test took 1108ms.
[12:23:15.475] <TB2> INFO: The DUT currently contains the following objects:
[12:23:15.475] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:15.475] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:15.475] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:15.475] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:15.475] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.475] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.476] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.476] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.476] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:15.476] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.584] <TB2> INFO: Test took 1108ms.
[12:23:16.585] <TB2> INFO: The DUT currently contains the following objects:
[12:23:16.585] <TB2> INFO: 2 TBM Cores tbm09c (2 ON)
[12:23:16.585] <TB2> INFO: TBM Core alpha (0): 7 registers set
[12:23:16.585] <TB2> INFO: TBM Core beta (1): 7 registers set
[12:23:16.585] <TB2> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:23:16.585] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.585] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.585] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:16.586] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:23:17.721] <TB2> INFO: Test took 1135ms.
[12:23:17.725] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:27:22.643] <TB2> INFO: Test took 244918ms.
[12:27:24.441] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:20.648] <TB2> INFO: Test took 236207ms.
[12:31:22.364] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.371] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.378] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.385] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.392] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.399] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.406] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.414] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.423] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.431] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.438] <TB2> INFO: safety margin for low PH: adding 1, margin is now 21
[12:31:22.444] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.451] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.458] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.465] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.473] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.479] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[12:31:22.523] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:31:22.523] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:31:22.523] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:31:22.524] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:31:22.524] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:31:22.524] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:31:22.524] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:31:22.525] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:31:22.525] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:31:22.525] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:31:22.525] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:31:22.526] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:31:22.526] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:31:22.526] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:31:22.526] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:31:22.527] <TB2> INFO: write dac parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:31:26.079] <TB2> INFO: Test took 3549ms.
[12:31:29.834] <TB2> INFO: Test took 3482ms.
[12:31:33.702] <TB2> INFO: Test took 3564ms.
[12:31:33.987] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:34.919] <TB2> INFO: Test took 932ms.
[12:31:34.922] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:36.031] <TB2> INFO: Test took 1109ms.
[12:31:36.035] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:37.144] <TB2> INFO: Test took 1109ms.
[12:31:37.147] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:38.257] <TB2> INFO: Test took 1110ms.
[12:31:38.261] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:39.366] <TB2> INFO: Test took 1105ms.
[12:31:39.369] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:40.477] <TB2> INFO: Test took 1108ms.
[12:31:40.481] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:41.590] <TB2> INFO: Test took 1109ms.
[12:31:41.594] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:42.703] <TB2> INFO: Test took 1109ms.
[12:31:42.706] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:43.812] <TB2> INFO: Test took 1106ms.
[12:31:43.816] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:44.925] <TB2> INFO: Test took 1110ms.
[12:31:44.929] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:46.034] <TB2> INFO: Test took 1106ms.
[12:31:46.038] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:47.144] <TB2> INFO: Test took 1106ms.
[12:31:47.148] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:48.254] <TB2> INFO: Test took 1106ms.
[12:31:48.257] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:49.366] <TB2> INFO: Test took 1109ms.
[12:31:49.369] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:50.479] <TB2> INFO: Test took 1110ms.
[12:31:50.483] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:51.590] <TB2> INFO: Test took 1108ms.
[12:31:51.593] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:52.699] <TB2> INFO: Test took 1106ms.
[12:31:52.702] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:53.812] <TB2> INFO: Test took 1110ms.
[12:31:53.816] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:54.916] <TB2> INFO: Test took 1100ms.
[12:31:54.918] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:56.018] <TB2> INFO: Test took 1100ms.
[12:31:56.021] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:57.133] <TB2> INFO: Test took 1112ms.
[12:31:57.136] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:58.235] <TB2> INFO: Test took 1100ms.
[12:31:58.238] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:31:59.336] <TB2> INFO: Test took 1098ms.
[12:31:59.339] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:32:00.438] <TB2> INFO: Test took 1099ms.
[12:32:00.441] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:32:01.539] <TB2> INFO: Test took 1098ms.
[12:32:01.542] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:32:02.641] <TB2> INFO: Test took 1099ms.
[12:32:02.644] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:32:03.746] <TB2> INFO: Test took 1102ms.
[12:32:03.748] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:32:04.847] <TB2> INFO: Test took 1099ms.
[12:32:04.850] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:32:05.949] <TB2> INFO: Test took 1099ms.
[12:32:05.952] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:32:07.050] <TB2> INFO: Test took 1098ms.
[12:32:07.053] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:32:08.152] <TB2> INFO: Test took 1099ms.
[12:32:08.155] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:32:09.283] <TB2> INFO: Test took 1128ms.
[12:32:09.788] <TB2> INFO: PixTestPhOptimization::doTest() done, duration: 560 seconds
[12:32:09.788] <TB2> INFO: PH scale (per ROC): 80 84 78 75 89 87 71 87 100 90 85 80 79 82 91 92
[12:32:09.788] <TB2> INFO: PH offset (per ROC): 178 155 160 154 157 156 169 147 119 160 147 155 171 143 144 150
[12:32:09.972] <TB2> INFO: ######################################################################
[12:32:09.972] <TB2> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:32:09.972] <TB2> INFO: ######################################################################
[12:32:09.982] <TB2> INFO: scanning low vcal = 10
[12:32:13.741] <TB2> INFO: Test took 3759ms.
[12:32:13.744] <TB2> INFO: scanning low vcal = 20
[12:32:17.605] <TB2> INFO: Test took 3861ms.
[12:32:17.608] <TB2> INFO: scanning low vcal = 30
[12:32:21.490] <TB2> INFO: Test took 3882ms.
[12:32:21.496] <TB2> INFO: scanning low vcal = 40
[12:32:25.912] <TB2> INFO: Test took 4416ms.
[12:32:25.967] <TB2> INFO: scanning low vcal = 50
[12:32:30.595] <TB2> INFO: Test took 4628ms.
[12:32:30.669] <TB2> INFO: scanning low vcal = 60
[12:32:35.366] <TB2> INFO: Test took 4697ms.
[12:32:35.445] <TB2> INFO: scanning low vcal = 70
[12:32:40.201] <TB2> INFO: Test took 4756ms.
[12:32:40.296] <TB2> INFO: scanning low vcal = 80
[12:32:44.883] <TB2> INFO: Test took 4587ms.
[12:32:44.937] <TB2> INFO: scanning low vcal = 90
[12:32:49.624] <TB2> INFO: Test took 4686ms.
[12:32:49.688] <TB2> INFO: scanning low vcal = 100
[12:32:54.458] <TB2> INFO: Test took 4770ms.
[12:32:54.518] <TB2> INFO: scanning low vcal = 110
[12:32:59.046] <TB2> INFO: Test took 4528ms.
[12:32:59.130] <TB2> INFO: scanning low vcal = 120
[12:33:03.764] <TB2> INFO: Test took 4635ms.
[12:33:03.845] <TB2> INFO: scanning low vcal = 130
[12:33:08.530] <TB2> INFO: Test took 4684ms.
[12:33:08.596] <TB2> INFO: scanning low vcal = 140
[12:33:13.378] <TB2> INFO: Test took 4782ms.
[12:33:13.475] <TB2> INFO: scanning low vcal = 150
[12:33:18.134] <TB2> INFO: Test took 4659ms.
[12:33:18.198] <TB2> INFO: scanning low vcal = 160
[12:33:22.997] <TB2> INFO: Test took 4799ms.
[12:33:23.084] <TB2> INFO: scanning low vcal = 170
[12:33:27.779] <TB2> INFO: Test took 4695ms.
[12:33:27.840] <TB2> INFO: scanning low vcal = 180
[12:33:32.510] <TB2> INFO: Test took 4670ms.
[12:33:32.568] <TB2> INFO: scanning low vcal = 190
[12:33:37.223] <TB2> INFO: Test took 4655ms.
[12:33:37.286] <TB2> INFO: scanning low vcal = 200
[12:33:41.926] <TB2> INFO: Test took 4640ms.
[12:33:42.005] <TB2> INFO: scanning low vcal = 210
[12:33:46.708] <TB2> INFO: Test took 4703ms.
[12:33:46.767] <TB2> INFO: scanning low vcal = 220
[12:33:51.432] <TB2> INFO: Test took 4665ms.
[12:33:51.491] <TB2> INFO: scanning low vcal = 230
[12:33:56.170] <TB2> INFO: Test took 4679ms.
[12:33:56.229] <TB2> INFO: scanning low vcal = 240
[12:34:00.809] <TB2> INFO: Test took 4579ms.
[12:34:00.867] <TB2> INFO: scanning low vcal = 250
[12:34:05.469] <TB2> INFO: Test took 4602ms.
[12:34:05.542] <TB2> INFO: scanning high vcal = 30 (= 210 in low range)
[12:34:10.087] <TB2> INFO: Test took 4545ms.
[12:34:10.147] <TB2> INFO: scanning high vcal = 50 (= 350 in low range)
[12:34:14.859] <TB2> INFO: Test took 4712ms.
[12:34:14.930] <TB2> INFO: scanning high vcal = 70 (= 490 in low range)
[12:34:19.604] <TB2> INFO: Test took 4674ms.
[12:34:19.707] <TB2> INFO: scanning high vcal = 90 (= 630 in low range)
[12:34:23.965] <TB2> INFO: Test took 4258ms.
[12:34:24.020] <TB2> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:34:28.255] <TB2> INFO: Test took 4235ms.
[12:34:28.786] <TB2> INFO: PixTestGainPedestal::measure() done
[12:34:59.594] <TB2> INFO: PixTestGainPedestal::fit() done
[12:34:59.594] <TB2> INFO: non-linearity mean: 0.959 0.959 0.953 0.956 0.957 0.958 0.960 0.952 0.959 0.958 0.956 0.957 0.951 0.954 0.957 0.958
[12:34:59.594] <TB2> INFO: non-linearity RMS: 0.006 0.004 0.006 0.005 0.005 0.006 0.006 0.005 0.005 0.005 0.006 0.005 0.007 0.005 0.005 0.005
[12:34:59.594] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[12:34:59.611] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[12:34:59.628] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[12:34:59.646] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[12:34:59.663] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[12:34:59.680] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[12:34:59.697] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[12:34:59.714] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[12:34:59.732] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[12:34:59.749] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[12:34:59.766] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[12:34:59.783] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[12:34:59.801] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[12:34:59.818] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[12:34:59.835] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[12:34:59.852] <TB2> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2045_FullQualification_2015-08-19_10h30m_1439973003//002_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[12:34:59.869] <TB2> INFO: PixTestGainPedestal::doTest() done, duration: 169 seconds
[12:34:59.883] <TB2> INFO: enter test to run
[12:34:59.883] <TB2> INFO: test: exit no parameter change
[12:35:00.316] <TB2> QUIET: Connection to board 156 closed.
[12:35:00.396] <TB2> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master