Test Date: 2015-08-06 10:09
Analysis date: 2016-05-26 00:50
Logfile
LogfileView
[14:02:14.882] <TB1> INFO: *** Welcome to pxar ***
[14:02:14.882] <TB1> INFO: *** Today: 2015/08/06
[14:02:14.882] <TB1> INFO: readRocDacs: /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C15.dat
[14:02:14.882] <TB1> INFO: readTbmDacs: /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//tbmParameters_C0b.dat
[14:02:14.882] <TB1> INFO: readMaskFile: /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//defaultMaskFile.dat
[14:02:14.883] <TB1> INFO: readTrimFile: /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters_C15.dat
[14:02:14.944] <TB1> INFO: clk: 4
[14:02:14.944] <TB1> INFO: ctr: 4
[14:02:14.944] <TB1> INFO: sda: 19
[14:02:14.944] <TB1> INFO: tin: 9
[14:02:14.944] <TB1> INFO: level: 15
[14:02:14.944] <TB1> INFO: triggerdelay: 0
[14:02:14.944] <TB1> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[14:02:14.945] <TB1> INFO: Log level: INFO
[14:02:14.961] <TB1> INFO: Found DTB DTB_WXBYFL
[14:02:14.972] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[14:02:14.976] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[14:02:14.980] <TB1> INFO: RPC call hashes of host and DTB match: 447413373
[14:02:16.506] <TB1> INFO: DUT info:
[14:02:16.506] <TB1> INFO: The DUT currently contains the following objects:
[14:02:16.506] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:02:16.506] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:02:16.506] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:02:16.506] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:02:16.506] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.506] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.506] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.507] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:02:16.908] <TB1> INFO: enter 'restricted' command line mode
[14:02:16.908] <TB1> INFO: enter test to run
[14:02:16.908] <TB1> INFO: test: pretest no parameter change
[14:02:16.908] <TB1> INFO: running: pretest
[14:02:16.918] <TB1> INFO: ######################################################################
[14:02:16.918] <TB1> INFO: PixTestPretest::doTest()
[14:02:16.918] <TB1> INFO: ######################################################################
[14:02:16.920] <TB1> INFO: ----------------------------------------------------------------------
[14:02:16.920] <TB1> INFO: PixTestPretest::programROC()
[14:02:16.920] <TB1> INFO: ----------------------------------------------------------------------
[14:02:34.941] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[14:02:34.941] <TB1> INFO: IA differences per ROC: 20.1 19.3 20.1 19.3 21.7 17.7 20.9 19.3 17.7 16.9 17.7 20.1 16.9 20.1 18.5 17.7
[14:02:35.030] <TB1> INFO: ----------------------------------------------------------------------
[14:02:35.030] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[14:02:35.030] <TB1> INFO: ----------------------------------------------------------------------
[14:02:54.632] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 384.3 mA = 24.0187 mA/ROC
[14:02:54.635] <TB1> INFO: ----------------------------------------------------------------------
[14:02:54.636] <TB1> INFO: PixTestPretest::findWorkingPixel()
[14:02:54.636] <TB1> INFO: ----------------------------------------------------------------------
[14:03:04.615] <TB1> INFO: Test took 9973ms.
[14:03:04.922] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[14:03:04.975] <TB1> INFO: ----------------------------------------------------------------------
[14:03:04.975] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[14:03:04.975] <TB1> INFO: ----------------------------------------------------------------------
[14:03:15.439] <TB1> INFO: Test took 10455ms.
[14:03:15.774] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[14:03:15.774] <TB1> INFO: CalDel: 111 139 161 149 140 140 139 144 129 135 148 146 136 143 153 139
[14:03:15.774] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[14:03:15.780] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C0.dat
[14:03:15.781] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C1.dat
[14:03:15.781] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C2.dat
[14:03:15.781] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C3.dat
[14:03:15.782] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C4.dat
[14:03:15.782] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C5.dat
[14:03:15.782] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C6.dat
[14:03:15.783] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C7.dat
[14:03:15.783] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C8.dat
[14:03:15.783] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C9.dat
[14:03:15.783] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C10.dat
[14:03:15.784] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C11.dat
[14:03:15.784] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C12.dat
[14:03:15.784] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C13.dat
[14:03:15.784] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C14.dat
[14:03:15.785] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters_C15.dat
[14:03:15.785] <TB1> INFO: PixTestPretest::doTest() done, duration: 58 seconds
[14:03:15.896] <TB1> INFO: enter test to run
[14:03:15.896] <TB1> INFO: test: fulltest no parameter change
[14:03:15.896] <TB1> INFO: running: fulltest
[14:03:15.896] <TB1> INFO: ######################################################################
[14:03:15.896] <TB1> INFO: PixTestFullTest::doTest()
[14:03:15.896] <TB1> INFO: ######################################################################
[14:03:15.897] <TB1> INFO: ######################################################################
[14:03:15.897] <TB1> INFO: PixTestAlive::doTest()
[14:03:15.897] <TB1> INFO: ######################################################################
[14:03:15.899] <TB1> INFO: ----------------------------------------------------------------------
[14:03:15.899] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:03:15.899] <TB1> INFO: ----------------------------------------------------------------------
[14:03:19.776] <TB1> INFO: Test took 3874ms.
[14:03:19.798] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:20.037] <TB1> INFO: PixTestAlive::aliveTest() done
[14:03:20.037] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0
[14:03:20.040] <TB1> INFO: ----------------------------------------------------------------------
[14:03:20.040] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:03:20.040] <TB1> INFO: ----------------------------------------------------------------------
[14:03:23.043] <TB1> INFO: Test took 3001ms.
[14:03:23.047] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:23.047] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[14:03:23.289] <TB1> INFO: PixTestAlive::maskTest() done
[14:03:23.289] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:03:23.291] <TB1> INFO: ----------------------------------------------------------------------
[14:03:23.291] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:03:23.291] <TB1> INFO: ----------------------------------------------------------------------
[14:03:27.318] <TB1> INFO: Test took 4025ms.
[14:03:27.344] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:27.585] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[14:03:27.585] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:03:27.586] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[14:03:27.592] <TB1> INFO: ######################################################################
[14:03:27.592] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[14:03:27.592] <TB1> INFO: ######################################################################
[14:03:27.596] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[14:03:27.608] <TB1> INFO: dacScan step from 0 .. 29
[14:03:54.740] <TB1> INFO: Test took 27132ms.
[14:03:54.779] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:54.779] <TB1> INFO: dacScan step from 30 .. 59
[14:04:22.257] <TB1> INFO: Test took 27478ms.
[14:04:22.335] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:22.345] <TB1> INFO: dacScan step from 60 .. 89
[14:05:00.339] <TB1> INFO: Test took 37994ms.
[14:05:00.609] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:00.680] <TB1> INFO: dacScan step from 90 .. 119
[14:05:39.146] <TB1> INFO: Test took 38466ms.
[14:05:39.418] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:39.497] <TB1> INFO: dacScan step from 120 .. 149
[14:06:36.696] <TB1> INFO: Test took 57199ms.
[14:06:36.881] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:02.056] <TB1> INFO: PixTestBBMap::doTest() done, duration: 214 seconds
[14:07:02.056] <TB1> INFO: number of dead bumps (per ROC): 15 2 0 0 0 0 0 0 0 0 0 3 0 4 0 65
[14:07:02.056] <TB1> INFO: separation cut (per ROC): 83 105 89 88 97 90 110 94 87 87 78 89 78 98 100 78
[14:07:02.125] <TB1> INFO: ######################################################################
[14:07:02.125] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50
[14:07:02.125] <TB1> INFO: ######################################################################
[14:07:02.125] <TB1> INFO: ----------------------------------------------------------------------
[14:07:02.125] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[14:07:02.125] <TB1> INFO: ----------------------------------------------------------------------
[14:07:02.125] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[14:07:02.133] <TB1> INFO: dacScan step from 0 .. 3
[14:07:36.109] <TB1> INFO: Test took 33976ms.
[14:07:36.140] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:36.140] <TB1> INFO: dacScan step from 4 .. 7
[14:08:02.173] <TB1> INFO: Test took 26033ms.
[14:08:02.205] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:02.205] <TB1> INFO: dacScan step from 8 .. 11
[14:08:29.481] <TB1> INFO: Test took 27276ms.
[14:08:29.511] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:29.511] <TB1> INFO: dacScan step from 12 .. 15
[14:08:55.463] <TB1> INFO: Test took 25952ms.
[14:08:55.498] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:55.498] <TB1> INFO: dacScan step from 16 .. 19
[14:09:21.514] <TB1> INFO: Test took 26016ms.
[14:09:21.547] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:21.547] <TB1> INFO: dacScan step from 20 .. 23
[14:09:48.561] <TB1> INFO: Test took 27014ms.
[14:09:48.592] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:48.592] <TB1> INFO: dacScan step from 24 .. 27
[14:10:15.580] <TB1> INFO: Test took 26988ms.
[14:10:15.612] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:15.612] <TB1> INFO: dacScan step from 28 .. 31
[14:10:41.466] <TB1> INFO: Test took 25854ms.
[14:10:41.498] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:41.498] <TB1> INFO: dacScan step from 32 .. 35
[14:11:07.271] <TB1> INFO: Test took 25772ms.
[14:11:07.301] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:07.301] <TB1> INFO: dacScan step from 36 .. 39
[14:11:33.915] <TB1> INFO: Test took 26613ms.
[14:11:33.951] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:33.951] <TB1> INFO: dacScan step from 40 .. 43
[14:11:59.543] <TB1> INFO: Test took 25592ms.
[14:11:59.576] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:59.576] <TB1> INFO: dacScan step from 44 .. 47
[14:12:24.764] <TB1> INFO: Test took 25188ms.
[14:12:24.795] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:24.795] <TB1> INFO: dacScan step from 48 .. 51
[14:12:51.377] <TB1> INFO: Test took 26582ms.
[14:12:51.410] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:51.410] <TB1> INFO: dacScan step from 52 .. 55
[14:13:18.886] <TB1> INFO: Test took 27476ms.
[14:13:18.916] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:18.916] <TB1> INFO: dacScan step from 56 .. 59
[14:13:45.188] <TB1> INFO: Test took 26272ms.
[14:13:45.218] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:45.218] <TB1> INFO: dacScan step from 60 .. 63
[14:14:11.008] <TB1> INFO: Test took 25790ms.
[14:14:11.041] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:11.041] <TB1> INFO: dacScan step from 64 .. 67
[14:14:37.219] <TB1> INFO: Test took 26178ms.
[14:14:37.250] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:37.250] <TB1> INFO: dacScan step from 68 .. 71
[14:15:04.006] <TB1> INFO: Test took 26755ms.
[14:15:04.038] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:04.038] <TB1> INFO: dacScan step from 72 .. 75
[14:15:32.945] <TB1> INFO: Test took 28907ms.
[14:15:32.978] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:32.978] <TB1> INFO: dacScan step from 76 .. 79
[14:16:02.620] <TB1> INFO: Test took 29642ms.
[14:16:02.667] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:02.668] <TB1> INFO: dacScan step from 80 .. 83
[14:16:34.573] <TB1> INFO: Test took 31905ms.
[14:16:34.651] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:34.653] <TB1> INFO: dacScan step from 84 .. 87
[14:17:09.624] <TB1> INFO: Test took 34971ms.
[14:17:09.749] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:09.754] <TB1> INFO: dacScan step from 88 .. 91
[14:17:45.625] <TB1> INFO: Test took 35871ms.
[14:17:45.767] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:45.773] <TB1> INFO: dacScan step from 92 .. 95
[14:18:24.983] <TB1> INFO: Test took 39209ms.
[14:18:25.161] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:25.171] <TB1> INFO: dacScan step from 96 .. 99
[14:19:07.144] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (211) != TBM ID (0)

