Test Date: 2015-08-05 10:47
Analysis date: 2016-05-26 00:26
Logfile
LogfileView
[08:55:15.951] <TB1> INFO: *** Welcome to pxar ***
[08:55:15.951] <TB1> INFO: *** Today: 2015/08/05
[08:55:15.951] <TB1> INFO: readRocDacs: /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C15.dat
[08:55:15.952] <TB1> INFO: readTbmDacs: /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//tbmParameters_C0b.dat
[08:55:15.952] <TB1> INFO: readMaskFile: /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//defaultMaskFile.dat
[08:55:15.952] <TB1> INFO: readTrimFile: /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters_C15.dat
[08:55:16.226] <TB1> INFO: clk: 4
[08:55:16.226] <TB1> INFO: ctr: 4
[08:55:16.226] <TB1> INFO: sda: 19
[08:55:16.226] <TB1> INFO: tin: 9
[08:55:16.226] <TB1> INFO: level: 15
[08:55:16.226] <TB1> INFO: triggerdelay: 0
[08:55:16.226] <TB1> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[08:55:16.226] <TB1> INFO: Log level: INFO
[08:55:16.250] <TB1> INFO: Found DTB DTB_WXBYFL
[08:55:16.276] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[08:55:16.279] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[08:55:16.283] <TB1> INFO: RPC call hashes of host and DTB match: 447413373
[08:55:18.247] <TB1> INFO: DUT info:
[08:55:18.247] <TB1> INFO: The DUT currently contains the following objects:
[08:55:18.247] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[08:55:18.247] <TB1> INFO: TBM Core alpha (0): 7 registers set
[08:55:18.247] <TB1> INFO: TBM Core beta (1): 7 registers set
[08:55:18.247] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[08:55:18.247] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.247] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[08:55:18.649] <TB1> INFO: enter 'restricted' command line mode
[08:55:18.649] <TB1> INFO: enter test to run
[08:55:18.649] <TB1> INFO: test: pretest no parameter change
[08:55:18.649] <TB1> INFO: running: pretest
[08:55:18.656] <TB1> INFO: ######################################################################
[08:55:18.656] <TB1> INFO: PixTestPretest::doTest()
[08:55:18.656] <TB1> INFO: ######################################################################
[08:55:18.658] <TB1> INFO: ----------------------------------------------------------------------
[08:55:18.658] <TB1> INFO: PixTestPretest::programROC()
[08:55:18.658] <TB1> INFO: ----------------------------------------------------------------------
[08:55:36.686] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[08:55:36.686] <TB1> INFO: IA differences per ROC: 16.9 16.9 18.5 19.3 20.1 17.7 17.7 17.7 18.5 18.5 16.9 19.3 17.7 17.7 21.7 18.5
[08:55:36.775] <TB1> INFO: ----------------------------------------------------------------------
[08:55:36.775] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[08:55:36.775] <TB1> INFO: ----------------------------------------------------------------------
[08:55:56.374] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 381.9 mA = 23.8688 mA/ROC
[08:55:56.382] <TB1> INFO: ----------------------------------------------------------------------
[08:55:56.382] <TB1> INFO: PixTestPretest::findWorkingPixel()
[08:55:56.382] <TB1> INFO: ----------------------------------------------------------------------
[08:56:08.691] <TB1> INFO: Test took 12304ms.
[08:56:09.010] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[08:56:09.060] <TB1> INFO: ----------------------------------------------------------------------
[08:56:09.061] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[08:56:09.061] <TB1> INFO: ----------------------------------------------------------------------
[08:56:22.474] <TB1> INFO: Test took 13407ms.
[08:56:22.797] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[08:56:22.797] <TB1> INFO: CalDel: 155 123 154 153 138 141 129 108 146 135 132 143 132 148 143 131
[08:56:22.797] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[08:56:22.800] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C0.dat
[08:56:22.800] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C1.dat
[08:56:22.800] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C2.dat
[08:56:22.800] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C3.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C4.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C5.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C6.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C7.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C8.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C9.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C10.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C11.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C12.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C13.dat
[08:56:22.801] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C14.dat
[08:56:22.802] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters_C15.dat
[08:56:22.802] <TB1> INFO: PixTestPretest::doTest() done, duration: 64 seconds
[08:56:22.893] <TB1> INFO: enter test to run
[08:56:22.893] <TB1> INFO: test: fulltest no parameter change
[08:56:22.893] <TB1> INFO: running: fulltest
[08:56:22.893] <TB1> INFO: ######################################################################
[08:56:22.893] <TB1> INFO: PixTestFullTest::doTest()
[08:56:22.893] <TB1> INFO: ######################################################################
[08:56:22.896] <TB1> INFO: ######################################################################
[08:56:22.896] <TB1> INFO: PixTestAlive::doTest()
[08:56:22.896] <TB1> INFO: ######################################################################
[08:56:22.899] <TB1> INFO: ----------------------------------------------------------------------
[08:56:22.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)
[08:56:22.899] <TB1> INFO: ----------------------------------------------------------------------
[08:56:27.862] <TB1> INFO: Test took 4960ms.
[08:56:27.882] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:28.123] <TB1> INFO: PixTestAlive::aliveTest() done
[08:56:28.123] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0
[08:56:28.125] <TB1> INFO: ----------------------------------------------------------------------
[08:56:28.125] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[08:56:28.125] <TB1> INFO: ----------------------------------------------------------------------
[08:56:31.242] <TB1> INFO: Test took 3115ms.
[08:56:31.243] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:31.244] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[08:56:31.483] <TB1> INFO: PixTestAlive::maskTest() done
[08:56:31.483] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[08:56:31.485] <TB1> INFO: ----------------------------------------------------------------------
[08:56:31.485] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[08:56:31.485] <TB1> INFO: ----------------------------------------------------------------------
[08:56:36.038] <TB1> INFO: Test took 4551ms.
[08:56:36.059] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:56:36.302] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[08:56:36.302] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[08:56:36.303] <TB1> INFO: PixTestAlive::doTest() done, duration: 13 seconds
[08:56:36.311] <TB1> INFO: ######################################################################
[08:56:36.311] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[08:56:36.311] <TB1> INFO: ######################################################################
[08:56:36.315] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[08:56:36.329] <TB1> INFO: dacScan step from 0 .. 29
[08:57:12.076] <TB1> INFO: Test took 35746ms.
[08:57:12.165] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:57:12.165] <TB1> INFO: dacScan step from 30 .. 59
[08:58:05.198] <TB1> INFO: Test took 53033ms.
[08:58:05.651] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:58:05.749] <TB1> INFO: dacScan step from 60 .. 89
[08:59:13.164] <TB1> INFO: Test took 67415ms.
[08:59:14.433] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:59:14.911] <TB1> INFO: dacScan step from 90 .. 119
[09:00:32.050] <TB1> INFO: Test took 77139ms.
[09:00:32.306] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:00:32.387] <TB1> INFO: dacScan step from 120 .. 149
[09:01:31.802] <TB1> INFO: Test took 59415ms.
[09:01:32.585] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:02:35.462] <TB1> INFO: PixTestBBMap::doTest() done, duration: 359 seconds
[09:02:35.462] <TB1> INFO: number of dead bumps (per ROC): 5 0 0 0 0 1 0 0 0 0 0 0 0 0 1 0
[09:02:35.462] <TB1> INFO: separation cut (per ROC): 87 97 99 78 84 94 95 93 91 86 78 80 91 80 84 89
[09:02:35.535] <TB1> INFO: ######################################################################
[09:02:35.535] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50
[09:02:35.535] <TB1> INFO: ######################################################################
[09:02:35.535] <TB1> INFO: ----------------------------------------------------------------------
[09:02:35.535] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[09:02:35.535] <TB1> INFO: ----------------------------------------------------------------------
[09:02:35.536] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[09:02:35.545] <TB1> INFO: dacScan step from 0 .. 3
[09:03:09.102] <TB1> INFO: Test took 33557ms.
[09:03:09.130] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:03:09.130] <TB1> INFO: dacScan step from 4 .. 7
[09:03:41.491] <TB1> INFO: Test took 32361ms.
[09:03:41.520] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:03:41.520] <TB1> INFO: dacScan step from 8 .. 11
[09:04:22.043] <TB1> INFO: Test took 40523ms.
[09:04:22.145] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:04:22.145] <TB1> INFO: dacScan step from 12 .. 15
[09:05:10.918] <TB1> INFO: Test took 48773ms.
[09:05:11.010] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:05:11.010] <TB1> INFO: dacScan step from 16 .. 19
[09:05:50.431] <TB1> INFO: Test took 39421ms.
[09:05:50.461] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:05:50.461] <TB1> INFO: dacScan step from 20 .. 23
[09:06:36.398] <TB1> INFO: Test took 45937ms.
[09:06:36.460] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:06:36.460] <TB1> INFO: dacScan step from 24 .. 27
[09:07:24.758] <TB1> INFO: Test took 48298ms.
[09:07:24.871] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:07:24.871] <TB1> INFO: dacScan step from 28 .. 31
[09:08:00.972] <TB1> INFO: Test took 36101ms.
[09:08:01.000] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:08:01.000] <TB1> INFO: dacScan step from 32 .. 35
[09:08:47.213] <TB1> INFO: Test took 46213ms.
[09:08:47.239] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:08:47.239] <TB1> INFO: dacScan step from 36 .. 39
[09:09:34.899] <TB1> INFO: Test took 47660ms.
[09:09:34.956] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:09:34.956] <TB1> INFO: dacScan step from 40 .. 43
[09:10:10.161] <TB1> INFO: Test took 35204ms.
[09:10:10.191] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:10:10.191] <TB1> INFO: dacScan step from 44 .. 47
[09:10:43.498] <TB1> INFO: Test took 33307ms.
[09:10:43.527] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:10:43.527] <TB1> INFO: dacScan step from 48 .. 51
[09:11:16.437] <TB1> INFO: Test took 32910ms.
[09:11:16.468] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:11:16.468] <TB1> INFO: dacScan step from 52 .. 55
[09:11:43.913] <TB1> INFO: Test took 27445ms.
[09:11:43.940] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:11:43.940] <TB1> INFO: dacScan step from 56 .. 59
[09:12:13.024] <TB1> INFO: Test took 29084ms.
[09:12:13.057] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:12:13.057] <TB1> INFO: dacScan step from 60 .. 63
[09:12:43.019] <TB1> INFO: Test took 29962ms.
[09:12:43.048] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:12:43.048] <TB1> INFO: dacScan step from 64 .. 67
[09:13:13.618] <TB1> INFO: Test took 30570ms.
[09:13:13.652] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:13:13.652] <TB1> INFO: dacScan step from 68 .. 71
[09:13:41.254] <TB1> INFO: Test took 27602ms.
[09:13:41.289] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:13:41.290] <TB1> INFO: dacScan step from 72 .. 75
[09:14:10.343] <TB1> INFO: Test took 29053ms.
[09:14:10.394] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:10.395] <TB1> INFO: dacScan step from 76 .. 79
[09:14:41.933] <TB1> INFO: Test took 31537ms.
[09:14:42.006] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:14:42.009] <TB1> INFO: dacScan step from 80 .. 83
[09:15:14.895] <TB1> INFO: Test took 32887ms.
[09:15:15.010] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:15.015] <TB1> INFO: dacScan step from 84 .. 87
[09:15:52.924] <TB1> INFO: Test took 37909ms.
[09:15:53.075] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:15:53.083] <TB1> INFO: dacScan step from 88 .. 91
[09:16:50.803] <TB1> INFO: Test took 57720ms.
[09:16:50.984] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:16:50.993] <TB1> INFO: dacScan step from 92 .. 95
[09:17:29.769] <TB1> INFO: Test took 38775ms.
[09:17:30.006] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:30.016] <TB1> INFO: dacScan step from 96 .. 99
[09:18:10.171] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (116) != TBM ID (0)

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

