[11:38:25.918] <TB3> INFO: *** Welcome to pxar ***
[11:38:25.918] <TB3> INFO: *** Today: 2015/08/06
[11:38:25.918] <TB3> INFO: readRocDacs: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C15.dat
[11:38:25.919] <TB3> INFO: readTbmDacs: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//tbmParameters_C0b.dat
[11:38:25.919] <TB3> INFO: readMaskFile: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//defaultMaskFile.dat
[11:38:25.919] <TB3> INFO: readTrimFile: /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters_C15.dat
[11:38:25.984] <TB3> INFO: clk: 4
[11:38:25.984] <TB3> INFO: ctr: 4
[11:38:25.984] <TB3> INFO: sda: 19
[11:38:25.984] <TB3> INFO: tin: 9
[11:38:25.984] <TB3> INFO: level: 15
[11:38:25.984] <TB3> INFO: triggerdelay: 0
[11:38:25.984] <TB3> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[11:38:25.984] <TB3> INFO: Log level: INFO
[11:38:26.006] <TB3> INFO: Found DTB DTB_WZ4I6J
[11:38:26.022] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[11:38:26.025] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 170
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WZ4I6J
MAC address: 40D8551180AA
Hostname: pixelDTB170
Comment:
------------------------------------------------------
[11:38:26.028] <TB3> INFO: RPC call hashes of host and DTB match: 447413373
[11:38:27.565] <TB3> INFO: DUT info:
[11:38:27.565] <TB3> INFO: The DUT currently contains the following objects:
[11:38:27.565] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[11:38:27.565] <TB3> INFO: TBM Core alpha (0): 7 registers set
[11:38:27.565] <TB3> INFO: TBM Core beta (1): 7 registers set
[11:38:27.565] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:38:27.565] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.565] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.566] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:38:27.967] <TB3> INFO: enter 'restricted' command line mode
[11:38:27.967] <TB3> INFO: enter test to run
[11:38:27.967] <TB3> INFO: test: pretest no parameter change
[11:38:27.967] <TB3> INFO: running: pretest
[11:38:27.976] <TB3> INFO: ######################################################################
[11:38:27.976] <TB3> INFO: PixTestPretest::doTest()
[11:38:27.976] <TB3> INFO: ######################################################################
[11:38:27.977] <TB3> INFO: ----------------------------------------------------------------------
[11:38:27.977] <TB3> INFO: PixTestPretest::programROC()
[11:38:27.977] <TB3> INFO: ----------------------------------------------------------------------
[11:38:45.993] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:38:45.993] <TB3> INFO: IA differences per ROC: 20.1 18.5 19.3 18.5 17.7 18.5 17.7 17.7 17.7 18.5 17.7 20.1 20.1 16.9 17.7 17.7
[11:38:46.050] <TB3> INFO: ----------------------------------------------------------------------
[11:38:46.050] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:38:46.050] <TB3> INFO: ----------------------------------------------------------------------
[11:39:05.611] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[11:39:05.614] <TB3> INFO: ----------------------------------------------------------------------
[11:39:05.614] <TB3> INFO: PixTestPretest::findWorkingPixel()
[11:39:05.614] <TB3> INFO: ----------------------------------------------------------------------
[11:39:14.632] <TB3> INFO: Test took 9013ms.
[11:39:14.938] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:39:14.959] <TB3> INFO: ----------------------------------------------------------------------
[11:39:14.959] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[11:39:14.959] <TB3> INFO: ----------------------------------------------------------------------
[11:39:23.922] <TB3> INFO: Test took 8957ms.
[11:39:24.223] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[11:39:24.223] <TB3> INFO: CalDel: 168 170 177 159 154 144 164 158 139 134 134 138 134 149 139 146
[11:39:24.223] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[11:39:24.227] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C0.dat
[11:39:24.227] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C1.dat
[11:39:24.228] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C2.dat
[11:39:24.228] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C3.dat
[11:39:24.228] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C4.dat
[11:39:24.228] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C5.dat
[11:39:24.228] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C6.dat
[11:39:24.228] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C7.dat
[11:39:24.228] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C8.dat
[11:39:24.228] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C9.dat
[11:39:24.229] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C10.dat
[11:39:24.229] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C11.dat
[11:39:24.229] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C12.dat
[11:39:24.229] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C13.dat
[11:39:24.229] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C14.dat
[11:39:24.230] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters_C15.dat
[11:39:24.230] <TB3> INFO: PixTestPretest::doTest() done, duration: 56 seconds
[11:39:24.341] <TB3> INFO: enter test to run
[11:39:24.341] <TB3> INFO: test: fulltest no parameter change
[11:39:24.341] <TB3> INFO: running: fulltest
[11:39:24.341] <TB3> INFO: ######################################################################
[11:39:24.342] <TB3> INFO: PixTestFullTest::doTest()
[11:39:24.342] <TB3> INFO: ######################################################################
[11:39:24.343] <TB3> INFO: ######################################################################
[11:39:24.343] <TB3> INFO: PixTestAlive::doTest()
[11:39:24.343] <TB3> INFO: ######################################################################
[11:39:24.344] <TB3> INFO: ----------------------------------------------------------------------
[11:39:24.344] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:39:24.344] <TB3> INFO: ----------------------------------------------------------------------
[11:39:27.915] <TB3> INFO: Test took 3570ms.
[11:39:27.933] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:28.143] <TB3> INFO: PixTestAlive::aliveTest() done
[11:39:28.143] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[11:39:28.145] <TB3> INFO: ----------------------------------------------------------------------
[11:39:28.145] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:39:28.145] <TB3> INFO: ----------------------------------------------------------------------
[11:39:31.009] <TB3> INFO: Test took 2862ms.
[11:39:31.012] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:31.013] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:39:31.224] <TB3> INFO: PixTestAlive::maskTest() done
[11:39:31.224] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:39:31.226] <TB3> INFO: ----------------------------------------------------------------------
[11:39:31.226] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:39:31.226] <TB3> INFO: ----------------------------------------------------------------------
[11:39:34.804] <TB3> INFO: Test took 3576ms.
[11:39:34.827] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:35.039] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[11:39:35.039] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:39:35.039] <TB3> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[11:39:35.053] <TB3> INFO: ######################################################################
[11:39:35.053] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:39:35.053] <TB3> INFO: ######################################################################
[11:39:35.054] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[11:39:35.071] <TB3> INFO: dacScan step from 0 .. 29
[11:39:57.637] <TB3> INFO: Test took 22566ms.
[11:39:57.674] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:39:57.674] <TB3> INFO: dacScan step from 30 .. 59
[11:40:22.921] <TB3> INFO: Test took 25247ms.
[11:40:23.057] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:23.080] <TB3> INFO: dacScan step from 60 .. 89
[11:40:54.467] <TB3> INFO: Test took 31387ms.
[11:40:54.751] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:40:54.819] <TB3> INFO: dacScan step from 90 .. 119
[11:41:26.297] <TB3> INFO: Test took 31478ms.
[11:41:26.577] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:41:26.672] <TB3> INFO: dacScan step from 120 .. 149
[11:41:54.204] <TB3> INFO: Test took 27532ms.
[11:41:54.407] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:18.521] <TB3> INFO: PixTestBBMap::doTest() done, duration: 163 seconds
[11:42:18.521] <TB3> INFO: number of dead bumps (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[11:42:18.521] <TB3> INFO: separation cut (per ROC): 67 66 90 81 94 77 69 75 72 95 83 102 94 74 86 93
[11:42:18.593] <TB3> INFO: ######################################################################
[11:42:18.593] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50
[11:42:18.593] <TB3> INFO: ######################################################################
[11:42:18.593] <TB3> INFO: ----------------------------------------------------------------------
[11:42:18.593] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[11:42:18.593] <TB3> INFO: ----------------------------------------------------------------------
[11:42:18.593] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[11:42:18.602] <TB3> INFO: dacScan step from 0 .. 3
[11:42:37.954] <TB3> INFO: Test took 19352ms.
[11:42:37.979] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:37.979] <TB3> INFO: dacScan step from 4 .. 7
[11:42:57.097] <TB3> INFO: Test took 19118ms.
[11:42:57.121] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:42:57.121] <TB3> INFO: dacScan step from 8 .. 11
[11:43:17.708] <TB3> INFO: Test took 20588ms.
[11:43:17.740] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:17.740] <TB3> INFO: dacScan step from 12 .. 15
[11:43:38.005] <TB3> INFO: Test took 20265ms.
[11:43:38.030] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:38.030] <TB3> INFO: dacScan step from 16 .. 19
[11:43:58.222] <TB3> INFO: Test took 20192ms.
[11:43:58.248] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:43:58.248] <TB3> INFO: dacScan step from 20 .. 23
[11:44:18.836] <TB3> INFO: Test took 20588ms.
[11:44:18.860] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:18.860] <TB3> INFO: dacScan step from 24 .. 27
[11:44:39.560] <TB3> INFO: Test took 20700ms.
[11:44:39.589] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:39.589] <TB3> INFO: dacScan step from 28 .. 31
[11:44:59.975] <TB3> INFO: Test took 20386ms.
[11:45:00.007] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:00.007] <TB3> INFO: dacScan step from 32 .. 35
[11:45:20.417] <TB3> INFO: Test took 20410ms.
[11:45:20.443] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:20.443] <TB3> INFO: dacScan step from 36 .. 39
[11:45:40.885] <TB3> INFO: Test took 20441ms.
[11:45:40.910] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:40.910] <TB3> INFO: dacScan step from 40 .. 43
[11:46:01.423] <TB3> INFO: Test took 20513ms.
[11:46:01.454] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:01.454] <TB3> INFO: dacScan step from 44 .. 47
[11:46:21.972] <TB3> INFO: Test took 20518ms.
[11:46:21.999] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:21.999] <TB3> INFO: dacScan step from 48 .. 51
[11:46:42.885] <TB3> INFO: Test took 20886ms.
[11:46:42.912] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:42.912] <TB3> INFO: dacScan step from 52 .. 55
[11:47:03.301] <TB3> INFO: Test took 20389ms.
[11:47:03.330] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:03.330] <TB3> INFO: dacScan step from 56 .. 59
[11:47:23.643] <TB3> INFO: Test took 20313ms.
[11:47:23.669] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:23.669] <TB3> INFO: dacScan step from 60 .. 63
[11:47:44.538] <TB3> INFO: Test took 20869ms.
[11:47:44.569] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:44.570] <TB3> INFO: dacScan step from 64 .. 67
[11:48:05.407] <TB3> INFO: Test took 20837ms.
[11:48:05.448] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:05.448] <TB3> INFO: dacScan step from 68 .. 71
[11:48:26.706] <TB3> INFO: Test took 21258ms.
[11:48:26.765] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:26.767] <TB3> INFO: dacScan step from 72 .. 75
[11:48:48.634] <TB3> INFO: Test took 21867ms.
[11:48:48.707] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:48:48.709] <TB3> INFO: dacScan step from 76 .. 79
[11:49:12.120] <TB3> INFO: Test took 23410ms.
[11:49:12.212] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:12.216] <TB3> INFO: dacScan step from 80 .. 83
[11:49:38.601] <TB3> INFO: Test took 26384ms.
[11:49:38.743] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:49:38.751] <TB3> INFO: dacScan step from 84 .. 87
[11:50:07.590] <TB3> INFO: Test took 28839ms.
[11:50:07.788] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:07.798] <TB3> INFO: dacScan step from 88 .. 91
[11:50:38.063] <TB3> INFO: Test took 30265ms.
[11:50:38.262] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:50:38.272] <TB3> INFO: dacScan step from 92 .. 95
[11:51:09.782] <TB3> INFO: Test took 31510ms.
[11:51:10.009] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:10.021] <TB3> INFO: dacScan step from 96 .. 99
[11:51:41.931] <TB3> INFO: Test took 31910ms.
[11:51:42.157] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:42.167] <TB3> INFO: dacScan step from 100 .. 103
[11:52:14.319] <TB3> INFO: Test took 32152ms.
[11:52:14.583] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:14.595] <TB3> INFO: dacScan step from 104 .. 107
[11:52:44.110] <TB3> INFO: Test took 29515ms.
[11:52:44.447] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:52:44.460] <TB3> INFO: dacScan step from 108 .. 111
[11:53:12.326] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[11:53:12.326] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[11:53:13.624] <TB3> INFO: Test took 29164ms.
[11:53:13.841] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:13.853] <TB3> INFO: dacScan step from 112 .. 115
[11:53:41.638] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[11:53:42.929] <TB3> INFO: Test took 29076ms.
[11:53:43.178] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:53:43.191] <TB3> INFO: dacScan step from 116 .. 119
[11:54:14.919] <TB3> INFO: Test took 31728ms.
[11:54:15.155] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:15.167] <TB3> INFO: dacScan step from 120 .. 123
[11:54:45.748] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[11:54:45.748] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (195) != TBM ID (196)
[11:54:45.748] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[11:54:45.748] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[11:54:45.748] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[11:54:47.233] <TB3> INFO: Test took 32066ms.
[11:54:47.467] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:54:47.479] <TB3> INFO: dacScan step from 124 .. 127
[11:55:19.483] <TB3> INFO: Test took 32004ms.
[11:55:19.741] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:19.754] <TB3> INFO: dacScan step from 128 .. 131
[11:55:51.919] <TB3> INFO: Test took 32165ms.
[11:55:52.151] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:55:52.162] <TB3> INFO: dacScan step from 132 .. 135
[11:56:24.377] <TB3> INFO: Test took 32215ms.
[11:56:24.643] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:24.655] <TB3> INFO: dacScan step from 136 .. 139
[11:56:56.699] <TB3> INFO: Test took 32044ms.
[11:56:56.922] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:56:56.934] <TB3> INFO: dacScan step from 140 .. 143
[11:57:29.012] <TB3> INFO: Test took 32078ms.
[11:57:29.231] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:57:29.242] <TB3> INFO: dacScan step from 144 .. 147
[11:58:01.317] <TB3> INFO: Test took 32075ms.
[11:58:01.546] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:01.557] <TB3> INFO: dacScan step from 148 .. 149
[11:58:19.002] <TB3> INFO: Test took 17445ms.
[11:58:19.113] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:58:19.119] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:20.713] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:22.269] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:23.921] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:25.526] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:27.104] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:28.901] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:30.514] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:32.079] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:33.618] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:35.084] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:36.579] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:38.069] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:39.589] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:41.180] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:42.724] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:58:44.269] <TB3> INFO: PixTestScurves::scurves() done
[11:58:44.269] <TB3> INFO: Vcal mean: 78.92 70.59 88.46 83.03 98.92 80.92 86.60 87.00 77.48 98.53 87.98 93.00 86.64 77.98 81.49 86.72
[11:58:44.269] <TB3> INFO: Vcal RMS: 5.17 4.62 5.91 5.08 5.88 4.99 4.92 5.49 4.21 5.99 5.00 5.47 5.81 4.12 4.07 5.57
[11:58:44.269] <TB3> INFO: PixTestScurves::fullTest() done, duration: 985 seconds
[11:58:44.351] <TB3> INFO: ######################################################################
[11:58:44.351] <TB3> INFO: PixTestTrim::doTest()
[11:58:44.351] <TB3> INFO: ######################################################################
[11:58:44.353] <TB3> INFO: ----------------------------------------------------------------------
[11:58:44.353] <TB3> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[11:58:44.353] <TB3> INFO: ----------------------------------------------------------------------
[11:58:44.433] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[11:58:44.433] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[11:58:44.441] <TB3> INFO: dacScan step from 0 .. 19
[11:59:00.201] <TB3> INFO: Test took 15760ms.
[11:59:00.223] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:00.223] <TB3> INFO: dacScan step from 20 .. 39
[11:59:16.047] <TB3> INFO: Test took 15824ms.
[11:59:16.073] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:16.073] <TB3> INFO: dacScan step from 40 .. 59
[11:59:31.974] <TB3> INFO: Test took 15901ms.
[11:59:31.996] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:31.996] <TB3> INFO: dacScan step from 60 .. 79
[11:59:47.861] <TB3> INFO: Test took 15865ms.
[11:59:47.885] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[11:59:47.885] <TB3> INFO: dacScan step from 80 .. 99
[12:00:04.987] <TB3> INFO: Test took 17102ms.
[12:00:05.069] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:05.078] <TB3> INFO: dacScan step from 100 .. 119
[12:00:25.666] <TB3> INFO: Test took 20587ms.
[12:00:25.824] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:25.852] <TB3> INFO: dacScan step from 120 .. 139
[12:00:45.527] <TB3> INFO: Test took 19675ms.
[12:00:45.666] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:00:45.690] <TB3> INFO: dacScan step from 140 .. 159
[12:01:02.686] <TB3> INFO: Test took 16996ms.
[12:01:02.749] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:25.137] <TB3> INFO: ROC 0 VthrComp = 80
[12:01:25.137] <TB3> INFO: ROC 1 VthrComp = 75
[12:01:25.137] <TB3> INFO: ROC 2 VthrComp = 92
[12:01:25.137] <TB3> INFO: ROC 3 VthrComp = 89
[12:01:25.137] <TB3> INFO: ROC 4 VthrComp = 101
[12:01:25.137] <TB3> INFO: ROC 5 VthrComp = 86
[12:01:25.137] <TB3> INFO: ROC 6 VthrComp = 88
[12:01:25.137] <TB3> INFO: ROC 7 VthrComp = 89
[12:01:25.137] <TB3> INFO: ROC 8 VthrComp = 80
[12:01:25.137] <TB3> INFO: ROC 9 VthrComp = 99
[12:01:25.137] <TB3> INFO: ROC 10 VthrComp = 93
[12:01:25.137] <TB3> INFO: ROC 11 VthrComp = 103
[12:01:25.137] <TB3> INFO: ROC 12 VthrComp = 93
[12:01:25.138] <TB3> INFO: ROC 13 VthrComp = 84
[12:01:25.138] <TB3> INFO: ROC 14 VthrComp = 89
[12:01:25.138] <TB3> INFO: ROC 15 VthrComp = 92
[12:01:25.138] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:01:25.138] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[12:01:25.146] <TB3> INFO: dacScan step from 0 .. 19
[12:01:40.920] <TB3> INFO: Test took 15774ms.
[12:01:40.943] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:40.943] <TB3> INFO: dacScan step from 20 .. 39
[12:01:57.064] <TB3> INFO: Test took 16121ms.
[12:01:57.093] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:01:57.096] <TB3> INFO: dacScan step from 40 .. 59
[12:02:17.034] <TB3> INFO: Test took 19938ms.
[12:02:17.217] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:17.255] <TB3> INFO: dacScan step from 60 .. 79
[12:02:38.839] <TB3> INFO: Test took 21584ms.
[12:02:39.004] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:02:39.051] <TB3> INFO: dacScan step from 80 .. 99
[12:03:00.717] <TB3> INFO: Test took 21666ms.
[12:03:00.920] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:00.969] <TB3> INFO: dacScan step from 100 .. 119
[12:03:22.648] <TB3> INFO: Test took 21679ms.
[12:03:22.809] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:22.852] <TB3> INFO: dacScan step from 120 .. 139
[12:03:44.571] <TB3> INFO: Test took 21719ms.
[12:03:44.730] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:03:44.774] <TB3> INFO: dacScan step from 140 .. 159
[12:04:06.302] <TB3> INFO: Test took 21528ms.
[12:04:06.457] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:04:32.240] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 61.3203 for pixel 5/76 mean/min/max = 46.5382/31.6075/61.469
[12:04:32.240] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 58.4631 for pixel 4/10 mean/min/max = 46.5851/34.6852/58.485
[12:04:32.240] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 59.7634 for pixel 21/78 mean/min/max = 45.7957/31.7948/59.7966
[12:04:32.241] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 58.2171 for pixel 14/78 mean/min/max = 45.4179/32.5729/58.263
[12:04:32.241] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 59.2464 for pixel 0/29 mean/min/max = 45.4173/31.5752/59.2594
[12:04:32.241] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 58.8153 for pixel 12/62 mean/min/max = 45.3914/31.8927/58.8901
[12:04:32.242] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 60.9519 for pixel 12/0 mean/min/max = 47.4904/34.0213/60.9594
[12:04:32.242] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 60.7019 for pixel 0/13 mean/min/max = 46.6623/32.5637/60.7609
[12:04:32.242] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 56.8604 for pixel 41/65 mean/min/max = 45.0932/33.2674/56.919
[12:04:32.243] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 61.2318 for pixel 10/7 mean/min/max = 46.416/31.4596/61.3724
[12:04:32.243] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 57.3629 for pixel 11/0 mean/min/max = 44.9228/32.1301/57.7154
[12:04:32.244] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 58.4047 for pixel 14/79 mean/min/max = 45.1733/31.881/58.4657
[12:04:32.244] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 59.2126 for pixel 0/79 mean/min/max = 45.3135/31.3746/59.2524
[12:04:32.244] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 56.4697 for pixel 51/67 mean/min/max = 44.521/32.4877/56.5544
[12:04:32.245] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 55.9503 for pixel 20/76 mean/min/max = 44.7378/33.4123/56.0633
[12:04:32.245] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 59.6911 for pixel 15/77 mean/min/max = 45.9007/31.9679/59.8335
[12:04:32.245] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:06:12.498] <TB3> INFO: Test took 100253ms.
[12:06:14.006] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:06:14.015] <TB3> INFO: dacScan step from 0 .. 19
[12:06:36.432] <TB3> INFO: Test took 22417ms.
[12:06:36.480] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:06:36.482] <TB3> INFO: dacScan step from 20 .. 39
[12:07:07.166] <TB3> INFO: Test took 30684ms.
[12:07:07.395] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:07.424] <TB3> INFO: dacScan step from 40 .. 59
[12:07:41.913] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[12:07:43.356] <TB3> INFO: Test took 35932ms.
[12:07:43.661] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:07:43.710] <TB3> INFO: dacScan step from 60 .. 79
[12:08:18.056] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:08:18.056] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:08:19.429] <TB3> INFO: Test took 35719ms.
[12:08:19.772] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:19.821] <TB3> INFO: dacScan step from 80 .. 99
[12:08:51.336] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[12:08:51.336] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (201) != TBM ID (202)
[12:08:51.336] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[12:08:51.336] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[12:08:51.336] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:08:52.556] <TB3> INFO: Test took 32735ms.
[12:08:52.893] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:08:52.947] <TB3> INFO: dacScan step from 100 .. 119
[12:09:27.393] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:09:27.393] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:09:28.836] <TB3> INFO: Test took 35889ms.
[12:09:29.153] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:09:29.205] <TB3> INFO: dacScan step from 120 .. 139
[12:10:01.116] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[12:10:02.311] <TB3> INFO: Test took 33106ms.
[12:10:02.592] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:02.641] <TB3> INFO: dacScan step from 140 .. 159
[12:10:36.931] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:10:36.931] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:10:38.305] <TB3> INFO: Test took 35664ms.
[12:10:38.643] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:10:38.683] <TB3> INFO: dacScan step from 160 .. 179
[12:11:14.548] <TB3> INFO: Test took 35864ms.
[12:11:14.834] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:11:14.884] <TB3> INFO: dacScan step from 180 .. 199
[12:11:50.319] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:11:50.319] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:11:51.703] <TB3> INFO: Test took 36819ms.
[12:11:52.002] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:16.743] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 0.024201 .. 255.000000
[12:12:16.818] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[12:12:16.826] <TB3> INFO: dacScan step from 0 .. 19
[12:12:30.224] <TB3> INFO: Test took 13398ms.
[12:12:30.243] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:30.243] <TB3> INFO: dacScan step from 20 .. 39
[12:12:44.793] <TB3> INFO: Test took 14550ms.
[12:12:44.870] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:12:44.886] <TB3> INFO: dacScan step from 40 .. 59
[12:13:03.617] <TB3> INFO: Test took 18731ms.
[12:13:03.767] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:03.812] <TB3> INFO: dacScan step from 60 .. 79
[12:13:22.811] <TB3> INFO: Test took 18999ms.
[12:13:22.953] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:22.993] <TB3> INFO: dacScan step from 80 .. 99
[12:13:40.808] <TB3> INFO: Test took 17815ms.
[12:13:40.968] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:41.018] <TB3> INFO: dacScan step from 100 .. 119
[12:13:58.595] <TB3> INFO: Test took 17577ms.
[12:13:58.737] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:13:58.775] <TB3> INFO: dacScan step from 120 .. 139
[12:14:17.796] <TB3> INFO: Test took 19021ms.
[12:14:17.958] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:18.012] <TB3> INFO: dacScan step from 140 .. 159
[12:14:36.988] <TB3> INFO: Test took 18976ms.
[12:14:37.144] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:37.183] <TB3> INFO: dacScan step from 160 .. 179
[12:14:56.200] <TB3> INFO: Test took 19017ms.
[12:14:56.349] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:14:56.404] <TB3> INFO: dacScan step from 180 .. 199
[12:15:15.891] <TB3> INFO: Test took 19487ms.
[12:15:16.028] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:16.064] <TB3> INFO: dacScan step from 200 .. 219
[12:15:34.933] <TB3> INFO: Test took 18868ms.
[12:15:35.078] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:35.127] <TB3> INFO: dacScan step from 220 .. 239
[12:15:54.047] <TB3> INFO: Test took 18920ms.
[12:15:54.200] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:15:54.241] <TB3> INFO: dacScan step from 240 .. 255
[12:16:10.047] <TB3> INFO: Test took 15806ms.
[12:16:10.157] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:42.626] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 12.323070 .. 76.340759
[12:16:42.702] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 2 .. 86 (20) hits flags = 16 (plus default)
[12:16:42.710] <TB3> INFO: dacScan step from 2 .. 21
[12:16:56.750] <TB3> INFO: Test took 14040ms.
[12:16:56.770] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:16:56.771] <TB3> INFO: dacScan step from 22 .. 41
[12:17:12.854] <TB3> INFO: Test took 16083ms.
[12:17:12.950] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:12.970] <TB3> INFO: dacScan step from 42 .. 61
[12:17:32.110] <TB3> INFO: Test took 19140ms.
[12:17:32.275] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:32.327] <TB3> INFO: dacScan step from 62 .. 81
[12:17:51.187] <TB3> INFO: Test took 18860ms.
[12:17:51.332] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:51.381] <TB3> INFO: dacScan step from 82 .. 86
[12:17:58.268] <TB3> INFO: Test took 6887ms.
[12:17:58.308] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:18.922] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 1.705857 .. 65.687090
[12:18:19.006] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 1 .. 75 (20) hits flags = 16 (plus default)
[12:18:19.014] <TB3> INFO: dacScan step from 1 .. 20
[12:18:33.140] <TB3> INFO: Test took 14126ms.
[12:18:33.165] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:33.165] <TB3> INFO: dacScan step from 21 .. 40
[12:18:48.950] <TB3> INFO: Test took 15785ms.
[12:18:49.041] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:49.060] <TB3> INFO: dacScan step from 41 .. 60
[12:19:08.126] <TB3> INFO: Test took 19066ms.
[12:19:08.275] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:08.325] <TB3> INFO: dacScan step from 61 .. 75
[12:19:23.105] <TB3> INFO: Test took 14780ms.
[12:19:23.214] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:42.037] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 1.353906 .. 55.393240
[12:19:42.118] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 65 (20) hits flags = 16 (plus default)
[12:19:42.126] <TB3> INFO: dacScan step from 1 .. 20
[12:19:56.344] <TB3> INFO: Test took 14218ms.
[12:19:56.368] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:56.368] <TB3> INFO: dacScan step from 21 .. 40
[12:20:12.032] <TB3> INFO: Test took 15664ms.
[12:20:12.123] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:12.140] <TB3> INFO: dacScan step from 41 .. 60
[12:20:31.126] <TB3> INFO: Test took 18985ms.
[12:20:31.271] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:31.319] <TB3> INFO: dacScan step from 61 .. 65
[12:20:38.069] <TB3> INFO: Test took 6750ms.
[12:20:38.111] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:55.094] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:20:55.094] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[12:20:55.102] <TB3> INFO: dacScan step from 15 .. 34
[12:21:19.788] <TB3> INFO: Test took 24686ms.
[12:21:19.861] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:19.872] <TB3> INFO: dacScan step from 35 .. 54
[12:21:55.447] <TB3> INFO: Test took 35575ms.
[12:21:55.736] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:55.784] <TB3> INFO: dacScan step from 55 .. 55
[12:22:00.303] <TB3> INFO: Test took 4519ms.
[12:22:00.324] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:15.016] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:22:15.017] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:22:15.017] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:22:15.017] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:22:15.017] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:22:15.017] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:22:15.018] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:22:15.018] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:22:15.018] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:22:15.018] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:22:15.019] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:22:15.019] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:22:15.019] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:22:15.020] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:22:15.020] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:22:15.020] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:22:15.020] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C0.dat
[12:22:15.029] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C1.dat
[12:22:15.035] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C2.dat
[12:22:15.043] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C3.dat
[12:22:15.051] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C4.dat
[12:22:15.058] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C5.dat
[12:22:15.064] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C6.dat
[12:22:15.070] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C7.dat
[12:22:15.076] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C8.dat
[12:22:15.082] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C9.dat
[12:22:15.088] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C10.dat
[12:22:15.094] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C11.dat
[12:22:15.101] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C12.dat
[12:22:15.107] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C13.dat
[12:22:15.113] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C14.dat
[12:22:15.119] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//trimParameters35_C15.dat
[12:22:15.125] <TB3> INFO: PixTestTrim::trimTest() done
[12:22:15.125] <TB3> INFO: vtrim: 103 96 108 117 113 111 113 101 94 139 119 117 115 98 99 119
[12:22:15.125] <TB3> INFO: vthrcomp: 80 75 92 89 101 86 88 89 80 99 93 103 93 84 89 92
[12:22:15.125] <TB3> INFO: vcal mean: 35.04 35.06 35.03 35.05 35.02 35.06 35.11 35.03 35.03 35.05 35.04 35.02 35.02 35.03 35.04 35.00
[12:22:15.125] <TB3> INFO: vcal RMS: 1.11 1.05 1.18 1.00 1.18 1.04 1.16 1.21 0.99 1.08 1.07 0.98 1.02 0.96 0.95 1.14
[12:22:15.125] <TB3> INFO: bits mean: 9.72 9.47 9.91 9.99 9.93 9.94 9.48 9.70 10.00 9.80 10.31 9.90 9.85 10.07 9.95 10.00
[12:22:15.125] <TB3> INFO: bits RMS: 2.58 2.31 2.50 2.40 2.52 2.52 2.36 2.51 2.35 2.55 2.33 2.56 2.65 2.47 2.35 2.44
[12:22:15.131] <TB3> INFO: ----------------------------------------------------------------------
[12:22:15.131] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[12:22:15.131] <TB3> INFO: ----------------------------------------------------------------------
[12:22:15.133] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[12:22:15.142] <TB3> INFO: dacScan step from 0 .. 19
[12:22:37.710] <TB3> INFO: Test took 22568ms.
[12:22:37.752] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:22:37.752] <TB3> INFO: dacScan step from 20 .. 39
[12:23:00.477] <TB3> INFO: Test took 22725ms.
[12:23:00.527] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:00.527] <TB3> INFO: dacScan step from 40 .. 59
[12:23:23.425] <TB3> INFO: Test took 22898ms.
[12:23:23.473] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:23.473] <TB3> INFO: dacScan step from 60 .. 79
[12:23:45.976] <TB3> INFO: Test took 22503ms.
[12:23:46.010] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:23:46.010] <TB3> INFO: dacScan step from 80 .. 99
[12:24:10.201] <TB3> INFO: Test took 24191ms.
[12:24:10.265] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:10.269] <TB3> INFO: dacScan step from 100 .. 119
[12:24:39.943] <TB3> INFO: Test took 29674ms.
[12:24:40.163] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:24:40.186] <TB3> INFO: dacScan step from 120 .. 139
[12:25:15.098] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)
[12:25:15.098] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (59) != TBM ID (60)
[12:25:15.098] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!
[12:25:15.098] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!
[12:25:15.098] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:25:16.374] <TB3> INFO: Test took 36188ms.
[12:25:16.667] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:16.706] <TB3> INFO: dacScan step from 140 .. 159
[12:25:48.720] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (77) != TBM ID (8)
[12:25:48.720] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[12:25:48.721] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (78)
[12:25:49.897] <TB3> INFO: Test took 33190ms.
[12:25:50.166] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:25:50.215] <TB3> INFO: dacScan step from 160 .. 179
[12:26:26.113] <TB3> INFO: Test took 35898ms.
[12:26:26.377] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:26:26.423] <TB3> INFO: dacScan step from 180 .. 199
[12:27:03.138] <TB3> INFO: Test took 36716ms.
[12:27:03.431] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:31.008] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 171 (20) hits flags = 16 (plus default)
[12:27:31.018] <TB3> INFO: dacScan step from 0 .. 19
[12:27:55.163] <TB3> INFO: Test took 24145ms.
[12:27:55.197] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:27:55.197] <TB3> INFO: dacScan step from 20 .. 39
[12:28:19.467] <TB3> INFO: Test took 24270ms.
[12:28:19.504] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:19.504] <TB3> INFO: dacScan step from 40 .. 59
[12:28:41.789] <TB3> INFO: Test took 22285ms.
[12:28:41.824] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:28:41.824] <TB3> INFO: dacScan step from 60 .. 79
[12:29:05.188] <TB3> INFO: Test took 23364ms.
[12:29:05.234] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:05.234] <TB3> INFO: dacScan step from 80 .. 99
[12:29:32.305] <TB3> INFO: Test took 27071ms.
[12:29:32.450] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:29:32.464] <TB3> INFO: dacScan step from 100 .. 119
[12:30:03.996] <TB3> INFO: Test took 31532ms.
[12:30:04.273] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:04.303] <TB3> INFO: dacScan step from 120 .. 139
[12:30:36.626] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:30:36.626] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:30:37.813] <TB3> INFO: Test took 33510ms.
[12:30:38.120] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:30:38.193] <TB3> INFO: dacScan step from 140 .. 159
[12:31:14.031] <TB3> INFO: Test took 35838ms.
[12:31:14.319] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:31:14.361] <TB3> INFO: dacScan step from 160 .. 171
[12:31:40.445] <TB3> INFO: Test took 26084ms.
[12:31:40.692] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:06.826] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 161 (20) hits flags = 16 (plus default)
[12:32:06.834] <TB3> INFO: dacScan step from 0 .. 19
[12:32:29.254] <TB3> INFO: Test took 22420ms.
[12:32:29.287] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:29.287] <TB3> INFO: dacScan step from 20 .. 39
[12:32:53.114] <TB3> INFO: Test took 23827ms.
[12:32:53.147] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:32:53.147] <TB3> INFO: dacScan step from 40 .. 59
[12:33:15.469] <TB3> INFO: Test took 22322ms.
[12:33:15.503] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:15.503] <TB3> INFO: dacScan step from 60 .. 79
[12:33:39.643] <TB3> INFO: Test took 24140ms.
[12:33:39.684] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:33:39.684] <TB3> INFO: dacScan step from 80 .. 99
[12:34:06.146] <TB3> INFO: Test took 26462ms.
[12:34:06.285] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:06.298] <TB3> INFO: dacScan step from 100 .. 119
[12:34:40.054] <TB3> INFO: Test took 33756ms.
[12:34:40.336] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:34:40.367] <TB3> INFO: dacScan step from 120 .. 139
[12:35:12.169] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:35:12.169] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:35:13.596] <TB3> INFO: Test took 33229ms.
[12:35:13.914] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:13.958] <TB3> INFO: dacScan step from 140 .. 159
[12:35:49.761] <TB3> INFO: Test took 35803ms.
[12:35:50.021] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:35:50.072] <TB3> INFO: dacScan step from 160 .. 161
[12:35:56.204] <TB3> INFO: Test took 6132ms.
[12:35:56.237] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:18.607] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 161 (20) hits flags = 16 (plus default)
[12:36:18.615] <TB3> INFO: dacScan step from 0 .. 19
[12:36:40.843] <TB3> INFO: Test took 22228ms.
[12:36:40.879] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:36:40.879] <TB3> INFO: dacScan step from 20 .. 39
[12:37:04.824] <TB3> INFO: Test took 23945ms.
[12:37:04.862] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:04.863] <TB3> INFO: dacScan step from 40 .. 59
[12:37:29.042] <TB3> INFO: Test took 24179ms.
[12:37:29.078] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:29.078] <TB3> INFO: dacScan step from 60 .. 79
[12:37:52.677] <TB3> INFO: Test took 23599ms.
[12:37:52.726] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:37:52.727] <TB3> INFO: dacScan step from 80 .. 99
[12:38:19.956] <TB3> INFO: Test took 27229ms.
[12:38:20.093] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:20.104] <TB3> INFO: dacScan step from 100 .. 119
[12:38:54.771] <TB3> INFO: Test took 34667ms.
[12:38:55.039] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:38:55.075] <TB3> INFO: dacScan step from 120 .. 139
[12:39:29.553] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)
[12:39:30.998] <TB3> INFO: Test took 35923ms.
[12:39:31.289] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:39:31.334] <TB3> INFO: dacScan step from 140 .. 159
[12:40:07.342] <TB3> INFO: Test took 36008ms.
[12:40:07.641] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:07.689] <TB3> INFO: dacScan step from 160 .. 161
[12:40:13.701] <TB3> INFO: Test took 6011ms.
[12:40:13.733] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:35.795] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 160 (20) hits flags = 16 (plus default)
[12:40:35.804] <TB3> INFO: dacScan step from 0 .. 19
[12:40:59.729] <TB3> INFO: Test took 23925ms.
[12:40:59.766] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:40:59.766] <TB3> INFO: dacScan step from 20 .. 39
[12:41:22.012] <TB3> INFO: Test took 22246ms.
[12:41:22.046] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:22.046] <TB3> INFO: dacScan step from 40 .. 59
[12:41:46.056] <TB3> INFO: Test took 24010ms.
[12:41:46.093] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:41:46.093] <TB3> INFO: dacScan step from 60 .. 79
[12:42:10.391] <TB3> INFO: Test took 24298ms.
[12:42:10.432] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:10.432] <TB3> INFO: dacScan step from 80 .. 99
[12:42:37.612] <TB3> INFO: Test took 27180ms.
[12:42:37.747] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:42:37.762] <TB3> INFO: dacScan step from 100 .. 119
[12:43:12.615] <TB3> INFO: Test took 34853ms.
[12:43:12.894] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:12.929] <TB3> INFO: dacScan step from 120 .. 139
[12:43:45.993] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)
[12:43:45.993] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!
[12:43:47.271] <TB3> INFO: Test took 34342ms.
[12:43:47.563] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:43:47.614] <TB3> INFO: dacScan step from 140 .. 159
[12:44:22.573] <TB3> INFO: Test took 34959ms.
[12:44:22.891] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:22.939] <TB3> INFO: dacScan step from 160 .. 160
[12:44:27.441] <TB3> INFO: Test took 4501ms.
[12:44:27.461] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:51.399] <TB3> INFO: PixTestTrim::trimBitTest() done
[12:44:51.400] <TB3> INFO: PixTestTrim::doTest() done, duration: 2767 seconds
[12:44:52.077] <TB3> INFO: ######################################################################
[12:44:52.077] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:44:52.077] <TB3> INFO: ######################################################################
[12:44:55.688] <TB3> INFO: Test took 3609ms.
[12:44:55.716] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:44:59.514] <TB3> INFO: Test took 3602ms.
[12:44:59.582] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:03.207] <TB3> INFO: Test took 3615ms.
[12:45:03.272] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[12:45:03.278] <TB3> INFO: The DUT currently contains the following objects:
[12:45:03.278] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:03.278] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:03.278] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:03.278] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:03.278] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:03.279] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.394] <TB3> INFO: Test took 1115ms.
[12:45:04.395] <TB3> INFO: The DUT currently contains the following objects:
[12:45:04.395] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:04.395] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:04.395] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:04.395] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:04.395] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:04.395] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.507] <TB3> INFO: Test took 1112ms.
[12:45:05.508] <TB3> INFO: The DUT currently contains the following objects:
[12:45:05.508] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:05.508] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:05.508] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:05.508] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:05.508] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.508] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:05.509] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.621] <TB3> INFO: Test took 1112ms.
[12:45:06.623] <TB3> INFO: The DUT currently contains the following objects:
[12:45:06.628] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:06.628] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:06.628] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:06.628] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:06.628] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:06.628] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.735] <TB3> INFO: Test took 1107ms.
[12:45:07.736] <TB3> INFO: The DUT currently contains the following objects:
[12:45:07.737] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:07.737] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:07.737] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:07.737] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:07.737] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:07.737] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.850] <TB3> INFO: Test took 1113ms.
[12:45:08.851] <TB3> INFO: The DUT currently contains the following objects:
[12:45:08.851] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:08.851] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:08.851] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:08.851] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:08.851] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.851] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.851] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.851] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.851] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.851] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.851] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.851] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.851] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.851] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.852] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.852] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.852] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.852] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.852] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:08.852] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.964] <TB3> INFO: Test took 1112ms.
[12:45:09.965] <TB3> INFO: The DUT currently contains the following objects:
[12:45:09.965] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:09.965] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:09.965] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:09.965] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:09.965] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.965] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.966] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:09.966] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.078] <TB3> INFO: Test took 1112ms.
[12:45:11.079] <TB3> INFO: The DUT currently contains the following objects:
[12:45:11.079] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:11.079] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:11.079] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:11.079] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:11.079] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.079] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.079] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.079] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.079] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.079] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.079] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.079] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.079] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.079] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.080] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.080] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.080] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.080] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.080] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:11.080] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.191] <TB3> INFO: Test took 1111ms.
[12:45:12.193] <TB3> INFO: The DUT currently contains the following objects:
[12:45:12.193] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:12.193] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:12.193] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:12.193] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:12.193] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.193] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.193] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.193] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:12.194] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.306] <TB3> INFO: Test took 1112ms.
[12:45:13.307] <TB3> INFO: The DUT currently contains the following objects:
[12:45:13.307] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:13.307] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:13.307] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:13.307] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:13.307] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:13.308] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.420] <TB3> INFO: Test took 1112ms.
[12:45:14.422] <TB3> INFO: The DUT currently contains the following objects:
[12:45:14.422] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:14.422] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:14.422] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:14.422] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:14.422] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:14.422] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.534] <TB3> INFO: Test took 1112ms.
[12:45:15.535] <TB3> INFO: The DUT currently contains the following objects:
[12:45:15.535] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:15.535] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:15.535] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:15.536] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:15.536] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:15.536] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.649] <TB3> INFO: Test took 1113ms.
[12:45:16.651] <TB3> INFO: The DUT currently contains the following objects:
[12:45:16.651] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:16.651] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:16.651] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:16.651] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:16.651] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.651] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.651] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.651] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.651] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.651] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.651] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.651] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.651] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.651] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.652] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.652] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.652] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.652] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.652] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:16.652] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.760] <TB3> INFO: Test took 1108ms.
[12:45:17.761] <TB3> INFO: The DUT currently contains the following objects:
[12:45:17.761] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:17.761] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:17.761] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:17.761] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:17.761] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:17.761] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.867] <TB3> INFO: Test took 1106ms.
[12:45:18.868] <TB3> INFO: The DUT currently contains the following objects:
[12:45:18.868] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:18.868] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:18.868] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:18.868] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:18.868] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.868] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.869] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.869] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:18.869] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.976] <TB3> INFO: Test took 1107ms.
[12:45:19.977] <TB3> INFO: The DUT currently contains the following objects:
[12:45:19.977] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[12:45:19.977] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:45:19.977] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:45:19.977] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[12:45:19.977] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:19.978] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[12:45:21.084] <TB3> INFO: Test took 1106ms.
[12:45:21.087] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:49:20.713] <TB3> INFO: Test took 239626ms.
[12:49:22.302] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:17.202] <TB3> INFO: Test took 234900ms.
[12:53:18.974] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:18.981] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:18.988] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:18.995] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:53:19.002] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:53:19.008] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[12:53:19.016] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[12:53:19.023] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.029] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.036] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.043] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.050] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.057] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.063] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.070] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.077] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:53:19.084] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.090] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.097] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.104] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.111] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:19.134] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C0.dat
[12:53:19.135] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C1.dat
[12:53:19.135] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C2.dat
[12:53:19.135] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C3.dat
[12:53:19.135] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C4.dat
[12:53:19.135] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C5.dat
[12:53:19.135] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C6.dat
[12:53:19.135] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C7.dat
[12:53:19.136] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C8.dat
[12:53:19.136] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C9.dat
[12:53:19.136] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C10.dat
[12:53:19.136] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C11.dat
[12:53:19.136] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C12.dat
[12:53:19.136] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C13.dat
[12:53:19.137] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C14.dat
[12:53:19.137] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//dacParameters35_C15.dat
[12:53:22.594] <TB3> INFO: Test took 3456ms.
[12:53:26.371] <TB3> INFO: Test took 3513ms.
[12:53:30.096] <TB3> INFO: Test took 3451ms.
[12:53:30.363] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:31.284] <TB3> INFO: Test took 921ms.
[12:53:31.286] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:32.392] <TB3> INFO: Test took 1106ms.
[12:53:32.393] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:33.500] <TB3> INFO: Test took 1107ms.
[12:53:33.501] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:34.608] <TB3> INFO: Test took 1107ms.
[12:53:34.610] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:35.716] <TB3> INFO: Test took 1106ms.
[12:53:35.718] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:36.825] <TB3> INFO: Test took 1107ms.
[12:53:36.826] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:37.933] <TB3> INFO: Test took 1107ms.
[12:53:37.935] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:39.042] <TB3> INFO: Test took 1107ms.
[12:53:39.044] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:40.150] <TB3> INFO: Test took 1106ms.
[12:53:40.152] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:41.267] <TB3> INFO: Test took 1115ms.
[12:53:41.269] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:42.377] <TB3> INFO: Test took 1108ms.
[12:53:42.379] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:43.485] <TB3> INFO: Test took 1106ms.
[12:53:43.488] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:44.595] <TB3> INFO: Test took 1107ms.
[12:53:44.597] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:45.703] <TB3> INFO: Test took 1106ms.
[12:53:45.704] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:46.813] <TB3> INFO: Test took 1109ms.
[12:53:46.815] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:47.922] <TB3> INFO: Test took 1108ms.
[12:53:47.931] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:49.037] <TB3> INFO: Test took 1106ms.
[12:53:49.039] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:50.145] <TB3> INFO: Test took 1106ms.
[12:53:50.146] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:51.252] <TB3> INFO: Test took 1106ms.
[12:53:51.254] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:52.360] <TB3> INFO: Test took 1106ms.
[12:53:52.362] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:53.468] <TB3> INFO: Test took 1106ms.
[12:53:53.470] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:54.575] <TB3> INFO: Test took 1105ms.
[12:53:54.577] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:55.682] <TB3> INFO: Test took 1105ms.
[12:53:55.684] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:56.791] <TB3> INFO: Test took 1107ms.
[12:53:56.794] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:57.900] <TB3> INFO: Test took 1107ms.
[12:53:57.902] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:59.008] <TB3> INFO: Test took 1106ms.
[12:53:59.010] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:00.123] <TB3> INFO: Test took 1113ms.
[12:54:00.126] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:01.239] <TB3> INFO: Test took 1114ms.
[12:54:01.242] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:02.355] <TB3> INFO: Test took 1113ms.
[12:54:02.358] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:03.471] <TB3> INFO: Test took 1113ms.
[12:54:03.474] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:04.587] <TB3> INFO: Test took 1114ms.
[12:54:04.590] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:05.702] <TB3> INFO: Test took 1113ms.
[12:54:06.241] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 554 seconds
[12:54:06.241] <TB3> INFO: PH scale (per ROC): 80 79 93 89 84 78 80 90 80 82 85 81 80 91 87 88
[12:54:06.241] <TB3> INFO: PH offset (per ROC): 165 146 144 146 153 154 153 157 150 159 160 157 144 147 164 150
[12:54:06.432] <TB3> INFO: ######################################################################
[12:54:06.432] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:54:06.432] <TB3> INFO: ######################################################################
[12:54:06.443] <TB3> INFO: scanning low vcal = 10
[12:54:10.425] <TB3> INFO: Test took 3982ms.
[12:54:10.430] <TB3> INFO: scanning low vcal = 20
[12:54:14.417] <TB3> INFO: Test took 3987ms.
[12:54:14.422] <TB3> INFO: scanning low vcal = 30
[12:54:18.403] <TB3> INFO: Test took 3981ms.
[12:54:18.416] <TB3> INFO: scanning low vcal = 40
[12:54:22.931] <TB3> INFO: Test took 4515ms.
[12:54:22.999] <TB3> INFO: scanning low vcal = 50
[12:54:27.512] <TB3> INFO: Test took 4513ms.
[12:54:27.577] <TB3> INFO: scanning low vcal = 60
[12:54:32.071] <TB3> INFO: Test took 4494ms.
[12:54:32.136] <TB3> INFO: scanning low vcal = 70
[12:54:36.592] <TB3> INFO: Test took 4456ms.
[12:54:36.661] <TB3> INFO: scanning low vcal = 80
[12:54:41.142] <TB3> INFO: Test took 4481ms.
[12:54:41.205] <TB3> INFO: scanning low vcal = 90
[12:54:45.699] <TB3> INFO: Test took 4494ms.
[12:54:45.758] <TB3> INFO: scanning low vcal = 100
[12:54:50.271] <TB3> INFO: Test took 4513ms.
[12:54:50.342] <TB3> INFO: scanning low vcal = 110
[12:54:54.853] <TB3> INFO: Test took 4511ms.
[12:54:54.916] <TB3> INFO: scanning low vcal = 120
[12:54:59.430] <TB3> INFO: Test took 4514ms.
[12:54:59.489] <TB3> INFO: scanning low vcal = 130
[12:55:04.008] <TB3> INFO: Test took 4519ms.
[12:55:04.067] <TB3> INFO: scanning low vcal = 140
[12:55:08.589] <TB3> INFO: Test took 4522ms.
[12:55:08.652] <TB3> INFO: scanning low vcal = 150
[12:55:13.127] <TB3> INFO: Test took 4475ms.
[12:55:13.201] <TB3> INFO: scanning low vcal = 160
[12:55:17.720] <TB3> INFO: Test took 4519ms.
[12:55:17.778] <TB3> INFO: scanning low vcal = 170
[12:55:22.299] <TB3> INFO: Test took 4521ms.
[12:55:22.361] <TB3> INFO: scanning low vcal = 180
[12:55:26.883] <TB3> INFO: Test took 4522ms.
[12:55:26.946] <TB3> INFO: scanning low vcal = 190
[12:55:31.552] <TB3> INFO: Test took 4606ms.
[12:55:31.618] <TB3> INFO: scanning low vcal = 200
[12:55:36.135] <TB3> INFO: Test took 4517ms.
[12:55:36.195] <TB3> INFO: scanning low vcal = 210
[12:55:40.705] <TB3> INFO: Test took 4510ms.
[12:55:40.768] <TB3> INFO: scanning low vcal = 220
[12:55:45.249] <TB3> INFO: Test took 4481ms.
[12:55:45.333] <TB3> INFO: scanning low vcal = 230
[12:55:49.869] <TB3> INFO: Test took 4536ms.
[12:55:49.937] <TB3> INFO: scanning low vcal = 240
[12:55:54.422] <TB3> INFO: Test took 4484ms.
[12:55:54.498] <TB3> INFO: scanning low vcal = 250
[12:55:59.022] <TB3> INFO: Test took 4524ms.
[12:55:59.084] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[12:56:03.668] <TB3> INFO: Test took 4584ms.
[12:56:03.738] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[12:56:08.295] <TB3> INFO: Test took 4557ms.
[12:56:08.368] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[12:56:12.925] <TB3> INFO: Test took 4557ms.
[12:56:12.992] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[12:56:17.556] <TB3> INFO: Test took 4564ms.
[12:56:17.625] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:56:22.212] <TB3> INFO: Test took 4587ms.
[12:56:22.758] <TB3> INFO: PixTestGainPedestal::measure() done
[12:56:54.946] <TB3> INFO: PixTestGainPedestal::fit() done
[12:56:54.946] <TB3> INFO: non-linearity mean: 0.955 0.955 0.962 0.956 0.957 0.954 0.959 0.964 0.951 0.955 0.961 0.959 0.955 0.948 0.951 0.952
[12:56:54.946] <TB3> INFO: non-linearity RMS: 0.007 0.005 0.004 0.006 0.005 0.007 0.006 0.007 0.007 0.005 0.005 0.005 0.006 0.007 0.007 0.007
[12:56:54.946] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[12:56:54.971] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[12:56:54.995] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[12:56:55.015] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[12:56:55.038] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[12:56:55.061] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[12:56:55.079] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[12:56:55.098] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[12:56:55.116] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[12:56:55.135] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[12:56:55.154] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[12:56:55.172] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[12:56:55.192] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[12:56:55.217] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[12:56:55.236] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[12:56:55.255] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2067_FullQualification_2015-08-06_10h09m_1438848555//002_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[12:56:55.280] <TB3> INFO: PixTestGainPedestal::doTest() done, duration: 168 seconds
[12:56:55.287] <TB3> INFO: enter test to run
[12:56:55.288] <TB3> INFO: test: exit no parameter change
[12:56:55.736] <TB3> QUIET: Connection to board 170 closed.
[12:56:55.752] <TB3> INFO: pXar: this is the end, my friend