[14:19:07.144] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (1) != Token Chain Length (4)

[14:19:07.144] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (212)

[14:19:07.144] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[14:19:07.567] <TB1> INFO: Test took 42396ms.
[14:19:07.762] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:07.772] <TB1> INFO: dacScan step from 100 .. 103
[14:19:52.272] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:19:53.664] <TB1> INFO: Test took 45891ms.
[14:19:53.938] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:53.948] <TB1> INFO: dacScan step from 104 .. 107
[14:20:37.572] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:20:39.578] <TB1> INFO: Test took 45630ms.
[14:20:39.806] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:39.816] <TB1> INFO: dacScan step from 108 .. 111
[14:21:23.414] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (66) != TBM ID (0)

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

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

[14:21:26.180] <TB1> INFO: Test took 46364ms.
[14:21:26.431] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:26.442] <TB1> INFO: dacScan step from 112 .. 115
[14:22:21.855] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (47) != TBM ID (0)

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

[14:22:21.855] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (48)

[14:22:24.317] <TB1> INFO: Test took 57875ms.
[14:22:24.579] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:24.593] <TB1> INFO: dacScan step from 116 .. 119
[14:23:45.732] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[14:23:51.009] <TB1> INFO: Test took 86416ms.
[14:23:51.228] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:51.241] <TB1> INFO: dacScan step from 120 .. 123
[14:24:44.425] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:24:46.382] <TB1> INFO: Test took 55141ms.
[14:24:46.660] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:46.673] <TB1> INFO: dacScan step from 124 .. 127
[14:25:30.023] <TB1> INFO: Test took 43350ms.
[14:25:30.267] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:30.279] <TB1> INFO: dacScan step from 128 .. 131
[14:26:14.758] <TB1> INFO: Test took 44479ms.
[14:26:14.979] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:14.993] <TB1> INFO: dacScan step from 132 .. 135
[14:27:01.833] <TB1> INFO: Test took 46840ms.
[14:27:02.078] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:02.090] <TB1> INFO: dacScan step from 136 .. 139
[14:28:00.957] <TB1> INFO: Test took 58867ms.
[14:28:01.178] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:01.189] <TB1> INFO: dacScan step from 140 .. 143
[14:28:45.190] <TB1> INFO: Test took 44001ms.
[14:28:45.437] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:45.449] <TB1> INFO: dacScan step from 144 .. 147
[14:29:40.750] <TB1> INFO: Test took 55301ms.
[14:29:41.038] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:41.058] <TB1> INFO: dacScan step from 148 .. 149
[14:30:04.140] <TB1> INFO: Test took 23082ms.
[14:30:04.261] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:04.267] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:05.606] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:07.033] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:08.516] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:09.987] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:11.456] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:13.128] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:14.554] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:15.986] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:17.455] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:18.965] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:20.524] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:22.006] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:23.465] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:24.946] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:26.298] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:30:27.683] <TB1> INFO: PixTestScurves::scurves() done
[14:30:27.683] <TB1> INFO: Vcal mean: 101.52 102.24 91.71 93.60 95.58 88.22 103.77 101.56 95.37 81.65 81.42 89.41 88.76 95.40 93.63 98.49
[14:30:27.683] <TB1> INFO: Vcal RMS: 4.97 5.58 5.10 6.28 5.89 5.76 6.40 6.30 5.73 4.08 4.23 5.54 5.53 5.88 6.37 4.83
[14:30:27.684] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1405 seconds
[14:30:27.774] <TB1> INFO: ######################################################################
[14:30:27.774] <TB1> INFO: PixTestTrim::doTest()
[14:30:27.774] <TB1> INFO: ######################################################################
[14:30:27.776] <TB1> INFO: ----------------------------------------------------------------------
[14:30:27.776] <TB1> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[14:30:27.776] <TB1> INFO: ----------------------------------------------------------------------
[14:30:27.866] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[14:30:27.866] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[14:30:27.874] <TB1> INFO: dacScan step from 0 .. 19
[14:30:57.381] <TB1> INFO: Test took 29507ms.
[14:30:57.403] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:57.403] <TB1> INFO: dacScan step from 20 .. 39
[14:31:17.357] <TB1> INFO: Test took 19954ms.
[14:31:17.384] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:17.384] <TB1> INFO: dacScan step from 40 .. 59
[14:31:36.152] <TB1> INFO: Test took 18768ms.
[14:31:36.181] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:36.182] <TB1> INFO: dacScan step from 60 .. 79
[14:31:55.416] <TB1> INFO: Test took 19234ms.
[14:31:55.443] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:55.444] <TB1> INFO: dacScan step from 80 .. 99
[14:32:17.635] <TB1> INFO: Test took 22191ms.
[14:32:17.688] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:17.695] <TB1> INFO: dacScan step from 100 .. 119
[14:32:46.776] <TB1> INFO: Test took 29081ms.
[14:32:46.933] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:46.970] <TB1> INFO: dacScan step from 120 .. 139
[14:33:13.404] <TB1> INFO: Test took 26434ms.
[14:33:13.569] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:13.597] <TB1> INFO: dacScan step from 140 .. 159
[14:33:33.094] <TB1> INFO: Test took 19497ms.
[14:33:33.167] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:54.100] <TB1> INFO: ROC 0 VthrComp = 103
[14:33:54.100] <TB1> INFO: ROC 1 VthrComp = 101
[14:33:54.100] <TB1> INFO: ROC 2 VthrComp = 91
[14:33:54.100] <TB1> INFO: ROC 3 VthrComp = 92
[14:33:54.100] <TB1> INFO: ROC 4 VthrComp = 96
[14:33:54.100] <TB1> INFO: ROC 5 VthrComp = 87
[14:33:54.100] <TB1> INFO: ROC 6 VthrComp = 103
[14:33:54.100] <TB1> INFO: ROC 7 VthrComp = 98
[14:33:54.101] <TB1> INFO: ROC 8 VthrComp = 95
[14:33:54.101] <TB1> INFO: ROC 9 VthrComp = 86
[14:33:54.101] <TB1> INFO: ROC 10 VthrComp = 83
[14:33:54.101] <TB1> INFO: ROC 11 VthrComp = 89
[14:33:54.101] <TB1> INFO: ROC 12 VthrComp = 88
[14:33:54.101] <TB1> INFO: ROC 13 VthrComp = 96
[14:33:54.101] <TB1> INFO: ROC 14 VthrComp = 91
[14:33:54.101] <TB1> INFO: ROC 15 VthrComp = 102
[14:33:54.102] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[14:33:54.102] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[14:33:54.110] <TB1> INFO: dacScan step from 0 .. 19
[14:34:18.408] <TB1> INFO: Test took 24298ms.
[14:34:18.434] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:18.434] <TB1> INFO: dacScan step from 20 .. 39
[14:34:37.697] <TB1> INFO: Test took 19263ms.
[14:34:37.731] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:37.734] <TB1> INFO: dacScan step from 40 .. 59
[14:35:05.075] <TB1> INFO: Test took 27341ms.
[14:35:05.245] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:05.280] <TB1> INFO: dacScan step from 60 .. 79
[14:35:43.932] <TB1> INFO: Test took 38652ms.
[14:35:44.137] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:44.190] <TB1> INFO: dacScan step from 80 .. 99
[14:36:22.867] <TB1> INFO: Test took 38677ms.
[14:36:23.040] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:23.095] <TB1> INFO: dacScan step from 100 .. 119
[14:36:50.029] <TB1> INFO: Test took 26934ms.
[14:36:50.195] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:36:50.245] <TB1> INFO: dacScan step from 120 .. 139
[14:37:17.100] <TB1> INFO: Test took 26855ms.
[14:37:17.275] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:17.324] <TB1> INFO: dacScan step from 140 .. 159
[14:37:47.298] <TB1> INFO: Test took 29974ms.
[14:37:47.464] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:13.114] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 57.5488 for pixel 23/64 mean/min/max = 45.5937/33.5922/57.5952
[14:38:13.114] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 58.5948 for pixel 6/1 mean/min/max = 45.4332/32.1157/58.7507
[14:38:13.114] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 58.3055 for pixel 8/77 mean/min/max = 45.663/32.9164/58.4096
[14:38:13.115] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 60.0951 for pixel 37/73 mean/min/max = 46.5412/32.96/60.1224
[14:38:13.115] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 59.9869 for pixel 0/56 mean/min/max = 45.956/31.8168/60.0952
[14:38:13.115] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 58.9638 for pixel 2/45 mean/min/max = 45.5379/31.8079/59.2678
[14:38:13.116] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 62.7017 for pixel 10/42 mean/min/max = 47.6811/32.4393/62.9229
[14:38:13.116] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 61.5065 for pixel 2/27 mean/min/max = 46.7882/32.0562/61.5202
[14:38:13.116] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 59.5738 for pixel 21/9 mean/min/max = 45.9999/32.3347/59.6651
[14:38:13.117] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 54.9653 for pixel 17/3 mean/min/max = 43.6348/31.898/55.3716
[14:38:13.117] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 57.1261 for pixel 14/72 mean/min/max = 44.9816/32.7687/57.1944
[14:38:13.117] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 58.8472 for pixel 2/78 mean/min/max = 46.2503/33.6426/58.8581
[14:38:13.118] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 60.8529 for pixel 7/71 mean/min/max = 47.1153/33.3183/60.9122
[14:38:13.118] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 59.9699 for pixel 19/59 mean/min/max = 46.3507/32.6176/60.0838
[14:38:13.118] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 61.3821 for pixel 15/2 mean/min/max = 47.0079/32.6093/61.4065
[14:38:13.118] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 56.8913 for pixel 36/2 mean/min/max = 44.6314/32.1726/57.0901
[14:38:13.118] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:40:39.728] <TB1> INFO: Test took 146610ms.
[14:40:41.035] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[14:40:41.043] <TB1> INFO: dacScan step from 0 .. 19
[14:41:10.506] <TB1> INFO: Test took 29462ms.
[14:41:10.560] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:10.562] <TB1> INFO: dacScan step from 20 .. 39
[14:41:55.006] <TB1> INFO: Test took 44444ms.
[14:41:55.259] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:41:55.294] <TB1> INFO: dacScan step from 40 .. 59
[14:42:45.195] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[14:42:51.138] <TB1> INFO: Test took 55844ms.
[14:42:51.431] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:42:51.490] <TB1> INFO: dacScan step from 60 .. 79
[14:43:35.567] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:43:37.523] <TB1> INFO: Test took 46033ms.
[14:43:37.861] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:43:37.916] <TB1> INFO: dacScan step from 80 .. 99
[14:44:34.983] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:44:36.867] <TB1> INFO: Test took 58951ms.
[14:44:37.157] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:44:37.204] <TB1> INFO: dacScan step from 100 .. 119
[14:45:23.812] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:45:26.527] <TB1> INFO: Test took 49323ms.
[14:45:26.826] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:45:26.880] <TB1> INFO: dacScan step from 120 .. 139
[14:46:16.763] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[14:46:18.655] <TB1> INFO: Test took 51775ms.
[14:46:19.008] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:46:19.061] <TB1> INFO: dacScan step from 140 .. 159
[14:47:17.272] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:47:19.925] <TB1> INFO: Test took 60864ms.
[14:47:20.239] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:47:20.294] <TB1> INFO: dacScan step from 160 .. 179
[14:48:05.546] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (82) != TBM ID (0)

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