[09:18:10.171] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (117)

[09:18:11.214] <TB1> INFO: Test took 41198ms.
[09:18:11.472] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:18:11.482] <TB1> INFO: dacScan step from 100 .. 103
[09:18:59.807] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[09:19:03.672] <TB1> INFO: Test took 52190ms.
[09:19:03.920] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:03.933] <TB1> INFO: dacScan step from 104 .. 107
[09:19:51.189] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[09:19:53.289] <TB1> INFO: Test took 49356ms.
[09:19:53.529] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:19:53.540] <TB1> INFO: dacScan step from 108 .. 111
[09:20:48.213] <TB1> INFO: Test took 54673ms.
[09:20:48.468] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:20:48.479] <TB1> INFO: dacScan step from 112 .. 115
[09:21:30.277] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[09:21:30.277] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 31 readouts!

[09:21:30.277] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[09:21:32.227] <TB1> INFO: Test took 43748ms.
[09:21:32.485] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:21:32.496] <TB1> INFO: dacScan step from 116 .. 119
[09:22:50.692] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[09:22:56.426] <TB1> INFO: Test took 83930ms.
[09:22:56.651] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:22:56.663] <TB1> INFO: dacScan step from 120 .. 123
[09:24:04.786] <TB1> INFO: Test took 68122ms.
[09:24:05.008] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:05.019] <TB1> INFO: dacScan step from 124 .. 127
[09:24:46.052] <TB1> INFO: Test took 41033ms.
[09:24:46.270] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:24:46.281] <TB1> INFO: dacScan step from 128 .. 131
[09:25:31.736] <TB1> INFO: Test took 45455ms.
[09:25:31.981] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:25:31.993] <TB1> INFO: dacScan step from 132 .. 135
[09:26:17.133] <TB1> INFO: Test took 45140ms.
[09:26:17.377] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:26:17.389] <TB1> INFO: dacScan step from 136 .. 139
[09:27:15.148] <TB1> INFO: Test took 57759ms.
[09:27:15.394] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:27:15.405] <TB1> INFO: dacScan step from 140 .. 143
[09:27:59.941] <TB1> INFO: Test took 44536ms.
[09:28:00.185] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:00.197] <TB1> INFO: dacScan step from 144 .. 147
[09:28:44.746] <TB1> INFO: Test took 44549ms.
[09:28:45.000] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:28:45.013] <TB1> INFO: dacScan step from 148 .. 149
[09:29:10.585] <TB1> INFO: Test took 25572ms.
[09:29:10.694] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:29:10.700] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:12.165] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:13.583] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:14.953] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:16.333] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:17.710] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:19.056] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:20.493] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:21.948] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:23.381] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:24.801] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:26.206] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:27.727] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:29.215] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:30.796] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:32.316] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[09:29:33.835] <TB1> INFO: PixTestScurves::scurves() done
[09:29:33.835] <TB1> INFO: Vcal mean: 94.01 91.78 98.99 89.68 84.34 93.85 97.88 86.81 96.76 86.46 80.97 85.22 93.48 78.56 79.49 86.47
[09:29:33.835] <TB1> INFO: Vcal RMS: 5.97 5.48 6.08 5.89 4.65 6.03 5.63 5.88 5.57 5.28 5.17 5.64 6.06 4.48 4.85 5.69
[09:29:33.835] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1618 seconds
[09:29:33.912] <TB1> INFO: ######################################################################
[09:29:33.912] <TB1> INFO: PixTestTrim::doTest()
[09:29:33.912] <TB1> INFO: ######################################################################
[09:29:33.915] <TB1> INFO: ----------------------------------------------------------------------
[09:29:33.915] <TB1> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[09:29:33.915] <TB1> INFO: ----------------------------------------------------------------------
[09:29:34.003] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[09:29:34.003] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[09:29:34.012] <TB1> INFO: dacScan step from 0 .. 19
[09:30:00.755] <TB1> INFO: Test took 26743ms.
[09:30:00.776] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:00.776] <TB1> INFO: dacScan step from 20 .. 39
[09:30:25.488] <TB1> INFO: Test took 24711ms.
[09:30:25.515] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:25.515] <TB1> INFO: dacScan step from 40 .. 59
[09:30:43.092] <TB1> INFO: Test took 17577ms.
[09:30:43.119] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:30:43.119] <TB1> INFO: dacScan step from 60 .. 79
[09:31:00.047] <TB1> INFO: Test took 16928ms.
[09:31:00.074] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:31:00.074] <TB1> INFO: dacScan step from 80 .. 99
[09:31:19.280] <TB1> INFO: Test took 19206ms.
[09:31:19.335] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:31:19.343] <TB1> INFO: dacScan step from 100 .. 119
[09:31:44.380] <TB1> INFO: Test took 25037ms.
[09:31:44.538] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:31:44.569] <TB1> INFO: dacScan step from 120 .. 139
[09:32:11.415] <TB1> INFO: Test took 26846ms.
[09:32:11.582] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:11.615] <TB1> INFO: dacScan step from 140 .. 159
[09:32:32.563] <TB1> INFO: Test took 20947ms.
[09:32:32.634] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:32:53.345] <TB1> INFO: ROC 0 VthrComp = 96
[09:32:53.345] <TB1> INFO: ROC 1 VthrComp = 98
[09:32:53.345] <TB1> INFO: ROC 2 VthrComp = 101
[09:32:53.345] <TB1> INFO: ROC 3 VthrComp = 92
[09:32:53.346] <TB1> INFO: ROC 4 VthrComp = 92
[09:32:53.346] <TB1> INFO: ROC 5 VthrComp = 96
[09:32:53.346] <TB1> INFO: ROC 6 VthrComp = 99
[09:32:53.346] <TB1> INFO: ROC 7 VthrComp = 89
[09:32:53.346] <TB1> INFO: ROC 8 VthrComp = 99
[09:32:53.346] <TB1> INFO: ROC 9 VthrComp = 92
[09:32:53.346] <TB1> INFO: ROC 10 VthrComp = 84
[09:32:53.347] <TB1> INFO: ROC 11 VthrComp = 87
[09:32:53.347] <TB1> INFO: ROC 12 VthrComp = 94
[09:32:53.347] <TB1> INFO: ROC 13 VthrComp = 82
[09:32:53.347] <TB1> INFO: ROC 14 VthrComp = 85
[09:32:53.347] <TB1> INFO: ROC 15 VthrComp = 91
[09:32:53.347] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[09:32:53.347] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[09:32:53.359] <TB1> INFO: dacScan step from 0 .. 19
[09:33:10.717] <TB1> INFO: Test took 17357ms.
[09:33:10.743] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:10.743] <TB1> INFO: dacScan step from 20 .. 39
[09:33:29.471] <TB1> INFO: Test took 18728ms.
[09:33:29.507] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:33:29.511] <TB1> INFO: dacScan step from 40 .. 59
[09:34:12.247] <TB1> INFO: Test took 42736ms.
[09:34:12.418] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:12.454] <TB1> INFO: dacScan step from 60 .. 79
[09:34:53.158] <TB1> INFO: Test took 40704ms.
[09:34:53.334] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:34:53.383] <TB1> INFO: dacScan step from 80 .. 99
[09:35:25.450] <TB1> INFO: Test took 32067ms.
[09:35:25.620] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:35:25.677] <TB1> INFO: dacScan step from 100 .. 119
[09:36:13.458] <TB1> INFO: Test took 47780ms.
[09:36:13.617] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:13.666] <TB1> INFO: dacScan step from 120 .. 139
[09:36:49.438] <TB1> INFO: Test took 35772ms.
[09:36:49.639] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:36:49.690] <TB1> INFO: dacScan step from 140 .. 159
[09:37:21.662] <TB1> INFO: Test took 31971ms.
[09:37:21.840] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:37:46.913] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 61.1039 for pixel 8/52 mean/min/max = 46.3587/31.5546/61.1627
[09:37:46.914] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 58.761 for pixel 15/79 mean/min/max = 45.3027/31.8109/58.7945
[09:37:46.914] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 64.1981 for pixel 17/3 mean/min/max = 46.6968/28.3597/65.0339
[09:37:46.915] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 60.1789 for pixel 22/72 mean/min/max = 46.0293/31.6786/60.3799
[09:37:46.915] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 56.5832 for pixel 2/78 mean/min/max = 44.5178/32.2723/56.7633
[09:37:46.915] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 59.8376 for pixel 12/8 mean/min/max = 45.5345/31.0565/60.0124
[09:37:46.916] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 58.6197 for pixel 22/1 mean/min/max = 45.1349/31.5171/58.7527
[09:37:46.916] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 61.3069 for pixel 0/8 mean/min/max = 46.8759/32.404/61.3477
[09:37:46.916] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 59.4246 for pixel 24/70 mean/min/max = 45.7691/31.8003/59.7379
[09:37:46.917] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 59.09 for pixel 22/78 mean/min/max = 45.6048/31.8698/59.3397
[09:37:46.917] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 60.693 for pixel 4/73 mean/min/max = 46.2754/31.8439/60.7068
[09:37:46.917] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 60.7028 for pixel 51/74 mean/min/max = 46.169/31.2395/61.0984
[09:37:46.917] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 61.1845 for pixel 37/79 mean/min/max = 46.6068/31.9816/61.2321
[09:37:46.918] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 58.6186 for pixel 26/78 mean/min/max = 45.6884/32.6628/58.714
[09:37:46.918] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 59.5056 for pixel 8/79 mean/min/max = 45.6987/31.728/59.6694
[09:37:46.918] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 60.1122 for pixel 33/77 mean/min/max = 45.9686/31.7681/60.1692
[09:37:46.919] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[09:40:15.738] <TB1> INFO: Test took 148819ms.
[09:40:17.239] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[09:40:17.248] <TB1> INFO: dacScan step from 0 .. 19
[09:40:46.018] <TB1> INFO: Test took 28770ms.
[09:40:46.071] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:40:46.075] <TB1> INFO: dacScan step from 20 .. 39
[09:41:38.525] <TB1> INFO: Test took 52450ms.
[09:41:38.780] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:41:38.811] <TB1> INFO: dacScan step from 40 .. 59
[09:42:32.892] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (161) != TBM ID (0)

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