[14:48:05.546] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (83)

[14:48:08.228] <TB1> INFO: Test took 47934ms.
[14:48:08.535] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:08.590] <TB1> INFO: dacScan step from 180 .. 199
[14:49:11.234] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[14:49:13.777] <TB1> INFO: Test took 65187ms.
[14:49:14.123] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:41.339] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.023775 .. 255.000000
[14:49:41.424] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[14:49:41.433] <TB1> INFO: dacScan step from 0 .. 19
[14:49:58.215] <TB1> INFO: Test took 16782ms.
[14:49:58.240] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:58.240] <TB1> INFO: dacScan step from 20 .. 39
[14:50:18.568] <TB1> INFO: Test took 20328ms.
[14:50:18.667] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:18.685] <TB1> INFO: dacScan step from 40 .. 59
[14:50:55.957] <TB1> INFO: Test took 37272ms.
[14:50:56.104] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:56.159] <TB1> INFO: dacScan step from 60 .. 79
[14:51:18.075] <TB1> INFO: Test took 21916ms.
[14:51:18.216] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:18.266] <TB1> INFO: dacScan step from 80 .. 99
[14:51:39.482] <TB1> INFO: Test took 21216ms.
[14:51:39.645] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:39.699] <TB1> INFO: dacScan step from 100 .. 119
[14:52:01.261] <TB1> INFO: Test took 21562ms.
[14:52:01.427] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:01.477] <TB1> INFO: dacScan step from 120 .. 139
[14:52:36.190] <TB1> INFO: Test took 34713ms.
[14:52:36.411] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:52:36.505] <TB1> INFO: dacScan step from 140 .. 159
[14:53:12.407] <TB1> INFO: Test took 35902ms.
[14:53:12.562] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:12.614] <TB1> INFO: dacScan step from 160 .. 179
[14:53:51.853] <TB1> INFO: Test took 39239ms.
[14:53:52.087] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:53:52.197] <TB1> INFO: dacScan step from 180 .. 199
[14:54:27.723] <TB1> INFO: Test took 35526ms.
[14:54:27.872] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:27.923] <TB1> INFO: dacScan step from 200 .. 219
[14:54:50.733] <TB1> INFO: Test took 22810ms.
[14:54:50.885] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:54:50.942] <TB1> INFO: dacScan step from 220 .. 239
[14:55:16.944] <TB1> INFO: Test took 26002ms.
[14:55:17.103] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:55:17.156] <TB1> INFO: dacScan step from 240 .. 255
[14:55:47.862] <TB1> INFO: Test took 30706ms.
[14:55:47.985] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:19.325] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 14.541842 .. 44.608794
[14:56:19.410] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 4 .. 54 (20) hits flags = 16 (plus default)
[14:56:19.418] <TB1> INFO: dacScan step from 4 .. 23
[14:56:37.022] <TB1> INFO: Test took 17604ms.
[14:56:37.051] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:37.051] <TB1> INFO: dacScan step from 24 .. 43
[14:56:58.805] <TB1> INFO: Test took 21754ms.
[14:56:58.927] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:56:58.954] <TB1> INFO: dacScan step from 44 .. 54
[14:57:12.797] <TB1> INFO: Test took 13842ms.
[14:57:12.879] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:29.336] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 1.330037 .. 41.852365
[14:57:29.411] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 51 (20) hits flags = 16 (plus default)
[14:57:29.419] <TB1> INFO: dacScan step from 1 .. 20
[14:57:50.670] <TB1> INFO: Test took 21250ms.
[14:57:50.694] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:57:50.694] <TB1> INFO: dacScan step from 21 .. 40
[14:58:11.028] <TB1> INFO: Test took 20334ms.
[14:58:11.108] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:11.128] <TB1> INFO: dacScan step from 41 .. 51
[14:58:27.485] <TB1> INFO: Test took 16357ms.
[14:58:27.571] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:43.664] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 0.355415 .. 41.049205
[14:58:43.745] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 51 (20) hits flags = 16 (plus default)
[14:58:43.754] <TB1> INFO: dacScan step from 0 .. 19
[14:58:58.541] <TB1> INFO: Test took 14787ms.
[14:58:58.568] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:58.568] <TB1> INFO: dacScan step from 20 .. 39
[14:59:18.144] <TB1> INFO: Test took 19576ms.
[14:59:18.222] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:18.240] <TB1> INFO: dacScan step from 40 .. 51
[14:59:31.807] <TB1> INFO: Test took 13566ms.
[14:59:31.898] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:47.864] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[14:59:47.865] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[14:59:47.872] <TB1> INFO: dacScan step from 15 .. 34
[15:00:24.648] <TB1> INFO: Test took 36775ms.
[15:00:24.718] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:24.726] <TB1> INFO: dacScan step from 35 .. 54
[15:01:09.553] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[15:01:11.281] <TB1> INFO: Test took 46554ms.
[15:01:11.598] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:11.648] <TB1> INFO: dacScan step from 55 .. 55
[15:01:17.102] <TB1> INFO: Test took 5453ms.
[15:01:17.126] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:31.442] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C0.dat
[15:01:31.442] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C1.dat
[15:01:31.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C2.dat
[15:01:31.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C3.dat
[15:01:31.443] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C4.dat
[15:01:31.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C5.dat
[15:01:31.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C6.dat
[15:01:31.444] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C7.dat
[15:01:31.445] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C8.dat
[15:01:31.445] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C9.dat
[15:01:31.445] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C10.dat
[15:01:31.445] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C11.dat
[15:01:31.445] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C12.dat
[15:01:31.446] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C13.dat
[15:01:31.446] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C14.dat
[15:01:31.446] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C15.dat
[15:01:31.446] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C0.dat
[15:01:31.455] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C1.dat
[15:01:31.461] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C2.dat
[15:01:31.468] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C3.dat
[15:01:31.474] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C4.dat
[15:01:31.480] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C5.dat
[15:01:31.486] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C6.dat
[15:01:31.492] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C7.dat
[15:01:31.499] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C8.dat
[15:01:31.505] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C9.dat
[15:01:31.511] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C10.dat
[15:01:31.520] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C11.dat
[15:01:31.528] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C12.dat
[15:01:31.535] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C13.dat
[15:01:31.544] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C14.dat
[15:01:31.552] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//trimParameters35_C15.dat
[15:01:31.558] <TB1> INFO: PixTestTrim::trimTest() done
[15:01:31.558] <TB1> INFO: vtrim: 108 106 88 111 98 87 134 115 109 104 97 106 110 120 115 182
[15:01:31.558] <TB1> INFO: vthrcomp: 103 101 91 92 96 87 103 98 95 86 83 89 88 96 91 102
[15:01:31.558] <TB1> INFO: vcal mean: 35.05 35.15 35.15 35.12 35.15 35.11 35.07 35.07 35.10 35.08 35.07 35.10 35.13 35.11 35.09 35.07
[15:01:31.558] <TB1> INFO: vcal RMS: 1.03 1.17 1.05 1.22 0.99 1.09 1.14 1.25 1.11 1.00 1.11 1.02 1.05 1.05 1.11 2.10
[15:01:31.559] <TB1> INFO: bits mean: 9.63 10.00 9.40 10.02 9.49 9.83 9.59 9.67 10.11 10.70 10.11 9.42 9.28 9.68 9.89 11.96
[15:01:31.559] <TB1> INFO: bits RMS: 2.51 2.47 2.62 2.31 2.70 2.62 2.48 2.59 2.37 2.27 2.39 2.50 2.48 2.56 2.37 1.58
[15:01:31.569] <TB1> INFO: ----------------------------------------------------------------------
[15:01:31.569] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[15:01:31.569] <TB1> INFO: ----------------------------------------------------------------------
[15:01:31.573] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[15:01:31.587] <TB1> INFO: dacScan step from 0 .. 19
[15:01:59.550] <TB1> INFO: Test took 27963ms.
[15:01:59.588] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:59.588] <TB1> INFO: dacScan step from 20 .. 39
[15:02:29.248] <TB1> INFO: Test took 29660ms.
[15:02:29.287] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:29.287] <TB1> INFO: dacScan step from 40 .. 59
[15:02:58.159] <TB1> INFO: Test took 28872ms.
[15:02:58.197] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:02:58.197] <TB1> INFO: dacScan step from 60 .. 79
[15:03:27.090] <TB1> INFO: Test took 28893ms.
[15:03:27.136] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:27.136] <TB1> INFO: dacScan step from 80 .. 99
[15:03:57.267] <TB1> INFO: Test took 30131ms.
[15:03:57.309] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:57.309] <TB1> INFO: dacScan step from 100 .. 119
[15:04:51.936] <TB1> INFO: Test took 54627ms.
[15:04:52.066] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:04:52.078] <TB1> INFO: dacScan step from 120 .. 139
[15:05:34.607] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[15:05:34.607] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (98) != TBM ID (99)

[15:05:34.607] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[15:05:34.607] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[15:05:34.607] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:05:35.359] <TB1> INFO: Test took 43281ms.
[15:05:35.662] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:05:35.700] <TB1> INFO: dacScan step from 140 .. 159
[15:06:21.321] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (238) != TBM ID (0)

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

[15:06:21.321] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (239)

[15:06:23.250] <TB1> INFO: Test took 47550ms.
[15:06:23.534] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:06:23.583] <TB1> INFO: dacScan step from 160 .. 179
[15:07:22.815] <TB1> INFO: Test took 59232ms.
[15:07:23.105] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:23.153] <TB1> INFO: dacScan step from 180 .. 199
[15:08:11.656] <TB1> INFO: Test took 48503ms.
[15:08:11.990] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:39.572] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 179 (20) hits flags = 16 (plus default)
[15:08:39.580] <TB1> INFO: dacScan step from 0 .. 19
[15:09:14.871] <TB1> INFO: Test took 35287ms.
[15:09:14.912] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:14.912] <TB1> INFO: dacScan step from 20 .. 39
[15:09:43.903] <TB1> INFO: Test took 28991ms.
[15:09:43.939] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:43.939] <TB1> INFO: dacScan step from 40 .. 59
[15:10:15.116] <TB1> INFO: Test took 31177ms.
[15:10:15.157] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:15.157] <TB1> INFO: dacScan step from 60 .. 79
[15:10:46.076] <TB1> INFO: Test took 30919ms.
[15:10:46.110] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:46.110] <TB1> INFO: dacScan step from 80 .. 99
[15:11:19.047] <TB1> INFO: Test took 32937ms.
[15:11:19.107] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:11:19.110] <TB1> INFO: dacScan step from 100 .. 119
[15:12:05.137] <TB1> INFO: Test took 46027ms.
[15:12:05.344] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:05.366] <TB1> INFO: dacScan step from 120 .. 139
[15:12:51.655] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 32 readouts!