[09:42:32.892] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (162)

[09:42:35.435] <TB1> INFO: Test took 56624ms.
[09:42:35.735] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:42:35.782] <TB1> INFO: dacScan step from 60 .. 79
[09:43:32.508] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[09:43:36.959] <TB1> INFO: Test took 61176ms.
[09:43:37.255] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:43:37.309] <TB1> INFO: dacScan step from 80 .. 99
[09:44:46.307] <TB1> INFO: Test took 68998ms.
[09:44:46.602] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:44:46.657] <TB1> INFO: dacScan step from 100 .. 119
[09:45:31.564] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (203) != TBM ID (0)

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

[09:45:31.565] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (204)

[09:45:33.550] <TB1> INFO: Test took 46893ms.
[09:45:33.855] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:45:33.905] <TB1> INFO: dacScan step from 120 .. 139
[09:46:29.013] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[09:46:32.320] <TB1> INFO: Test took 58415ms.
[09:46:32.617] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:46:32.668] <TB1> INFO: dacScan step from 140 .. 159
[09:47:18.856] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (204) != TBM ID (0)

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

[09:47:18.856] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (1) != TBM ID (205)

[09:47:20.835] <TB1> INFO: Test took 48167ms.
[09:47:21.156] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:47:21.206] <TB1> INFO: dacScan step from 160 .. 179
[09:48:08.724] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[09:48:08.724] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[09:48:10.438] <TB1> INFO: Test took 49232ms.
[09:48:10.743] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:10.811] <TB1> INFO: dacScan step from 180 .. 199
[09:49:08.378] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[09:49:10.319] <TB1> INFO: Test took 59508ms.
[09:49:10.586] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:36.201] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.005425 .. 255.000000
[09:49:36.281] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[09:49:36.290] <TB1> INFO: dacScan step from 0 .. 19
[09:49:54.343] <TB1> INFO: Test took 18053ms.
[09:49:54.372] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:54.372] <TB1> INFO: dacScan step from 20 .. 39
[09:50:13.661] <TB1> INFO: Test took 19289ms.
[09:50:13.761] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:13.780] <TB1> INFO: dacScan step from 40 .. 59
[09:50:35.917] <TB1> INFO: Test took 22137ms.
[09:50:36.069] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:36.119] <TB1> INFO: dacScan step from 60 .. 79
[09:50:57.316] <TB1> INFO: Test took 21197ms.
[09:50:57.462] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:50:57.512] <TB1> INFO: dacScan step from 80 .. 99
[09:51:21.939] <TB1> INFO: Test took 24427ms.
[09:51:22.110] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:22.161] <TB1> INFO: dacScan step from 100 .. 119
[09:51:47.412] <TB1> INFO: Test took 25251ms.
[09:51:47.564] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:47.617] <TB1> INFO: dacScan step from 120 .. 139
[09:52:14.550] <TB1> INFO: Test took 26933ms.
[09:52:14.695] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:14.751] <TB1> INFO: dacScan step from 140 .. 159
[09:52:54.916] <TB1> INFO: Test took 40165ms.
[09:52:55.146] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:55.255] <TB1> INFO: dacScan step from 160 .. 179
[09:53:33.052] <TB1> INFO: Test took 37797ms.
[09:53:33.206] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:53:33.266] <TB1> INFO: dacScan step from 180 .. 199
[09:54:01.610] <TB1> INFO: Test took 28344ms.
[09:54:01.776] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:01.827] <TB1> INFO: dacScan step from 200 .. 219
[09:54:25.688] <TB1> INFO: Test took 23861ms.
[09:54:25.852] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:25.902] <TB1> INFO: dacScan step from 220 .. 239
[09:54:50.909] <TB1> INFO: Test took 25007ms.
[09:54:51.058] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:54:51.108] <TB1> INFO: dacScan step from 240 .. 255
[09:55:12.491] <TB1> INFO: Test took 21383ms.
[09:55:12.617] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:55:49.815] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 0.996275 .. 55.521579
[09:55:49.913] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 0 .. 65 (20) hits flags = 16 (plus default)
[09:55:49.922] <TB1> INFO: dacScan step from 0 .. 19
[09:56:05.566] <TB1> INFO: Test took 15644ms.
[09:56:05.589] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:56:05.589] <TB1> INFO: dacScan step from 20 .. 39
[09:56:25.753] <TB1> INFO: Test took 20164ms.
[09:56:25.840] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:56:25.858] <TB1> INFO: dacScan step from 40 .. 59
[09:56:59.369] <TB1> INFO: Test took 33511ms.
[09:56:59.533] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:56:59.594] <TB1> INFO: dacScan step from 60 .. 65
[09:57:13.474] <TB1> INFO: Test took 13880ms.
[09:57:13.542] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:57:32.553] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 15.500000 .. 55.521579
[09:57:32.628] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 5 .. 65 (20) hits flags = 16 (plus default)
[09:57:32.636] <TB1> INFO: dacScan step from 5 .. 24
[09:57:48.436] <TB1> INFO: Test took 15800ms.
[09:57:48.464] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:57:48.464] <TB1> INFO: dacScan step from 25 .. 44
[09:58:08.090] <TB1> INFO: Test took 19626ms.
[09:58:08.205] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:08.234] <TB1> INFO: dacScan step from 45 .. 64
[09:58:31.193] <TB1> INFO: Test took 22959ms.
[09:58:31.358] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:31.417] <TB1> INFO: dacScan step from 65 .. 65
[09:58:35.154] <TB1> INFO: Test took 3737ms.
[09:58:35.169] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:58:53.360] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 0.994242 .. 55.521579
[09:58:53.446] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 0 .. 65 (20) hits flags = 16 (plus default)
[09:58:53.455] <TB1> INFO: dacScan step from 0 .. 19
[09:59:10.922] <TB1> INFO: Test took 17467ms.
[09:59:10.948] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:10.948] <TB1> INFO: dacScan step from 20 .. 39
[09:59:28.652] <TB1> INFO: Test took 17704ms.
[09:59:28.731] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:28.750] <TB1> INFO: dacScan step from 40 .. 59
[09:59:54.125] <TB1> INFO: Test took 25375ms.
[09:59:54.302] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[09:59:54.350] <TB1> INFO: dacScan step from 60 .. 65
[10:00:03.166] <TB1> INFO: Test took 8815ms.
[10:00:03.215] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:00:21.955] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[10:00:21.956] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[10:00:21.965] <TB1> INFO: dacScan step from 15 .. 34
[10:01:02.465] <TB1> INFO: Test took 40500ms.
[10:01:02.531] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:01:02.545] <TB1> INFO: dacScan step from 35 .. 54
[10:02:05.050] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[10:02:05.050] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 31 readouts!