[15:12:53.472] <TB1> INFO: Test took 48106ms.
[15:12:53.806] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:12:53.854] <TB1> INFO: dacScan step from 140 .. 159
[15:13:53.464] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[15:13:55.333] <TB1> INFO: Test took 61479ms.
[15:13:55.658] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:13:55.708] <TB1> INFO: dacScan step from 160 .. 179
[15:14:43.222] <TB1> INFO: Test took 47514ms.
[15:14:43.496] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:06.570] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 161 (20) hits flags = 16 (plus default)
[15:15:06.578] <TB1> INFO: dacScan step from 0 .. 19
[15:15:36.370] <TB1> INFO: Test took 29792ms.
[15:15:36.409] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:15:36.409] <TB1> INFO: dacScan step from 20 .. 39
[15:16:06.696] <TB1> INFO: Test took 30287ms.
[15:16:06.741] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:06.741] <TB1> INFO: dacScan step from 40 .. 59
[15:16:36.917] <TB1> INFO: Test took 30176ms.
[15:16:36.957] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:16:36.957] <TB1> INFO: dacScan step from 60 .. 79
[15:17:07.290] <TB1> INFO: Test took 30333ms.
[15:17:07.328] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:07.328] <TB1> INFO: dacScan step from 80 .. 99
[15:17:46.451] <TB1> INFO: Test took 39123ms.
[15:17:46.527] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:17:46.531] <TB1> INFO: dacScan step from 100 .. 119
[15:18:22.588] <TB1> INFO: Test took 36057ms.
[15:18:22.814] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:18:22.836] <TB1> INFO: dacScan step from 120 .. 139
[15:19:05.800] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:19:05.800] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:19:07.590] <TB1> INFO: Test took 44754ms.
[15:19:07.873] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:19:07.920] <TB1> INFO: dacScan step from 140 .. 159
[15:20:00.256] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (68) != TBM ID (0)

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

[15:20:00.256] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (69)

[15:20:01.999] <TB1> INFO: Test took 54078ms.
[15:20:02.325] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:20:02.374] <TB1> INFO: dacScan step from 160 .. 161
[15:20:09.583] <TB1> INFO: Test took 7209ms.
[15:20:09.619] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:20:33.927] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 163 (20) hits flags = 16 (plus default)
[15:20:33.935] <TB1> INFO: dacScan step from 0 .. 19
[15:21:18.792] <TB1> INFO: Test took 44857ms.
[15:21:18.833] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:21:18.833] <TB1> INFO: dacScan step from 20 .. 39
[15:21:45.492] <TB1> INFO: Test took 26659ms.
[15:21:45.537] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:21:45.537] <TB1> INFO: dacScan step from 40 .. 59
[15:22:12.112] <TB1> INFO: Test took 26575ms.
[15:22:12.154] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:22:12.154] <TB1> INFO: dacScan step from 60 .. 79
[15:23:02.132] <TB1> INFO: Test took 49978ms.
[15:23:02.167] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:23:02.167] <TB1> INFO: dacScan step from 80 .. 99
[15:23:50.756] <TB1> INFO: Test took 48589ms.
[15:23:50.814] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:23:50.819] <TB1> INFO: dacScan step from 100 .. 119
[15:24:25.594] <TB1> INFO: Test took 34775ms.
[15:24:25.824] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:25.847] <TB1> INFO: dacScan step from 120 .. 139
[15:25:19.035] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[15:25:20.747] <TB1> INFO: Test took 54900ms.
[15:25:21.112] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:25:21.155] <TB1> INFO: dacScan step from 140 .. 159
[15:26:00.440] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:26:00.440] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:26:02.263] <TB1> INFO: Test took 41108ms.
[15:26:02.526] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:02.574] <TB1> INFO: dacScan step from 160 .. 163
[15:26:12.908] <TB1> INFO: Test took 10334ms.
[15:26:12.978] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:26:35.161] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 160 (20) hits flags = 16 (plus default)
[15:26:35.168] <TB1> INFO: dacScan step from 0 .. 19
[15:27:01.760] <TB1> INFO: Test took 26592ms.
[15:27:01.802] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:01.802] <TB1> INFO: dacScan step from 20 .. 39
[15:27:28.628] <TB1> INFO: Test took 26827ms.
[15:27:28.665] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:28.665] <TB1> INFO: dacScan step from 40 .. 59
[15:28:09.651] <TB1> INFO: Test took 40986ms.
[15:28:09.692] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:09.692] <TB1> INFO: dacScan step from 60 .. 79
[15:28:36.463] <TB1> INFO: Test took 26771ms.
[15:28:36.510] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:36.510] <TB1> INFO: dacScan step from 80 .. 99
[15:29:03.678] <TB1> INFO: Test took 27167ms.
[15:29:03.752] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:03.755] <TB1> INFO: dacScan step from 100 .. 119
[15:29:38.888] <TB1> INFO: Test took 35133ms.
[15:29:39.118] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:39.146] <TB1> INFO: dacScan step from 120 .. 139
[15:30:18.860] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:30:18.860] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[15:30:20.796] <TB1> INFO: Test took 41650ms.
[15:30:21.130] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:21.179] <TB1> INFO: dacScan step from 140 .. 159
[15:31:14.107] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[15:31:16.116] <TB1> INFO: Test took 54936ms.
[15:31:16.441] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:16.492] <TB1> INFO: dacScan step from 160 .. 160
[15:31:21.431] <TB1> INFO: Test took 4939ms.
[15:31:21.453] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:42.617] <TB1> INFO: PixTestTrim::trimBitTest() done
[15:31:42.619] <TB1> INFO: PixTestTrim::doTest() done, duration: 3674 seconds
[15:31:43.279] <TB1> INFO: ######################################################################
[15:31:43.279] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[15:31:43.279] <TB1> INFO: ######################################################################
[15:31:47.197] <TB1> INFO: Test took 3917ms.
[15:31:47.219] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:51.336] <TB1> INFO: Test took 3918ms.
[15:31:51.407] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:55.252] <TB1> INFO: Test took 3830ms.
[15:31:55.320] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:55.328] <TB1> INFO: The DUT currently contains the following objects:
[15:31:55.328] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:31:55.328] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:31:55.328] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:31:55.328] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:31:55.328] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:55.328] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.453] <TB1> INFO: Test took 1125ms.
[15:31:56.454] <TB1> INFO: The DUT currently contains the following objects:
[15:31:56.454] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:31:56.454] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:31:56.454] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:31:56.454] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:31:56.454] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.454] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.454] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.454] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.454] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.454] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.454] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.455] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.455] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.455] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.455] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.455] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.455] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.455] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.455] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:56.455] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.579] <TB1> INFO: Test took 1124ms.
[15:31:57.581] <TB1> INFO: The DUT currently contains the following objects:
[15:31:57.581] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:31:57.581] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:31:57.581] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:31:57.581] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:31:57.581] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.581] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.582] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.582] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.582] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:57.582] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.704] <TB1> INFO: Test took 1122ms.
[15:31:58.705] <TB1> INFO: The DUT currently contains the following objects:
[15:31:58.705] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:31:58.705] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:31:58.705] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:31:58.705] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:31:58.705] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.705] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.705] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.705] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.705] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.705] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.705] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.705] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.705] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.705] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.706] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.706] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.706] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.706] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.706] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:58.706] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.828] <TB1> INFO: Test took 1122ms.
[15:31:59.829] <TB1> INFO: The DUT currently contains the following objects:
[15:31:59.829] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:31:59.829] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:31:59.829] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:31:59.829] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:31:59.829] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.829] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.829] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.829] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:31:59.830] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.969] <TB1> INFO: Test took 1139ms.
[15:32:00.970] <TB1> INFO: The DUT currently contains the following objects:
[15:32:00.970] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:00.970] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:00.970] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:00.970] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:00.970] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.970] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.970] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.970] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.970] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.970] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.970] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.970] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.970] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.971] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.971] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.971] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.971] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.971] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.971] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:00.971] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.093] <TB1> INFO: Test took 1122ms.
[15:32:02.095] <TB1> INFO: The DUT currently contains the following objects:
[15:32:02.095] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:02.095] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:02.095] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:02.095] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:02.095] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.095] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.096] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.096] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.096] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:02.096] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.218] <TB1> INFO: Test took 1122ms.
[15:32:03.220] <TB1> INFO: The DUT currently contains the following objects:
[15:32:03.220] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:03.220] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:03.220] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:03.220] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:03.220] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:03.220] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.343] <TB1> INFO: Test took 1123ms.
[15:32:04.344] <TB1> INFO: The DUT currently contains the following objects:
[15:32:04.344] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:04.344] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:04.344] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:04.344] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:04.344] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.344] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:04.345] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.466] <TB1> INFO: Test took 1121ms.
[15:32:05.468] <TB1> INFO: The DUT currently contains the following objects:
[15:32:05.468] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:05.468] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:05.468] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:05.468] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:05.468] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.468] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.468] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.468] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.468] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.468] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.468] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.469] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.469] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.469] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.469] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.469] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.469] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.469] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.469] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:05.469] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.592] <TB1> INFO: Test took 1123ms.
[15:32:06.593] <TB1> INFO: The DUT currently contains the following objects:
[15:32:06.593] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:06.593] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:06.593] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:06.593] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:06.593] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.593] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.593] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.593] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.593] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.593] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.593] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.593] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.593] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.593] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.594] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.594] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.594] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.594] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.594] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:06.594] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.735] <TB1> INFO: Test took 1141ms.
[15:32:07.736] <TB1> INFO: The DUT currently contains the following objects:
[15:32:07.736] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:07.736] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:07.736] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:07.736] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:07.736] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.736] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.736] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.736] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.736] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.736] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.736] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.737] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.737] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.737] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.737] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.737] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.737] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.737] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.737] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:07.737] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.875] <TB1> INFO: Test took 1138ms.
[15:32:08.876] <TB1> INFO: The DUT currently contains the following objects:
[15:32:08.876] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:08.876] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:08.876] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:08.876] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:08.876] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.876] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.876] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:08.877] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.015] <TB1> INFO: Test took 1139ms.
[15:32:10.017] <TB1> INFO: The DUT currently contains the following objects:
[15:32:10.017] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:10.017] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:10.017] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:10.017] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:10.017] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:10.017] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.141] <TB1> INFO: Test took 1124ms.
[15:32:11.142] <TB1> INFO: The DUT currently contains the following objects:
[15:32:11.142] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:11.142] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:11.142] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:11.142] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:11.142] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:11.142] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.265] <TB1> INFO: Test took 1123ms.
[15:32:12.267] <TB1> INFO: The DUT currently contains the following objects:
[15:32:12.267] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[15:32:12.267] <TB1> INFO: TBM Core alpha (0): 7 registers set
[15:32:12.267] <TB1> INFO: TBM Core beta (1): 7 registers set
[15:32:12.267] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[15:32:12.267] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:12.267] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[15:32:13.391] <TB1> INFO: Test took 1124ms.
[15:32:13.397] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:36:55.498] <TB1> INFO: Test took 282101ms.
[15:36:57.240] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:41:39.207] <TB1> INFO: Test took 281967ms.
[15:41:41.065] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.074] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.081] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.090] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.097] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.106] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.113] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.119] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.126] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.132] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.141] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.147] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.154] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.163] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.170] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.177] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:41:41.184] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[15:41:41.192] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[15:41:41.199] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[15:41:41.205] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[15:41:41.212] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[15:41:41.219] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[15:41:41.225] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:41:41.280] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C0.dat
[15:41:41.280] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C1.dat
[15:41:41.280] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C2.dat
[15:41:41.280] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C3.dat
[15:41:41.281] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C4.dat
[15:41:41.281] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C5.dat
[15:41:41.281] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C6.dat
[15:41:41.281] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C7.dat
[15:41:41.282] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C8.dat
[15:41:41.282] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C9.dat
[15:41:41.282] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C10.dat
[15:41:41.282] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C11.dat
[15:41:41.282] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C12.dat
[15:41:41.282] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C13.dat
[15:41:41.283] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C14.dat
[15:41:41.283] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//dacParameters35_C15.dat
[15:41:45.083] <TB1> INFO: Test took 3796ms.
[15:41:49.439] <TB1> INFO: Test took 4075ms.
[15:41:53.713] <TB1> INFO: Test took 3974ms.
[15:41:54.033] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:41:54.985] <TB1> INFO: Test took 952ms.
[15:41:54.989] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:41:56.133] <TB1> INFO: Test took 1144ms.
[15:41:56.137] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:41:57.323] <TB1> INFO: Test took 1187ms.
[15:41:57.327] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:41:58.468] <TB1> INFO: Test took 1141ms.
[15:41:58.472] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:41:59.613] <TB1> INFO: Test took 1141ms.
[15:41:59.616] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:00.770] <TB1> INFO: Test took 1154ms.
[15:42:00.774] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:01.925] <TB1> INFO: Test took 1152ms.
[15:42:01.929] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:03.067] <TB1> INFO: Test took 1138ms.
[15:42:03.071] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:04.210] <TB1> INFO: Test took 1139ms.
[15:42:04.214] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:05.356] <TB1> INFO: Test took 1142ms.
[15:42:05.360] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:06.498] <TB1> INFO: Test took 1138ms.
[15:42:06.502] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:07.641] <TB1> INFO: Test took 1139ms.
[15:42:07.645] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:08.784] <TB1> INFO: Test took 1139ms.
[15:42:08.788] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:09.926] <TB1> INFO: Test took 1138ms.
[15:42:09.930] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:11.084] <TB1> INFO: Test took 1154ms.
[15:42:11.087] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:12.226] <TB1> INFO: Test took 1139ms.
[15:42:12.230] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:13.386] <TB1> INFO: Test took 1156ms.
[15:42:13.390] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:14.529] <TB1> INFO: Test took 1139ms.
[15:42:14.532] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:15.671] <TB1> INFO: Test took 1139ms.
[15:42:15.675] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:16.813] <TB1> INFO: Test took 1138ms.
[15:42:16.817] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:18.044] <TB1> INFO: Test took 1228ms.
[15:42:18.046] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:19.202] <TB1> INFO: Test took 1156ms.
[15:42:19.206] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:20.360] <TB1> INFO: Test took 1154ms.
[15:42:20.364] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:21.502] <TB1> INFO: Test took 1138ms.
[15:42:21.506] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:22.646] <TB1> INFO: Test took 1140ms.
[15:42:22.651] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:23.789] <TB1> INFO: Test took 1139ms.
[15:42:23.793] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:24.930] <TB1> INFO: Test took 1138ms.
[15:42:24.934] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:26.075] <TB1> INFO: Test took 1141ms.
[15:42:26.079] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:27.233] <TB1> INFO: Test took 1154ms.
[15:42:27.237] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:28.378] <TB1> INFO: Test took 1141ms.
[15:42:28.382] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:29.522] <TB1> INFO: Test took 1140ms.
[15:42:29.526] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:42:30.665] <TB1> INFO: Test took 1139ms.
[15:42:31.315] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 648 seconds
[15:42:31.315] <TB1> INFO: PH scale (per ROC): 73 70 66 69 68 71 79 70 64 83 69 79 68 75 78 75
[15:42:31.315] <TB1> INFO: PH offset (per ROC): 175 176 179 185 166 177 204 181 175 154 176 175 172 177 176 176
[15:42:31.510] <TB1> INFO: ######################################################################
[15:42:31.510] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[15:42:31.510] <TB1> INFO: ######################################################################
[15:42:31.522] <TB1> INFO: scanning low vcal = 10
[15:42:35.589] <TB1> INFO: Test took 4067ms.
[15:42:35.595] <TB1> INFO: scanning low vcal = 20
[15:42:39.914] <TB1> INFO: Test took 4319ms.
[15:42:39.920] <TB1> INFO: scanning low vcal = 30
[15:42:44.009] <TB1> INFO: Test took 4089ms.
[15:42:44.020] <TB1> INFO: scanning low vcal = 40
[15:42:48.787] <TB1> INFO: Test took 4767ms.
[15:42:48.848] <TB1> INFO: scanning low vcal = 50
[15:42:53.511] <TB1> INFO: Test took 4663ms.
[15:42:53.597] <TB1> INFO: scanning low vcal = 60
[15:42:58.370] <TB1> INFO: Test took 4773ms.
[15:42:58.429] <TB1> INFO: scanning low vcal = 70
[15:43:03.158] <TB1> INFO: Test took 4729ms.
[15:43:03.238] <TB1> INFO: scanning low vcal = 80
[15:43:07.975] <TB1> INFO: Test took 4737ms.
[15:43:08.055] <TB1> INFO: scanning low vcal = 90
[15:43:13.036] <TB1> INFO: Test took 4981ms.
[15:43:13.104] <TB1> INFO: scanning low vcal = 100
[15:43:17.977] <TB1> INFO: Test took 4873ms.
[15:43:18.068] <TB1> INFO: scanning low vcal = 110
[15:43:22.995] <TB1> INFO: Test took 4927ms.
[15:43:23.056] <TB1> INFO: scanning low vcal = 120
[15:43:27.788] <TB1> INFO: Test took 4732ms.
[15:43:27.855] <TB1> INFO: scanning low vcal = 130
[15:43:32.589] <TB1> INFO: Test took 4734ms.
[15:43:32.670] <TB1> INFO: scanning low vcal = 140
[15:43:37.348] <TB1> INFO: Test took 4678ms.
[15:43:37.408] <TB1> INFO: scanning low vcal = 150
[15:43:42.132] <TB1> INFO: Test took 4724ms.
[15:43:42.213] <TB1> INFO: scanning low vcal = 160
[15:43:46.917] <TB1> INFO: Test took 4704ms.
[15:43:46.978] <TB1> INFO: scanning low vcal = 170
[15:43:51.646] <TB1> INFO: Test took 4668ms.
[15:43:51.721] <TB1> INFO: scanning low vcal = 180
[15:43:56.642] <TB1> INFO: Test took 4921ms.
[15:43:56.707] <TB1> INFO: scanning low vcal = 190
[15:44:01.830] <TB1> INFO: Test took 5123ms.
[15:44:01.897] <TB1> INFO: scanning low vcal = 200
[15:44:07.237] <TB1> INFO: Test took 5340ms.
[15:44:07.301] <TB1> INFO: scanning low vcal = 210
[15:44:12.498] <TB1> INFO: Test took 5197ms.
[15:44:12.558] <TB1> INFO: scanning low vcal = 220
[15:44:18.035] <TB1> INFO: Test took 5477ms.
[15:44:18.100] <TB1> INFO: scanning low vcal = 230
[15:44:23.329] <TB1> INFO: Test took 5229ms.
[15:44:23.393] <TB1> INFO: scanning low vcal = 240
[15:44:28.674] <TB1> INFO: Test took 5281ms.
[15:44:28.739] <TB1> INFO: scanning low vcal = 250
[15:44:36.004] <TB1> INFO: Test took 7265ms.
[15:44:36.064] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[15:44:43.075] <TB1> INFO: Test took 7011ms.
[15:44:43.160] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[15:44:50.663] <TB1> INFO: Test took 7503ms.
[15:44:50.752] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[15:44:58.053] <TB1> INFO: Test took 7301ms.
[15:44:58.138] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[15:45:04.609] <TB1> INFO: Test took 6471ms.
[15:45:04.673] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[15:45:09.514] <TB1> INFO: Test took 4841ms.
[15:45:10.045] <TB1> INFO: PixTestGainPedestal::measure() done
[15:45:42.363] <TB1> INFO: PixTestGainPedestal::fit() done
[15:45:42.363] <TB1> INFO: non-linearity mean: 0.958 0.957 0.959 0.957 0.962 0.960 0.958 0.954 0.958 0.959 0.962 0.962 0.955 0.962 0.966 0.960
[15:45:42.363] <TB1> INFO: non-linearity RMS: 0.005 0.007 0.007 0.007 0.006 0.006 0.006 0.008 0.005 0.005 0.007 0.006 0.007 0.006 0.004 0.006
[15:45:42.363] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C0.dat
[15:45:42.384] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C1.dat
[15:45:42.405] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C2.dat
[15:45:42.426] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C3.dat
[15:45:42.447] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C4.dat
[15:45:42.467] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C5.dat
[15:45:42.488] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C6.dat
[15:45:42.509] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C7.dat
[15:45:42.529] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C8.dat
[15:45:42.548] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C9.dat
[15:45:42.568] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C10.dat
[15:45:42.588] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C11.dat
[15:45:42.608] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C12.dat
[15:45:42.629] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C13.dat
[15:45:42.648] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C14.dat
[15:45:42.668] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2065_FullQualification_2015-08-06_10h09m_1438848555//004_FulltestPxar_p17//phCalibrationFitErr35_C15.dat
[15:45:42.688] <TB1> INFO: PixTestGainPedestal::doTest() done, duration: 191 seconds
[15:45:42.695] <TB1> INFO: enter test to run
[15:45:42.695] <TB1> INFO: test: exit no parameter change
[15:45:43.167] <TB1> QUIET: Connection to board 153 closed.
[15:45:43.167] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master