[10:02:05.050] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[10:02:06.697] <TB1> INFO: Test took 64152ms.
[10:02:07.049] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:07.097] <TB1> INFO: dacScan step from 55 .. 55
[10:02:12.171] <TB1> INFO: Test took 5074ms.
[10:02:12.195] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:25.981] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C0.dat
[10:02:25.981] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C1.dat
[10:02:25.982] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C2.dat
[10:02:25.982] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C3.dat
[10:02:25.982] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C4.dat
[10:02:25.982] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C5.dat
[10:02:25.983] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C6.dat
[10:02:25.983] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C7.dat
[10:02:25.983] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C8.dat
[10:02:25.983] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C9.dat
[10:02:25.983] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C10.dat
[10:02:25.983] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C11.dat
[10:02:25.984] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C12.dat
[10:02:25.984] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C13.dat
[10:02:25.984] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C14.dat
[10:02:25.984] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C15.dat
[10:02:25.984] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C0.dat
[10:02:25.997] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C1.dat
[10:02:26.004] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C2.dat
[10:02:26.010] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C3.dat
[10:02:26.017] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C4.dat
[10:02:26.024] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C5.dat
[10:02:26.031] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C6.dat
[10:02:26.038] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C7.dat
[10:02:26.045] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C8.dat
[10:02:26.052] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C9.dat
[10:02:26.059] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C10.dat
[10:02:26.067] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C11.dat
[10:02:26.075] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C12.dat
[10:02:26.082] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C13.dat
[10:02:26.090] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C14.dat
[10:02:26.097] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//trimParameters35_C15.dat
[10:02:26.105] <TB1> INFO: PixTestTrim::trimTest() done
[10:02:26.105] <TB1> INFO: vtrim: 114 112 215 112 103 122 117 115 114 120 119 102 114 115 120 108
[10:02:26.105] <TB1> INFO: vthrcomp: 96 98 101 92 92 96 99 89 99 92 84 87 94 82 85 91
[10:02:26.105] <TB1> INFO: vcal mean: 35.03 35.04 34.92 34.89 35.06 35.00 34.99 35.05 35.04 35.04 35.05 34.89 35.05 35.04 35.02 35.03
[10:02:26.105] <TB1> INFO: vcal RMS: 1.19 1.16 2.63 1.11 1.01 1.06 1.12 1.03 1.21 1.01 1.06 1.00 1.05 1.02 0.97 1.07
[10:02:26.105] <TB1> INFO: bits mean: 9.87 10.23 11.88 10.07 10.08 9.95 10.20 9.48 9.95 9.95 9.79 9.51 9.43 10.05 9.81 9.62
[10:02:26.105] <TB1> INFO: bits RMS: 2.55 2.37 1.59 2.39 2.45 2.54 2.46 2.55 2.48 2.50 2.55 2.69 2.68 2.36 2.57 2.68
[10:02:26.116] <TB1> INFO: ----------------------------------------------------------------------
[10:02:26.116] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[10:02:26.116] <TB1> INFO: ----------------------------------------------------------------------
[10:02:26.120] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[10:02:26.136] <TB1> INFO: dacScan step from 0 .. 19
[10:02:55.882] <TB1> INFO: Test took 29746ms.
[10:02:55.927] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:02:55.927] <TB1> INFO: dacScan step from 20 .. 39
[10:03:25.818] <TB1> INFO: Test took 29891ms.
[10:03:25.858] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:25.858] <TB1> INFO: dacScan step from 40 .. 59
[10:03:56.176] <TB1> INFO: Test took 30318ms.
[10:03:56.218] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:03:56.218] <TB1> INFO: dacScan step from 60 .. 79
[10:04:26.641] <TB1> INFO: Test took 30423ms.
[10:04:26.677] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:26.677] <TB1> INFO: dacScan step from 80 .. 99
[10:04:57.339] <TB1> INFO: Test took 30662ms.
[10:04:57.395] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:04:57.398] <TB1> INFO: dacScan step from 100 .. 119
[10:05:36.307] <TB1> INFO: Test took 38909ms.
[10:05:36.492] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:05:36.513] <TB1> INFO: dacScan step from 120 .. 139
[10:06:31.508] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[10:06:33.012] <TB1> INFO: Test took 56499ms.
[10:06:33.289] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:06:33.331] <TB1> INFO: dacScan step from 140 .. 159
[10:07:20.987] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[10:07:24.483] <TB1> INFO: Test took 51152ms.
[10:07:24.776] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:07:24.826] <TB1> INFO: dacScan step from 160 .. 179
[10:08:14.764] <TB1> INFO: Test took 49938ms.
[10:08:15.063] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:08:15.113] <TB1> INFO: dacScan step from 180 .. 199
[10:09:04.001] <TB1> INFO: Test took 48888ms.
[10:09:04.326] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:09:32.658] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 167 (20) hits flags = 16 (plus default)
[10:09:32.669] <TB1> INFO: dacScan step from 0 .. 19
[10:10:00.666] <TB1> INFO: Test took 27997ms.
[10:10:00.705] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:00.705] <TB1> INFO: dacScan step from 20 .. 39
[10:10:30.252] <TB1> INFO: Test took 29547ms.
[10:10:30.293] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:10:30.294] <TB1> INFO: dacScan step from 40 .. 59
[10:11:10.259] <TB1> INFO: Test took 39965ms.
[10:11:10.298] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:10.298] <TB1> INFO: dacScan step from 60 .. 79
[10:11:38.328] <TB1> INFO: Test took 28030ms.
[10:11:38.369] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:11:38.369] <TB1> INFO: dacScan step from 80 .. 99
[10:12:08.902] <TB1> INFO: Test took 30533ms.
[10:12:08.994] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:12:09.004] <TB1> INFO: dacScan step from 100 .. 119
[10:13:07.462] <TB1> INFO: Test took 58457ms.
[10:13:07.707] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:13:07.740] <TB1> INFO: dacScan step from 120 .. 139
[10:14:11.252] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[10:14:12.994] <TB1> INFO: Test took 65254ms.
[10:14:13.285] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:14:13.330] <TB1> INFO: dacScan step from 140 .. 159
[10:14:54.028] <TB1> INFO: Test took 40698ms.
[10:14:54.338] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:14:54.388] <TB1> INFO: dacScan step from 160 .. 167
[10:15:12.471] <TB1> INFO: Test took 18083ms.
[10:15:12.582] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:15:36.966] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 155 (20) hits flags = 16 (plus default)
[10:15:36.975] <TB1> INFO: dacScan step from 0 .. 19
[10:16:03.446] <TB1> INFO: Test took 26471ms.
[10:16:03.490] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:03.490] <TB1> INFO: dacScan step from 20 .. 39
[10:16:30.127] <TB1> INFO: Test took 26637ms.
[10:16:30.172] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:30.172] <TB1> INFO: dacScan step from 40 .. 59
[10:16:56.681] <TB1> INFO: Test took 26509ms.
[10:16:56.716] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:16:56.717] <TB1> INFO: dacScan step from 60 .. 79
[10:17:22.927] <TB1> INFO: Test took 26210ms.
[10:17:22.975] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:22.975] <TB1> INFO: dacScan step from 80 .. 99
[10:17:50.629] <TB1> INFO: Test took 27654ms.
[10:17:50.729] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:17:50.739] <TB1> INFO: dacScan step from 100 .. 119
[10:18:27.960] <TB1> INFO: Test took 37220ms.
[10:18:28.234] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:18:28.264] <TB1> INFO: dacScan step from 120 .. 139
[10:19:07.067] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[10:19:08.787] <TB1> INFO: Test took 40523ms.
[10:19:09.151] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:19:09.197] <TB1> INFO: dacScan step from 140 .. 155
[10:19:42.355] <TB1> INFO: Test took 33158ms.
[10:19:42.574] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:04.287] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 156 (20) hits flags = 16 (plus default)
[10:20:04.297] <TB1> INFO: dacScan step from 0 .. 19
[10:20:30.884] <TB1> INFO: Test took 26587ms.
[10:20:30.923] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:30.923] <TB1> INFO: dacScan step from 20 .. 39
[10:20:57.873] <TB1> INFO: Test took 26950ms.
[10:20:57.924] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:20:57.924] <TB1> INFO: dacScan step from 40 .. 59
[10:21:24.880] <TB1> INFO: Test took 26956ms.
[10:21:24.924] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:21:24.924] <TB1> INFO: dacScan step from 60 .. 79
[10:21:51.722] <TB1> INFO: Test took 26798ms.
[10:21:51.778] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:21:51.778] <TB1> INFO: dacScan step from 80 .. 99
[10:22:19.985] <TB1> INFO: Test took 28207ms.
[10:22:20.074] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:22:20.081] <TB1> INFO: dacScan step from 100 .. 119
[10:23:38.399] <TB1> INFO: Test took 78318ms.
[10:23:38.791] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:23:38.842] <TB1> INFO: dacScan step from 120 .. 139
[10:24:23.866] <TB1> INFO: Test took 45024ms.
[10:24:24.140] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:24:24.187] <TB1> INFO: dacScan step from 140 .. 156
[10:25:00.590] <TB1> INFO: Test took 36403ms.
[10:25:00.866] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:25:22.460] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 155 (20) hits flags = 16 (plus default)
[10:25:22.468] <TB1> INFO: dacScan step from 0 .. 19
[10:26:13.934] <TB1> INFO: Test took 51465ms.
[10:26:13.966] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:26:13.966] <TB1> INFO: dacScan step from 20 .. 39
[10:27:09.984] <TB1> INFO: Test took 56017ms.
[10:27:10.018] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:10.018] <TB1> INFO: dacScan step from 40 .. 59
[10:28:05.602] <TB1> INFO: Test took 55584ms.
[10:28:05.634] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:05.634] <TB1> INFO: dacScan step from 60 .. 79
[10:28:59.662] <TB1> INFO: Test took 54028ms.
[10:28:59.696] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:28:59.697] <TB1> INFO: dacScan step from 80 .. 99
[10:30:06.638] <TB1> INFO: Test took 66941ms.
[10:30:06.722] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:30:06.730] <TB1> INFO: dacScan step from 100 .. 119
[10:31:31.256] <TB1> INFO: Test took 84525ms.
[10:31:31.495] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:31:31.525] <TB1> INFO: dacScan step from 120 .. 139
[10:33:11.479] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[10:33:11.479] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[10:33:17.203] <TB1> INFO: Test took 105678ms.
[10:33:17.456] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:33:17.500] <TB1> INFO: dacScan step from 140 .. 155
[10:34:35.151] <TB1> INFO: Test took 77650ms.
[10:34:35.350] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:34:55.576] <TB1> INFO: PixTestTrim::trimBitTest() done
[10:34:55.578] <TB1> INFO: PixTestTrim::doTest() done, duration: 3921 seconds
[10:34:56.219] <TB1> INFO: ######################################################################
[10:34:56.219] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[10:34:56.219] <TB1> INFO: ######################################################################
[10:35:02.913] <TB1> INFO: Test took 6692ms.
[10:35:02.930] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:09.908] <TB1> INFO: Test took 6779ms.
[10:35:09.967] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:16.400] <TB1> INFO: Test took 6419ms.
[10:35:16.458] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[10:35:16.466] <TB1> INFO: The DUT currently contains the following objects:
[10:35:16.466] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:16.466] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:16.466] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:16.466] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:16.466] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:16.466] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.706] <TB1> INFO: Test took 1240ms.
[10:35:17.707] <TB1> INFO: The DUT currently contains the following objects:
[10:35:17.707] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:17.707] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:17.707] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:17.707] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:17.707] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.707] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.708] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:17.708] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.947] <TB1> INFO: Test took 1239ms.
[10:35:18.948] <TB1> INFO: The DUT currently contains the following objects:
[10:35:18.948] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:18.948] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:18.948] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:18.948] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:18.948] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:18.948] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.189] <TB1> INFO: Test took 1241ms.
[10:35:20.190] <TB1> INFO: The DUT currently contains the following objects:
[10:35:20.190] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:20.190] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:20.190] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:20.190] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:20.190] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:20.190] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.461] <TB1> INFO: Test took 1271ms.
[10:35:21.461] <TB1> INFO: The DUT currently contains the following objects:
[10:35:21.461] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:21.461] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:21.462] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:21.462] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:21.462] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:21.462] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.686] <TB1> INFO: Test took 1224ms.
[10:35:22.686] <TB1> INFO: The DUT currently contains the following objects:
[10:35:22.686] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:22.686] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:22.686] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:22.686] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:22.686] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.686] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.686] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.686] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:22.687] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: Test took 1226ms.
[10:35:23.913] <TB1> INFO: The DUT currently contains the following objects:
[10:35:23.913] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:23.913] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:23.913] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:23.913] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:23.913] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.913] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.914] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:23.914] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.139] <TB1> INFO: Test took 1225ms.
[10:35:25.139] <TB1> INFO: The DUT currently contains the following objects:
[10:35:25.139] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:25.139] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:25.140] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:25.140] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:25.140] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:25.140] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.396] <TB1> INFO: Test took 1256ms.
[10:35:26.396] <TB1> INFO: The DUT currently contains the following objects:
[10:35:26.397] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:26.397] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:26.397] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:26.397] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:26.397] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:26.397] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.637] <TB1> INFO: Test took 1240ms.
[10:35:27.637] <TB1> INFO: The DUT currently contains the following objects:
[10:35:27.638] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:27.638] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:27.638] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:27.638] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:27.638] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:27.638] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.879] <TB1> INFO: Test took 1241ms.
[10:35:28.880] <TB1> INFO: The DUT currently contains the following objects:
[10:35:28.880] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:28.880] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:28.880] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:28.880] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:28.880] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.880] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.881] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.881] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:28.881] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.121] <TB1> INFO: Test took 1240ms.
[10:35:30.121] <TB1> INFO: The DUT currently contains the following objects:
[10:35:30.121] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:30.121] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:30.121] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:30.121] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:30.121] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.121] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.121] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.121] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:30.122] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.378] <TB1> INFO: Test took 1256ms.
[10:35:31.378] <TB1> INFO: The DUT currently contains the following objects:
[10:35:31.378] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:31.378] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:31.378] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:31.378] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:31.378] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.378] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.378] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.378] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.378] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:31.379] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.649] <TB1> INFO: Test took 1270ms.
[10:35:32.650] <TB1> INFO: The DUT currently contains the following objects:
[10:35:32.650] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:32.650] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:32.650] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:32.650] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:32.650] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:32.650] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.905] <TB1> INFO: Test took 1255ms.
[10:35:33.905] <TB1> INFO: The DUT currently contains the following objects:
[10:35:33.905] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:33.905] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:33.905] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:33.905] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:33.905] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.905] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.905] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.905] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.905] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.905] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.905] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.906] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.906] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.906] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.906] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.906] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.906] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.906] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.906] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:33.906] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.161] <TB1> INFO: Test took 1255ms.
[10:35:35.162] <TB1> INFO: The DUT currently contains the following objects:
[10:35:35.162] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[10:35:35.162] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:35:35.162] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:35:35.162] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[10:35:35.162] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:35.162] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[10:35:36.418] <TB1> INFO: Test took 1256ms.
[10:35:36.422] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:47:40.926] <TB1> INFO: Test took 724504ms.
[10:47:42.337] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:11.305] <TB1> INFO: Test took 688968ms.
[10:59:12.835] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.842] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.849] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.855] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.862] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.869] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.875] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.882] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.889] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.895] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.902] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.909] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.915] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.922] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.929] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[10:59:12.935] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[10:59:12.942] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[10:59:12.949] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[10:59:12.955] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[10:59:12.962] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[10:59:12.969] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[10:59:12.975] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:12.982] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[10:59:13.037] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C0.dat
[10:59:13.043] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C1.dat
[10:59:13.043] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C2.dat
[10:59:13.043] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C3.dat
[10:59:13.043] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C4.dat
[10:59:13.044] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C5.dat
[10:59:13.044] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C6.dat
[10:59:13.044] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C7.dat
[10:59:13.044] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C8.dat
[10:59:13.044] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C9.dat
[10:59:13.044] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C10.dat
[10:59:13.044] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C11.dat
[10:59:13.044] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C12.dat
[10:59:13.045] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C13.dat
[10:59:13.045] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C14.dat
[10:59:13.045] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//dacParameters35_C15.dat
[10:59:19.830] <TB1> INFO: Test took 6781ms.
[10:59:27.741] <TB1> INFO: Test took 7637ms.
[10:59:34.562] <TB1> INFO: Test took 6545ms.
[10:59:34.840] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:35.860] <TB1> INFO: Test took 1020ms.
[10:59:35.863] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:37.087] <TB1> INFO: Test took 1224ms.
[10:59:37.090] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:38.361] <TB1> INFO: Test took 1271ms.
[10:59:38.364] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:39.589] <TB1> INFO: Test took 1225ms.
[10:59:39.592] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:40.832] <TB1> INFO: Test took 1240ms.
[10:59:40.835] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:42.075] <TB1> INFO: Test took 1240ms.
[10:59:42.078] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:43.349] <TB1> INFO: Test took 1272ms.
[10:59:43.352] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:44.607] <TB1> INFO: Test took 1256ms.
[10:59:44.610] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:45.866] <TB1> INFO: Test took 1256ms.
[10:59:45.869] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:47.156] <TB1> INFO: Test took 1287ms.
[10:59:47.158] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:48.430] <TB1> INFO: Test took 1272ms.
[10:59:48.432] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:49.703] <TB1> INFO: Test took 1271ms.
[10:59:49.706] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:50.961] <TB1> INFO: Test took 1255ms.
[10:59:50.964] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:52.236] <TB1> INFO: Test took 1272ms.
[10:59:52.239] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:53.510] <TB1> INFO: Test took 1271ms.
[10:59:53.513] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:54.768] <TB1> INFO: Test took 1255ms.
[10:59:54.771] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:56.027] <TB1> INFO: Test took 1256ms.
[10:59:56.030] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:57.286] <TB1> INFO: Test took 1256ms.
[10:59:57.289] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:58.544] <TB1> INFO: Test took 1255ms.
[10:59:58.547] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:59:59.755] <TB1> INFO: Test took 1208ms.
[10:59:59.758] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:00.998] <TB1> INFO: Test took 1240ms.
[11:00:01.001] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:02.257] <TB1> INFO: Test took 1256ms.
[11:00:02.260] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:03.517] <TB1> INFO: Test took 1257ms.
[11:00:03.520] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:04.792] <TB1> INFO: Test took 1272ms.
[11:00:04.795] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:06.020] <TB1> INFO: Test took 1225ms.
[11:00:06.023] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:07.263] <TB1> INFO: Test took 1240ms.
[11:00:07.266] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:08.537] <TB1> INFO: Test took 1272ms.
[11:00:08.539] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:09.781] <TB1> INFO: Test took 1242ms.
[11:00:09.783] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:11.024] <TB1> INFO: Test took 1241ms.
[11:00:11.027] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:12.267] <TB1> INFO: Test took 1240ms.
[11:00:12.270] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:13.540] <TB1> INFO: Test took 1271ms.
[11:00:13.543] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:00:14.799] <TB1> INFO: Test took 1256ms.
[11:00:15.388] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 1519 seconds
[11:00:15.388] <TB1> INFO: PH scale (per ROC): 80 79 80 80 85 76 77 92 89 81 80 78 80 86 86 79
[11:00:15.388] <TB1> INFO: PH offset (per ROC): 167 156 165 156 150 156 170 169 149 153 160 146 154 176 146 161
[11:00:15.556] <TB1> INFO: ######################################################################
[11:00:15.556] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[11:00:15.556] <TB1> INFO: ######################################################################
[11:00:15.566] <TB1> INFO: scanning low vcal = 10
[11:00:21.304] <TB1> INFO: Test took 5737ms.
[11:00:21.309] <TB1> INFO: scanning low vcal = 20
[11:00:27.088] <TB1> INFO: Test took 5779ms.
[11:00:27.092] <TB1> INFO: scanning low vcal = 30
[11:00:33.091] <TB1> INFO: Test took 5999ms.
[11:00:33.099] <TB1> INFO: scanning low vcal = 40
[11:00:40.611] <TB1> INFO: Test took 7512ms.
[11:00:40.669] <TB1> INFO: scanning low vcal = 50
[11:00:48.420] <TB1> INFO: Test took 7751ms.
[11:00:48.479] <TB1> INFO: scanning low vcal = 60
[11:00:55.805] <TB1> INFO: Test took 7326ms.
[11:00:55.861] <TB1> INFO: scanning low vcal = 70
[11:01:03.760] <TB1> INFO: Test took 7899ms.
[11:01:03.817] <TB1> INFO: scanning low vcal = 80
[11:01:11.611] <TB1> INFO: Test took 7794ms.
[11:01:11.667] <TB1> INFO: scanning low vcal = 90
[11:01:19.642] <TB1> INFO: Test took 7975ms.
[11:01:19.698] <TB1> INFO: scanning low vcal = 100
[11:01:27.734] <TB1> INFO: Test took 8036ms.
[11:01:27.790] <TB1> INFO: scanning low vcal = 110
[11:01:34.928] <TB1> INFO: Test took 7138ms.
[11:01:34.985] <TB1> INFO: scanning low vcal = 120
[11:01:42.767] <TB1> INFO: Test took 7782ms.
[11:01:42.827] <TB1> INFO: scanning low vcal = 130
[11:01:49.887] <TB1> INFO: Test took 7059ms.
[11:01:49.943] <TB1> INFO: scanning low vcal = 140
[11:01:56.983] <TB1> INFO: Test took 7040ms.
[11:01:57.043] <TB1> INFO: scanning low vcal = 150
[11:02:04.324] <TB1> INFO: Test took 7281ms.
[11:02:04.381] <TB1> INFO: scanning low vcal = 160
[11:02:12.388] <TB1> INFO: Test took 8007ms.
[11:02:12.444] <TB1> INFO: scanning low vcal = 170
[11:02:20.035] <TB1> INFO: Test took 7591ms.
[11:02:20.091] <TB1> INFO: scanning low vcal = 180
[11:02:27.933] <TB1> INFO: Test took 7842ms.
[11:02:27.992] <TB1> INFO: scanning low vcal = 190
[11:02:35.614] <TB1> INFO: Test took 7622ms.
[11:02:35.674] <TB1> INFO: scanning low vcal = 200
[11:02:43.502] <TB1> INFO: Test took 7828ms.
[11:02:43.560] <TB1> INFO: scanning low vcal = 210
[11:02:51.249] <TB1> INFO: Test took 7689ms.
[11:02:51.305] <TB1> INFO: scanning low vcal = 220
[11:02:59.056] <TB1> INFO: Test took 7751ms.
[11:02:59.114] <TB1> INFO: scanning low vcal = 230
[11:03:07.000] <TB1> INFO: Test took 7886ms.
[11:03:07.057] <TB1> INFO: scanning low vcal = 240
[11:03:14.564] <TB1> INFO: Test took 7507ms.
[11:03:14.623] <TB1> INFO: scanning low vcal = 250
[11:03:22.448] <TB1> INFO: Test took 7825ms.
[11:03:22.507] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[11:03:30.254] <TB1> INFO: Test took 7747ms.
[11:03:30.314] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[11:03:37.975] <TB1> INFO: Test took 7661ms.
[11:03:38.031] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[11:03:45.753] <TB1> INFO: Test took 7722ms.
[11:03:45.811] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[11:03:53.428] <TB1> INFO: Test took 7616ms.
[11:03:53.487] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[11:04:01.403] <TB1> INFO: Test took 7916ms.
[11:04:01.898] <TB1> INFO: PixTestGainPedestal::measure() done
[11:04:32.255] <TB1> INFO: PixTestGainPedestal::fit() done
[11:04:32.255] <TB1> INFO: non-linearity mean: 0.956 0.954 0.961 0.960 0.956 0.962 0.956 0.957 0.956 0.954 0.956 0.960 0.958 0.966 0.951 0.955
[11:04:32.255] <TB1> INFO: non-linearity RMS: 0.005 0.006 0.009 0.005 0.007 0.009 0.006 0.006 0.006 0.005 0.006 0.005 0.007 0.004 0.005 0.005
[11:04:32.256] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[11:04:32.275] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[11:04:32.293] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[11:04:32.312] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[11:04:32.330] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[11:04:32.349] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[11:04:32.368] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[11:04:32.387] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[11:04:32.405] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[11:04:32.424] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[11:04:32.443] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[11:04:32.461] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[11:04:32.479] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[11:04:32.497] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[11:04:32.515] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[11:04:32.533] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2061_FullQualification_2015-08-05_10h47m_1438764466//000_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[11:04:32.551] <TB1> INFO: PixTestGainPedestal::doTest() done, duration: 256 seconds
[11:04:32.557] <TB1> INFO: enter test to run
[11:04:32.557] <TB1> INFO: test: exit no parameter change
[11:04:33.006] <TB1> QUIET: Connection to board 153 closed.
[11:04:33.006] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master