Test Date: 2015-08-21 12:37
Analysis date: 2016-05-26 02:14
Logfile
LogfileView
[15:26:55.599] <TB3> INFO: *** Welcome to pxar ***
[15:26:55.599] <TB3> INFO: *** Today: 2015/08/21
[15:26:55.599] <TB3> INFO: readRocDacs: /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C15.dat
[15:26:55.601] <TB3> INFO: readTbmDacs: /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//tbmParameters_C0b.dat
[15:26:55.601] <TB3> INFO: readMaskFile: /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//defaultMaskFile.dat
[15:26:55.601] <TB3> INFO: readTrimFile: /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters_C15.dat
[15:26:55.687] <TB3> INFO: clk: 4
[15:26:55.687] <TB3> INFO: ctr: 4
[15:26:55.687] <TB3> INFO: sda: 19
[15:26:55.687] <TB3> INFO: tin: 9
[15:26:55.687] <TB3> INFO: level: 15
[15:26:55.687] <TB3> INFO: triggerdelay: 0
[15:26:55.687] <TB3> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[15:26:55.687] <TB3> INFO: Log level: INFO
[15:26:55.695] <TB3> INFO: Found DTB DTB_WZ4I6J
[15:26:55.705] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[15:26:55.708] <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:
------------------------------------------------------
[15:26:55.710] <TB3> INFO: RPC call hashes of host and DTB match: 447413373
[15:26:57.239] <TB3> INFO: DUT info:
[15:26:57.239] <TB3> INFO: The DUT currently contains the following objects:
[15:26:57.239] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[15:26:57.240] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:26:57.240] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:26:57.240] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:26:57.240] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.240] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:26:57.641] <TB3> INFO: enter 'restricted' command line mode
[15:26:57.641] <TB3> INFO: enter test to run
[15:26:57.642] <TB3> INFO: test: pretest no parameter change
[15:26:57.642] <TB3> INFO: running: pretest
[15:26:57.649] <TB3> INFO: ######################################################################
[15:26:57.649] <TB3> INFO: PixTestPretest::doTest()
[15:26:57.649] <TB3> INFO: ######################################################################
[15:26:57.651] <TB3> INFO: ----------------------------------------------------------------------
[15:26:57.651] <TB3> INFO: PixTestPretest::programROC()
[15:26:57.651] <TB3> INFO: ----------------------------------------------------------------------
[15:27:15.668] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[15:27:15.668] <TB3> INFO: IA differences per ROC: 19.3 18.5 19.3 16.9 17.7 20.1 17.7 16.9 18.5 19.3 20.1 17.7 17.7 20.1 18.5 19.3
[15:27:15.735] <TB3> INFO: ----------------------------------------------------------------------
[15:27:15.735] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[15:27:15.735] <TB3> INFO: ----------------------------------------------------------------------
[15:27:21.814] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 382.7 mA = 23.9187 mA/ROC
[15:27:21.817] <TB3> INFO: ----------------------------------------------------------------------
[15:27:21.817] <TB3> INFO: PixTestPretest::findWorkingPixel()
[15:27:21.817] <TB3> INFO: ----------------------------------------------------------------------
[15:27:30.048] <TB3> INFO: Test took 8225ms.
[15:27:30.349] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[15:27:30.380] <TB3> INFO: ----------------------------------------------------------------------
[15:27:30.380] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[15:27:30.380] <TB3> INFO: ----------------------------------------------------------------------
[15:27:38.547] <TB3> INFO: Test took 8161ms.
[15:27:38.855] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[15:27:38.855] <TB3> INFO: CalDel: 131 146 131 121 146 127 144 142 146 132 144 139 139 141 141 144
[15:27:38.855] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[15:27:38.859] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C0.dat
[15:27:38.859] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C1.dat
[15:27:38.860] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C2.dat
[15:27:38.860] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C3.dat
[15:27:38.860] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C4.dat
[15:27:38.860] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C5.dat
[15:27:38.860] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C6.dat
[15:27:38.860] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C7.dat
[15:27:38.861] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C8.dat
[15:27:38.861] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C9.dat
[15:27:38.861] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C10.dat
[15:27:38.861] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C11.dat
[15:27:38.862] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C12.dat
[15:27:38.862] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C13.dat
[15:27:38.862] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C14.dat
[15:27:38.862] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters_C15.dat
[15:27:38.862] <TB3> INFO: PixTestPretest::doTest() done, duration: 41 seconds
[15:27:38.955] <TB3> INFO: enter test to run
[15:27:38.955] <TB3> INFO: test: fulltest no parameter change
[15:27:38.955] <TB3> INFO: running: fulltest
[15:27:38.955] <TB3> INFO: ######################################################################
[15:27:38.955] <TB3> INFO: PixTestFullTest::doTest()
[15:27:38.955] <TB3> INFO: ######################################################################
[15:27:38.956] <TB3> INFO: ######################################################################
[15:27:38.956] <TB3> INFO: PixTestAlive::doTest()
[15:27:38.956] <TB3> INFO: ######################################################################
[15:27:38.958] <TB3> INFO: ----------------------------------------------------------------------
[15:27:38.958] <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)
[15:27:38.958] <TB3> INFO: ----------------------------------------------------------------------
[15:27:42.354] <TB3> INFO: Test took 3395ms.
[15:27:42.379] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:42.609] <TB3> INFO: PixTestAlive::aliveTest() done
[15:27:42.609] <TB3> INFO: number of dead pixels (per ROC): 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:27:42.611] <TB3> INFO: ----------------------------------------------------------------------
[15:27:42.611] <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)
[15:27:42.611] <TB3> INFO: ----------------------------------------------------------------------
[15:27:45.306] <TB3> INFO: Test took 2693ms.
[15:27:45.310] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:45.311] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[15:27:45.544] <TB3> INFO: PixTestAlive::maskTest() done
[15:27:45.544] <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
[15:27:45.546] <TB3> INFO: ----------------------------------------------------------------------
[15:27:45.546] <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)
[15:27:45.546] <TB3> INFO: ----------------------------------------------------------------------
[15:27:48.969] <TB3> INFO: Test took 3421ms.
[15:27:48.993] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:27:49.226] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[15:27:49.226] <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
[15:27:49.226] <TB3> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[15:27:49.239] <TB3> INFO: ######################################################################
[15:27:49.239] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[15:27:49.239] <TB3> INFO: ######################################################################
[15:27:49.242] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[15:27:49.254] <TB3> INFO: dacScan step from 0 .. 29
[15:28:10.460] <TB3> INFO: Test took 21207ms.
[15:28:10.495] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:10.495] <TB3> INFO: dacScan step from 30 .. 59
[15:28:33.165] <TB3> INFO: Test took 22670ms.
[15:28:33.268] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:28:33.280] <TB3> INFO: dacScan step from 60 .. 89
[15:29:02.102] <TB3> INFO: Test took 28822ms.
[15:29:02.367] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:02.443] <TB3> INFO: dacScan step from 90 .. 119
[15:29:31.412] <TB3> INFO: Test took 28969ms.
[15:29:31.668] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:29:31.750] <TB3> INFO: dacScan step from 120 .. 149
[15:29:55.758] <TB3> INFO: Test took 24008ms.
[15:29:56.025] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:20.198] <TB3> INFO: PixTestBBMap::doTest() done, duration: 150 seconds
[15:30:20.198] <TB3> INFO: number of dead bumps (per ROC): 0 1 0 0 0 0 0 0 0 0 2 0 0 0 0 0
[15:30:20.198] <TB3> INFO: separation cut (per ROC): 85 93 89 101 85 92 88 86 84 75 80 88 94 90 93 83
[15:30:20.271] <TB3> INFO: ######################################################################
[15:30:20.271] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50
[15:30:20.271] <TB3> INFO: ######################################################################
[15:30:20.271] <TB3> INFO: ----------------------------------------------------------------------
[15:30:20.271] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[15:30:20.271] <TB3> INFO: ----------------------------------------------------------------------
[15:30:20.271] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[15:30:20.279] <TB3> INFO: dacScan step from 0 .. 3
[15:30:38.986] <TB3> INFO: Test took 18707ms.
[15:30:39.012] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:39.012] <TB3> INFO: dacScan step from 4 .. 7
[15:30:57.972] <TB3> INFO: Test took 18960ms.
[15:30:58.000] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:58.000] <TB3> INFO: dacScan step from 8 .. 11
[15:31:15.334] <TB3> INFO: Test took 17334ms.
[15:31:15.367] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:15.367] <TB3> INFO: dacScan step from 12 .. 15
[15:31:34.358] <TB3> INFO: Test took 18991ms.
[15:31:34.387] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:34.387] <TB3> INFO: dacScan step from 16 .. 19
[15:31:53.304] <TB3> INFO: Test took 18917ms.
[15:31:53.332] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:53.332] <TB3> INFO: dacScan step from 20 .. 23
[15:32:12.281] <TB3> INFO: Test took 18949ms.
[15:32:12.309] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:12.309] <TB3> INFO: dacScan step from 24 .. 27
[15:32:31.204] <TB3> INFO: Test took 18894ms.
[15:32:31.231] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:31.231] <TB3> INFO: dacScan step from 28 .. 31
[15:32:50.025] <TB3> INFO: Test took 18794ms.
[15:32:50.052] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:50.052] <TB3> INFO: dacScan step from 32 .. 35
[15:33:09.002] <TB3> INFO: Test took 18950ms.
[15:33:09.036] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:09.036] <TB3> INFO: dacScan step from 36 .. 39
[15:33:27.855] <TB3> INFO: Test took 18819ms.
[15:33:27.881] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:27.881] <TB3> INFO: dacScan step from 40 .. 43
[15:33:46.759] <TB3> INFO: Test took 18878ms.
[15:33:46.789] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:46.789] <TB3> INFO: dacScan step from 44 .. 47
[15:34:05.590] <TB3> INFO: Test took 18801ms.
[15:34:05.619] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:05.619] <TB3> INFO: dacScan step from 48 .. 51
[15:34:24.437] <TB3> INFO: Test took 18818ms.
[15:34:24.467] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:24.468] <TB3> INFO: dacScan step from 52 .. 55
[15:34:43.260] <TB3> INFO: Test took 18792ms.
[15:34:43.287] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:43.287] <TB3> INFO: dacScan step from 56 .. 59
[15:35:02.082] <TB3> INFO: Test took 18795ms.
[15:35:02.115] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:02.115] <TB3> INFO: dacScan step from 60 .. 63
[15:35:20.981] <TB3> INFO: Test took 18866ms.
[15:35:21.011] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:21.011] <TB3> INFO: dacScan step from 64 .. 67
[15:35:39.957] <TB3> INFO: Test took 18946ms.
[15:35:39.987] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:39.987] <TB3> INFO: dacScan step from 68 .. 71
[15:35:58.971] <TB3> INFO: Test took 18984ms.
[15:35:59.000] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:59.000] <TB3> INFO: dacScan step from 72 .. 75
[15:36:18.022] <TB3> INFO: Test took 19022ms.
[15:36:18.054] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:18.055] <TB3> INFO: dacScan step from 76 .. 79
[15:36:37.344] <TB3> INFO: Test took 19289ms.
[15:36:37.388] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:37.389] <TB3> INFO: dacScan step from 80 .. 83
[15:36:58.366] <TB3> INFO: Test took 20977ms.
[15:36:58.455] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:36:58.460] <TB3> INFO: dacScan step from 84 .. 87
[15:37:21.317] <TB3> INFO: Test took 22857ms.
[15:37:21.442] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:21.449] <TB3> INFO: dacScan step from 88 .. 91
[15:37:45.880] <TB3> INFO: Test took 24431ms.
[15:37:46.046] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:37:46.053] <TB3> INFO: dacScan step from 92 .. 95
[15:38:12.702] <TB3> INFO: Test took 26649ms.
[15:38:12.889] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:12.897] <TB3> INFO: dacScan step from 96 .. 99
[15:38:40.003] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (44) != TBM ID (8)

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

[15:38:40.016] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (45)

[15:38:40.563] <TB3> INFO: Test took 27666ms.
[15:38:40.808] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:38:40.817] <TB3> INFO: dacScan step from 100 .. 103
[15:39:09.108] <TB3> INFO: Test took 28291ms.
[15:39:09.349] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:09.360] <TB3> INFO: dacScan step from 104 .. 107
[15:39:37.192] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[15:39:37.193] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (90) != TBM ID (91)

[15:39:37.193] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[15:39:37.193] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[15:39:37.193] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:39:38.336] <TB3> INFO: Test took 28976ms.
[15:39:38.568] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:39:38.578] <TB3> INFO: dacScan step from 108 .. 111
[15:40:07.705] <TB3> INFO: Test took 29126ms.
[15:40:07.925] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:40:07.936] <TB3> INFO: dacScan step from 112 .. 115
[15:40:36.015] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[15:40:37.331] <TB3> INFO: Test took 29395ms.
[15:40:37.573] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:40:37.586] <TB3> INFO: dacScan step from 116 .. 119
[15:41:05.746] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:41:05.746] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:41:07.053] <TB3> INFO: Test took 29467ms.
[15:41:07.298] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:07.311] <TB3> INFO: dacScan step from 120 .. 123
[15:41:35.266] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:41:35.266] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:41:36.523] <TB3> INFO: Test took 29212ms.
[15:41:36.754] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:36.766] <TB3> INFO: dacScan step from 124 .. 127
[15:42:04.357] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (195) != TBM ID (8)

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

[15:42:04.357] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (9) != TBM ID (196)

[15:42:05.627] <TB3> INFO: Test took 28860ms.
[15:42:05.868] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:05.881] <TB3> INFO: dacScan step from 128 .. 131
[15:42:34.769] <TB3> INFO: Test took 28888ms.
[15:42:35.009] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:35.022] <TB3> INFO: dacScan step from 132 .. 135
[15:43:04.043] <TB3> INFO: Test took 29021ms.
[15:43:04.277] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:04.288] <TB3> INFO: dacScan step from 136 .. 139
[15:43:33.488] <TB3> INFO: Test took 29200ms.
[15:43:33.717] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:33.729] <TB3> INFO: dacScan step from 140 .. 143
[15:44:02.647] <TB3> INFO: Test took 28918ms.
[15:44:02.881] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:02.893] <TB3> INFO: dacScan step from 144 .. 147
[15:44:32.043] <TB3> INFO: Test took 29150ms.
[15:44:32.339] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:32.357] <TB3> INFO: dacScan step from 148 .. 149
[15:44:48.301] <TB3> INFO: Test took 15944ms.
[15:44:48.426] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:44:48.433] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:44:50.063] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:44:51.612] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:44:53.171] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:44:54.648] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:44:56.046] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:44:57.533] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:44:59.016] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:45:00.541] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:45:02.062] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:45:03.631] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:45:05.111] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:45:06.599] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:45:08.090] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:45:09.587] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:45:10.993] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:45:12.404] <TB3> INFO: PixTestScurves::scurves() done
[15:45:12.404] <TB3> INFO: Vcal mean: 89.06 100.01 90.87 112.85 87.93 89.25 101.88 91.24 92.80 79.93 84.71 86.54 98.57 95.23 93.77 91.44
[15:45:12.404] <TB3> INFO: Vcal RMS: 5.84 6.43 5.88 5.77 5.00 5.05 5.53 5.01 5.49 4.00 5.07 4.80 5.91 5.91 5.12 6.36
[15:45:12.404] <TB3> INFO: PixTestScurves::fullTest() done, duration: 892 seconds
[15:45:12.491] <TB3> INFO: ######################################################################
[15:45:12.491] <TB3> INFO: PixTestTrim::doTest()
[15:45:12.491] <TB3> INFO: ######################################################################
[15:45:12.492] <TB3> INFO: ----------------------------------------------------------------------
[15:45:12.493] <TB3> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[15:45:12.493] <TB3> INFO: ----------------------------------------------------------------------
[15:45:12.592] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[15:45:12.592] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[15:45:12.600] <TB3> INFO: dacScan step from 0 .. 19
[15:45:27.572] <TB3> INFO: Test took 14972ms.
[15:45:27.593] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:27.593] <TB3> INFO: dacScan step from 20 .. 39
[15:45:42.682] <TB3> INFO: Test took 15089ms.
[15:45:42.702] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:42.702] <TB3> INFO: dacScan step from 40 .. 59
[15:45:57.009] <TB3> INFO: Test took 14307ms.
[15:45:57.036] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:45:57.036] <TB3> INFO: dacScan step from 60 .. 79
[15:46:11.610] <TB3> INFO: Test took 14574ms.
[15:46:11.633] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:46:11.633] <TB3> INFO: dacScan step from 80 .. 99
[15:46:27.128] <TB3> INFO: Test took 15495ms.
[15:46:27.179] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:46:27.185] <TB3> INFO: dacScan step from 100 .. 119
[15:46:46.120] <TB3> INFO: Test took 18935ms.
[15:46:46.283] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:46:46.316] <TB3> INFO: dacScan step from 120 .. 139
[15:47:05.104] <TB3> INFO: Test took 18788ms.
[15:47:05.258] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:05.287] <TB3> INFO: dacScan step from 140 .. 159
[15:47:21.178] <TB3> INFO: Test took 15891ms.
[15:47:21.246] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:47:45.202] <TB3> INFO: ROC 0 VthrComp = 92
[15:47:45.202] <TB3> INFO: ROC 1 VthrComp = 96
[15:47:45.202] <TB3> INFO: ROC 2 VthrComp = 93
[15:47:45.202] <TB3> INFO: ROC 3 VthrComp = 106
[15:47:45.202] <TB3> INFO: ROC 4 VthrComp = 89
[15:47:45.203] <TB3> INFO: ROC 5 VthrComp = 96
[15:47:45.203] <TB3> INFO: ROC 6 VthrComp = 93
[15:47:45.203] <TB3> INFO: ROC 7 VthrComp = 94
[15:47:45.203] <TB3> INFO: ROC 8 VthrComp = 92
[15:47:45.203] <TB3> INFO: ROC 9 VthrComp = 82
[15:47:45.203] <TB3> INFO: ROC 10 VthrComp = 87
[15:47:45.204] <TB3> INFO: ROC 11 VthrComp = 89
[15:47:45.204] <TB3> INFO: ROC 12 VthrComp = 95
[15:47:45.204] <TB3> INFO: ROC 13 VthrComp = 94
[15:47:45.204] <TB3> INFO: ROC 14 VthrComp = 96
[15:47:45.204] <TB3> INFO: ROC 15 VthrComp = 91
[15:47:45.204] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[15:47:45.204] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[15:47:45.215] <TB3> INFO: dacScan step from 0 .. 19
[15:48:00.269] <TB3> INFO: Test took 15054ms.
[15:48:00.295] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:00.295] <TB3> INFO: dacScan step from 20 .. 39
[15:48:14.701] <TB3> INFO: Test took 14406ms.
[15:48:14.736] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:14.739] <TB3> INFO: dacScan step from 40 .. 59
[15:48:32.555] <TB3> INFO: Test took 17816ms.
[15:48:32.785] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:32.864] <TB3> INFO: dacScan step from 60 .. 79
[15:48:52.162] <TB3> INFO: Test took 19298ms.
[15:48:52.392] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:52.451] <TB3> INFO: dacScan step from 80 .. 99
[15:49:11.325] <TB3> INFO: Test took 18873ms.
[15:49:11.488] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:11.547] <TB3> INFO: dacScan step from 100 .. 119
[15:49:30.404] <TB3> INFO: Test took 18856ms.
[15:49:30.569] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:30.628] <TB3> INFO: dacScan step from 120 .. 139
[15:49:50.575] <TB3> INFO: Test took 19947ms.
[15:49:50.743] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:50.799] <TB3> INFO: dacScan step from 140 .. 159
[15:50:10.907] <TB3> INFO: Test took 20108ms.
[15:50:11.070] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:50:36.544] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 59.0284 for pixel 6/54 mean/min/max = 46.1186/32.9988/59.2384
[15:50:36.544] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 63.7666 for pixel 0/1 mean/min/max = 47.6787/31.4752/63.8822
[15:50:36.545] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 60.9561 for pixel 0/59 mean/min/max = 46.8475/32.4511/61.2438
[15:50:36.545] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 66.8451 for pixel 24/74 mean/min/max = 50.4556/33.8286/67.0826
[15:50:36.546] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 58.4348 for pixel 16/3 mean/min/max = 46.4229/34.3307/58.5151
[15:50:36.546] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 56.4184 for pixel 20/79 mean/min/max = 44.3862/32.268/56.5045
[15:50:36.546] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 64.1099 for pixel 19/12 mean/min/max = 48.7771/33.3719/64.1822
[15:50:36.546] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 58.0855 for pixel 0/62 mean/min/max = 45.2469/32.308/58.1858
[15:50:36.547] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 60.0261 for pixel 23/71 mean/min/max = 46.738/33.4205/60.0554
[15:50:36.547] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 56.8373 for pixel 0/45 mean/min/max = 45.0741/33.3104/56.8379
[15:50:36.547] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 58.213 for pixel 36/79 mean/min/max = 44.9818/31.7426/58.221
[15:50:36.547] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 58.3256 for pixel 2/9 mean/min/max = 46.4028/34.4469/58.3586
[15:50:36.548] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 61.0687 for pixel 0/41 mean/min/max = 46.7119/32.2191/61.2047
[15:50:36.548] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 62.2655 for pixel 0/9 mean/min/max = 47.4522/32.3963/62.508
[15:50:36.548] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 58.5832 for pixel 0/32 mean/min/max = 45.3324/32.0128/58.6521
[15:50:36.549] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 62.84 for pixel 7/77 mean/min/max = 47.1713/31.4843/62.8584
[15:50:36.549] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:52:07.747] <TB3> INFO: Test took 91198ms.
[15:52:09.190] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[15:52:09.199] <TB3> INFO: dacScan step from 0 .. 19
[15:52:32.096] <TB3> INFO: Test took 22897ms.
[15:52:32.147] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:32.150] <TB3> INFO: dacScan step from 20 .. 39
[15:53:00.418] <TB3> INFO: Test took 28268ms.
[15:53:00.661] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:00.695] <TB3> INFO: dacScan step from 40 .. 59
[15:53:32.328] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:53:32.328] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:53:33.540] <TB3> INFO: Test took 32845ms.
[15:53:33.817] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:33.874] <TB3> INFO: dacScan step from 60 .. 79
[15:54:05.603] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:54:05.603] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:54:06.881] <TB3> INFO: Test took 33007ms.
[15:54:07.180] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:07.234] <TB3> INFO: dacScan step from 80 .. 99
[15:54:40.067] <TB3> INFO: Test took 32833ms.
[15:54:40.352] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:40.404] <TB3> INFO: dacScan step from 100 .. 119
[15:55:12.267] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:55:12.267] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:55:13.571] <TB3> INFO: Test took 33167ms.
[15:55:13.850] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:13.903] <TB3> INFO: dacScan step from 120 .. 139
[15:55:45.763] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:55:45.763] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:55:46.969] <TB3> INFO: Test took 33066ms.
[15:55:47.236] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:47.288] <TB3> INFO: dacScan step from 140 .. 159
[15:56:19.040] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[15:56:19.040] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[15:56:20.299] <TB3> INFO: Test took 33011ms.
[15:56:20.578] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:20.633] <TB3> INFO: dacScan step from 160 .. 179
[15:56:52.383] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[15:56:53.653] <TB3> INFO: Test took 33020ms.
[15:56:53.929] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:53.983] <TB3> INFO: dacScan step from 180 .. 199
[15:57:27.846] <TB3> INFO: Test took 33863ms.
[15:57:28.116] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:53.390] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 0.054610 .. 255.000000
[15:57:53.471] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[15:57:53.479] <TB3> INFO: dacScan step from 0 .. 19
[15:58:06.922] <TB3> INFO: Test took 13443ms.
[15:58:06.949] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:58:06.949] <TB3> INFO: dacScan step from 20 .. 39
[15:58:21.821] <TB3> INFO: Test took 14872ms.
[15:58:21.909] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:58:21.925] <TB3> INFO: dacScan step from 40 .. 59
[15:58:38.380] <TB3> INFO: Test took 16455ms.
[15:58:38.528] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:58:38.580] <TB3> INFO: dacScan step from 60 .. 79
[15:58:55.241] <TB3> INFO: Test took 16661ms.
[15:58:55.380] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:58:55.432] <TB3> INFO: dacScan step from 80 .. 99
[15:59:12.031] <TB3> INFO: Test took 16599ms.
[15:59:12.258] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:12.346] <TB3> INFO: dacScan step from 100 .. 119
[15:59:28.777] <TB3> INFO: Test took 16430ms.
[15:59:28.918] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:28.974] <TB3> INFO: dacScan step from 120 .. 139
[15:59:46.523] <TB3> INFO: Test took 17549ms.
[15:59:46.675] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[15:59:46.731] <TB3> INFO: dacScan step from 140 .. 159
[16:00:04.126] <TB3> INFO: Test took 17395ms.
[16:00:04.272] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:04.324] <TB3> INFO: dacScan step from 160 .. 179
[16:00:22.204] <TB3> INFO: Test took 17880ms.
[16:00:22.352] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:22.407] <TB3> INFO: dacScan step from 180 .. 199
[16:00:40.848] <TB3> INFO: Test took 18441ms.
[16:00:40.989] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:41.045] <TB3> INFO: dacScan step from 200 .. 219
[16:00:58.632] <TB3> INFO: Test took 17587ms.
[16:00:58.779] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:00:58.834] <TB3> INFO: dacScan step from 220 .. 239
[16:01:16.445] <TB3> INFO: Test took 17611ms.
[16:01:16.589] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:01:16.647] <TB3> INFO: dacScan step from 240 .. 255
[16:01:31.219] <TB3> INFO: Test took 14572ms.
[16:01:31.337] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:04.033] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 15.793260 .. 44.115774
[16:02:04.123] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 5 .. 54 (20) hits flags = 16 (plus default)
[16:02:04.133] <TB3> INFO: dacScan step from 5 .. 24
[16:02:17.638] <TB3> INFO: Test took 13505ms.
[16:02:17.660] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:17.660] <TB3> INFO: dacScan step from 25 .. 44
[16:02:33.359] <TB3> INFO: Test took 15699ms.
[16:02:33.469] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:33.498] <TB3> INFO: dacScan step from 45 .. 54
[16:02:43.159] <TB3> INFO: Test took 9661ms.
[16:02:43.229] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:02:59.445] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 17.658186 .. 40.478308
[16:02:59.524] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 7 .. 50 (20) hits flags = 16 (plus default)
[16:02:59.532] <TB3> INFO: dacScan step from 7 .. 26
[16:03:12.918] <TB3> INFO: Test took 13386ms.
[16:03:12.935] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:12.936] <TB3> INFO: dacScan step from 27 .. 46
[16:03:28.031] <TB3> INFO: Test took 15095ms.
[16:03:28.151] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:28.187] <TB3> INFO: dacScan step from 47 .. 50
[16:03:33.854] <TB3> INFO: Test took 5667ms.
[16:03:33.883] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:03:49.830] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 2.089641 .. 38.521815
[16:03:49.907] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 2 .. 48 (20) hits flags = 16 (plus default)
[16:03:49.915] <TB3> INFO: dacScan step from 2 .. 21
[16:04:03.014] <TB3> INFO: Test took 13099ms.
[16:04:03.038] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:03.039] <TB3> INFO: dacScan step from 22 .. 41
[16:04:17.996] <TB3> INFO: Test took 14957ms.
[16:04:18.090] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:18.120] <TB3> INFO: dacScan step from 42 .. 48
[16:04:26.145] <TB3> INFO: Test took 8025ms.
[16:04:26.206] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:04:42.101] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[16:04:42.101] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[16:04:42.109] <TB3> INFO: dacScan step from 15 .. 34
[16:05:03.845] <TB3> INFO: Test took 21736ms.
[16:05:03.912] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:03.924] <TB3> INFO: dacScan step from 35 .. 54
[16:05:33.169] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[16:05:33.169] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[16:05:33.730] <TB3> INFO: Test took 29806ms.
[16:05:34.032] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:34.092] <TB3> INFO: dacScan step from 55 .. 55
[16:05:38.415] <TB3> INFO: Test took 4323ms.
[16:05:38.435] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:05:53.383] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C0.dat
[16:05:53.383] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C1.dat
[16:05:53.383] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C2.dat
[16:05:53.383] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C3.dat
[16:05:53.383] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C4.dat
[16:05:53.383] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C5.dat
[16:05:53.384] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C6.dat
[16:05:53.384] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C7.dat
[16:05:53.384] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C8.dat
[16:05:53.384] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C9.dat
[16:05:53.384] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C10.dat
[16:05:53.384] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C11.dat
[16:05:53.384] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C12.dat
[16:05:53.384] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C13.dat
[16:05:53.384] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C14.dat
[16:05:53.385] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C15.dat
[16:05:53.385] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C0.dat
[16:05:53.391] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C1.dat
[16:05:53.397] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C2.dat
[16:05:53.403] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C3.dat
[16:05:53.409] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C4.dat
[16:05:53.416] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C5.dat
[16:05:53.422] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C6.dat
[16:05:53.428] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C7.dat
[16:05:53.434] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C8.dat
[16:05:53.441] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C9.dat
[16:05:53.450] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C10.dat
[16:05:53.458] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C11.dat
[16:05:53.466] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C12.dat
[16:05:53.474] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C13.dat
[16:05:53.480] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C14.dat
[16:05:53.486] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//trimParameters35_C15.dat
[16:05:53.492] <TB3> INFO: PixTestTrim::trimTest() done
[16:05:53.492] <TB3> INFO: vtrim: 107 119 114 139 103 114 121 95 112 93 102 114 98 108 104 123
[16:05:53.492] <TB3> INFO: vthrcomp: 92 96 93 106 89 96 93 94 92 82 87 89 95 94 96 91
[16:05:53.492] <TB3> INFO: vcal mean: 35.10 35.09 35.13 35.13 35.09 35.09 35.13 35.10 35.14 35.03 35.07 35.11 35.11 35.02 35.08 35.06
[16:05:53.492] <TB3> INFO: vcal RMS: 1.06 1.28 1.05 1.34 1.05 0.98 1.21 1.05 1.10 1.01 1.08 1.05 1.22 1.07 1.08 1.41
[16:05:53.492] <TB3> INFO: bits mean: 9.55 9.54 9.37 9.26 9.78 10.07 9.55 9.53 9.77 9.70 10.23 9.80 9.62 8.82 10.02 10.03
[16:05:53.492] <TB3> INFO: bits RMS: 2.57 2.63 2.62 2.24 2.25 2.47 2.33 2.68 2.33 2.52 2.43 2.27 2.55 2.80 2.56 2.44
[16:05:53.499] <TB3> INFO: ----------------------------------------------------------------------
[16:05:53.499] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[16:05:53.499] <TB3> INFO: ----------------------------------------------------------------------
[16:05:53.502] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[16:05:53.511] <TB3> INFO: dacScan step from 0 .. 19
[16:06:14.741] <TB3> INFO: Test took 21230ms.
[16:06:14.779] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:14.779] <TB3> INFO: dacScan step from 20 .. 39
[16:06:36.649] <TB3> INFO: Test took 21870ms.
[16:06:36.684] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:36.684] <TB3> INFO: dacScan step from 40 .. 59
[16:06:57.810] <TB3> INFO: Test took 21126ms.
[16:06:57.844] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:57.844] <TB3> INFO: dacScan step from 60 .. 79
[16:07:20.413] <TB3> INFO: Test took 22569ms.
[16:07:20.447] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:20.447] <TB3> INFO: dacScan step from 80 .. 99
[16:07:41.768] <TB3> INFO: Test took 21321ms.
[16:07:41.805] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:41.805] <TB3> INFO: dacScan step from 100 .. 119
[16:08:06.177] <TB3> INFO: Test took 24371ms.
[16:08:06.315] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:08:06.331] <TB3> INFO: dacScan step from 120 .. 139
[16:08:37.726] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[16:08:37.727] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[16:08:38.377] <TB3> INFO: Test took 32046ms.
[16:08:38.658] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:08:38.692] <TB3> INFO: dacScan step from 140 .. 159
[16:09:08.542] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[16:09:09.605] <TB3> INFO: Test took 30912ms.
[16:09:09.886] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:09.940] <TB3> INFO: dacScan step from 160 .. 179
[16:09:43.081] <TB3> INFO: Test took 33141ms.
[16:09:43.355] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:43.407] <TB3> INFO: dacScan step from 180 .. 199
[16:10:17.213] <TB3> INFO: Test took 33806ms.
[16:10:17.493] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:46.919] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 180 (20) hits flags = 16 (plus default)
[16:10:46.931] <TB3> INFO: dacScan step from 0 .. 19
[16:11:09.670] <TB3> INFO: Test took 22739ms.
[16:11:09.708] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:09.708] <TB3> INFO: dacScan step from 20 .. 39
[16:11:32.221] <TB3> INFO: Test took 22513ms.
[16:11:32.254] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:32.254] <TB3> INFO: dacScan step from 40 .. 59
[16:11:53.315] <TB3> INFO: Test took 21061ms.
[16:11:53.352] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:11:53.352] <TB3> INFO: dacScan step from 60 .. 79
[16:12:15.994] <TB3> INFO: Test took 22642ms.
[16:12:16.030] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:12:16.030] <TB3> INFO: dacScan step from 80 .. 99
[16:12:38.991] <TB3> INFO: Test took 22961ms.
[16:12:39.052] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:12:39.056] <TB3> INFO: dacScan step from 100 .. 119
[16:13:08.191] <TB3> INFO: Test took 29135ms.
[16:13:08.416] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:13:08.444] <TB3> INFO: dacScan step from 120 .. 139
[16:13:41.232] <TB3> INFO: Test took 32788ms.
[16:13:41.506] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:13:41.553] <TB3> INFO: dacScan step from 140 .. 159
[16:14:11.065] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[16:14:11.065] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (68) != TBM ID (69)

[16:14:11.065] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[16:14:11.065] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[16:14:11.065] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[16:14:12.193] <TB3> INFO: Test took 30640ms.
[16:14:12.497] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:14:12.554] <TB3> INFO: dacScan step from 160 .. 179
[16:14:45.592] <TB3> INFO: Test took 33038ms.
[16:14:45.934] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:14:45.994] <TB3> INFO: dacScan step from 180 .. 180
[16:14:50.396] <TB3> INFO: Test took 4402ms.
[16:14:50.416] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:15:15.865] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 165 (20) hits flags = 16 (plus default)
[16:15:15.874] <TB3> INFO: dacScan step from 0 .. 19
[16:15:38.585] <TB3> INFO: Test took 22708ms.
[16:15:38.618] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:15:38.618] <TB3> INFO: dacScan step from 20 .. 39
[16:16:01.155] <TB3> INFO: Test took 22537ms.
[16:16:01.193] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:01.193] <TB3> INFO: dacScan step from 40 .. 59
[16:16:22.596] <TB3> INFO: Test took 21403ms.
[16:16:22.642] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:22.642] <TB3> INFO: dacScan step from 60 .. 79
[16:16:45.119] <TB3> INFO: Test took 22477ms.
[16:16:45.155] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:45.155] <TB3> INFO: dacScan step from 80 .. 99
[16:17:08.255] <TB3> INFO: Test took 23100ms.
[16:17:08.314] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:17:08.318] <TB3> INFO: dacScan step from 100 .. 119
[16:17:37.493] <TB3> INFO: Test took 29175ms.
[16:17:37.733] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:17:37.758] <TB3> INFO: dacScan step from 120 .. 139
[16:18:08.898] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[16:18:09.994] <TB3> INFO: Test took 32236ms.
[16:18:10.341] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:18:10.397] <TB3> INFO: dacScan step from 140 .. 159
[16:18:39.893] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[16:18:39.894] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[16:18:40.994] <TB3> INFO: Test took 30597ms.
[16:18:41.275] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:18:41.345] <TB3> INFO: dacScan step from 160 .. 165
[16:18:52.452] <TB3> INFO: Test took 11107ms.
[16:18:52.539] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:19:18.365] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 166 (20) hits flags = 16 (plus default)
[16:19:18.376] <TB3> INFO: dacScan step from 0 .. 19
[16:19:39.651] <TB3> INFO: Test took 21275ms.
[16:19:39.691] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:19:39.691] <TB3> INFO: dacScan step from 20 .. 39
[16:20:02.207] <TB3> INFO: Test took 22516ms.
[16:20:02.246] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:02.246] <TB3> INFO: dacScan step from 40 .. 59
[16:20:23.477] <TB3> INFO: Test took 21231ms.
[16:20:23.512] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:23.512] <TB3> INFO: dacScan step from 60 .. 79
[16:20:45.587] <TB3> INFO: Test took 22075ms.
[16:20:45.627] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:20:45.627] <TB3> INFO: dacScan step from 80 .. 99
[16:21:08.645] <TB3> INFO: Test took 23018ms.
[16:21:08.712] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:08.716] <TB3> INFO: dacScan step from 100 .. 119
[16:21:38.034] <TB3> INFO: Test took 29318ms.
[16:21:38.272] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:21:38.295] <TB3> INFO: dacScan step from 120 .. 139
[16:22:09.930] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[16:22:09.930] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (162) != TBM ID (163)

[16:22:09.930] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[16:22:09.930] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[16:22:09.930] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[16:22:11.106] <TB3> INFO: Test took 32810ms.
[16:22:11.396] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:11.445] <TB3> INFO: dacScan step from 140 .. 159
[16:22:40.830] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[16:22:40.830] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[16:22:42.065] <TB3> INFO: Test took 30620ms.
[16:22:42.329] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:42.389] <TB3> INFO: dacScan step from 160 .. 166
[16:22:55.831] <TB3> INFO: Test took 13442ms.
[16:22:55.928] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:19.820] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 166 (20) hits flags = 16 (plus default)
[16:23:19.829] <TB3> INFO: dacScan step from 0 .. 19
[16:23:42.450] <TB3> INFO: Test took 22621ms.
[16:23:42.489] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:42.489] <TB3> INFO: dacScan step from 20 .. 39
[16:24:05.111] <TB3> INFO: Test took 22622ms.
[16:24:05.148] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:05.148] <TB3> INFO: dacScan step from 40 .. 59
[16:24:26.516] <TB3> INFO: Test took 21368ms.
[16:24:26.551] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:26.551] <TB3> INFO: dacScan step from 60 .. 79
[16:24:48.787] <TB3> INFO: Test took 22236ms.
[16:24:48.829] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:48.829] <TB3> INFO: dacScan step from 80 .. 99
[16:25:11.883] <TB3> INFO: Test took 23054ms.
[16:25:11.946] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:11.950] <TB3> INFO: dacScan step from 100 .. 119
[16:25:41.247] <TB3> INFO: Test took 29297ms.
[16:25:41.489] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:41.517] <TB3> INFO: dacScan step from 120 .. 139
[16:26:12.789] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

[16:26:12.789] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[16:26:13.802] <TB3> INFO: Test took 32285ms.
[16:26:14.077] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:26:14.128] <TB3> INFO: dacScan step from 140 .. 159
[16:26:44.952] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[16:26:44.952] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (68) != TBM ID (69)

[16:26:44.952] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[16:26:44.952] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

[16:26:44.952] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 15 readouts!

[16:26:46.251] <TB3> INFO: Test took 32123ms.
[16:26:46.541] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:26:46.591] <TB3> INFO: dacScan step from 160 .. 166
[16:26:59.895] <TB3> INFO: Test took 13304ms.
[16:27:00.001] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:27:24.623] <TB3> INFO: PixTestTrim::trimBitTest() done
[16:27:24.625] <TB3> INFO: PixTestTrim::doTest() done, duration: 2532 seconds
[16:27:25.363] <TB3> INFO: ######################################################################
[16:27:25.363] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[16:27:25.363] <TB3> INFO: ######################################################################
[16:27:28.835] <TB3> INFO: Test took 3471ms.
[16:27:28.860] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:27:32.472] <TB3> INFO: Test took 3414ms.
[16:27:32.541] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:27:35.992] <TB3> INFO: Test took 3441ms.
[16:27:36.061] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[16:27:36.068] <TB3> INFO: The DUT currently contains the following objects:
[16:27:36.068] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:36.068] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:36.068] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:36.068] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:36.068] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:36.068] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.177] <TB3> INFO: Test took 1109ms.
[16:27:37.178] <TB3> INFO: The DUT currently contains the following objects:
[16:27:37.178] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:37.178] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:37.178] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:37.178] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:37.178] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:37.178] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.286] <TB3> INFO: Test took 1108ms.
[16:27:38.287] <TB3> INFO: The DUT currently contains the following objects:
[16:27:38.287] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:38.287] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:38.288] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:38.288] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:38.288] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:38.288] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.397] <TB3> INFO: Test took 1109ms.
[16:27:39.398] <TB3> INFO: The DUT currently contains the following objects:
[16:27:39.398] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:39.398] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:39.398] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:39.398] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:39.398] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.398] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.399] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.399] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.399] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:39.399] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.505] <TB3> INFO: Test took 1106ms.
[16:27:40.506] <TB3> INFO: The DUT currently contains the following objects:
[16:27:40.506] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:40.506] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:40.506] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:40.506] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:40.506] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.506] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.506] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.506] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.506] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.506] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.506] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.506] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.507] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.507] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.507] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.507] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.507] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.507] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.507] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:40.507] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.615] <TB3> INFO: Test took 1108ms.
[16:27:41.617] <TB3> INFO: The DUT currently contains the following objects:
[16:27:41.617] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:41.617] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:41.617] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:41.617] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:41.617] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:41.617] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.724] <TB3> INFO: Test took 1107ms.
[16:27:42.725] <TB3> INFO: The DUT currently contains the following objects:
[16:27:42.725] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:42.725] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:42.725] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:42.725] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:42.725] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:42.725] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.834] <TB3> INFO: Test took 1108ms.
[16:27:43.836] <TB3> INFO: The DUT currently contains the following objects:
[16:27:43.836] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:43.836] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:43.836] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:43.836] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:43.836] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:43.836] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.944] <TB3> INFO: Test took 1108ms.
[16:27:44.946] <TB3> INFO: The DUT currently contains the following objects:
[16:27:44.946] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:44.946] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:44.946] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:44.946] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:44.946] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.946] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.947] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:44.947] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.054] <TB3> INFO: Test took 1107ms.
[16:27:46.056] <TB3> INFO: The DUT currently contains the following objects:
[16:27:46.056] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:46.056] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:46.056] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:46.056] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:46.056] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:46.056] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.166] <TB3> INFO: Test took 1110ms.
[16:27:47.167] <TB3> INFO: The DUT currently contains the following objects:
[16:27:47.167] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:47.167] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:47.167] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:47.167] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:47.167] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.167] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.168] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.168] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.168] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.168] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:47.168] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.275] <TB3> INFO: Test took 1107ms.
[16:27:48.276] <TB3> INFO: The DUT currently contains the following objects:
[16:27:48.276] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:48.276] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:48.276] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:48.276] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:48.276] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:48.277] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.385] <TB3> INFO: Test took 1108ms.
[16:27:49.386] <TB3> INFO: The DUT currently contains the following objects:
[16:27:49.386] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:49.386] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:49.386] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:49.386] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:49.386] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.386] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.386] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.386] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:49.387] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.499] <TB3> INFO: Test took 1112ms.
[16:27:50.500] <TB3> INFO: The DUT currently contains the following objects:
[16:27:50.500] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:50.500] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:50.500] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:50.500] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:50.500] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.500] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:50.501] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: Test took 1104ms.
[16:27:51.605] <TB3> INFO: The DUT currently contains the following objects:
[16:27:51.605] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:51.605] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:51.605] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:51.605] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:51.605] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.605] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.606] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:51.606] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.713] <TB3> INFO: Test took 1107ms.
[16:27:52.714] <TB3> INFO: The DUT currently contains the following objects:
[16:27:52.714] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[16:27:52.714] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:27:52.714] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:27:52.714] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[16:27:52.714] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.714] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.714] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.714] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.714] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.714] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.714] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.714] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.715] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.715] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.715] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.715] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.715] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.715] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.715] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:52.715] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[16:27:53.839] <TB3> INFO: Test took 1124ms.
[16:27:53.843] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:31:31.110] <TB3> INFO: Test took 217267ms.
[16:31:32.641] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:14.728] <TB3> INFO: Test took 222087ms.
[16:35:16.416] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.422] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.429] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.436] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.445] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.451] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[16:35:16.458] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[16:35:16.465] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.471] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.478] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.484] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[16:35:16.491] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[16:35:16.498] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[16:35:16.504] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[16:35:16.511] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[16:35:16.517] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.524] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.531] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.537] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.544] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[16:35:16.550] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[16:35:16.557] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[16:35:16.564] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[16:35:16.570] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[16:35:16.577] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[16:35:16.583] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[16:35:16.590] <TB3> INFO: safety margin for low PH: adding 8, margin is now 28
[16:35:16.597] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.603] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.610] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.616] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[16:35:16.623] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[16:35:16.629] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[16:35:16.636] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[16:35:16.643] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[16:35:16.649] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[16:35:16.656] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[16:35:16.662] <TB3> INFO: safety margin for low PH: adding 8, margin is now 28
[16:35:16.669] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:35:16.710] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C0.dat
[16:35:16.710] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C1.dat
[16:35:16.711] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C2.dat
[16:35:16.711] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C3.dat
[16:35:16.711] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C4.dat
[16:35:16.711] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C5.dat
[16:35:16.711] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C6.dat
[16:35:16.712] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C7.dat
[16:35:16.712] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C8.dat
[16:35:16.712] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C9.dat
[16:35:16.712] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C10.dat
[16:35:16.713] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C11.dat
[16:35:16.713] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C12.dat
[16:35:16.713] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C13.dat
[16:35:16.713] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C14.dat
[16:35:16.714] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//dacParameters35_C15.dat
[16:35:20.164] <TB3> INFO: Test took 3447ms.
[16:35:23.854] <TB3> INFO: Test took 3410ms.
[16:35:27.575] <TB3> INFO: Test took 3438ms.
[16:35:27.861] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:28.782] <TB3> INFO: Test took 921ms.
[16:35:28.787] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:29.895] <TB3> INFO: Test took 1108ms.
[16:35:29.898] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:31.009] <TB3> INFO: Test took 1111ms.
[16:35:31.012] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:32.121] <TB3> INFO: Test took 1109ms.
[16:35:32.124] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:33.233] <TB3> INFO: Test took 1109ms.
[16:35:33.237] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:34.347] <TB3> INFO: Test took 1110ms.
[16:35:34.351] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:35.459] <TB3> INFO: Test took 1108ms.
[16:35:35.462] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:36.570] <TB3> INFO: Test took 1108ms.
[16:35:36.573] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:37.681] <TB3> INFO: Test took 1108ms.
[16:35:37.684] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:38.793] <TB3> INFO: Test took 1109ms.
[16:35:38.797] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:39.905] <TB3> INFO: Test took 1108ms.
[16:35:39.909] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:41.017] <TB3> INFO: Test took 1108ms.
[16:35:41.021] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:42.128] <TB3> INFO: Test took 1108ms.
[16:35:42.132] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:43.240] <TB3> INFO: Test took 1108ms.
[16:35:43.245] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:44.353] <TB3> INFO: Test took 1109ms.
[16:35:44.356] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:45.463] <TB3> INFO: Test took 1108ms.
[16:35:45.467] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:46.575] <TB3> INFO: Test took 1108ms.
[16:35:46.579] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:47.688] <TB3> INFO: Test took 1109ms.
[16:35:47.692] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:48.804] <TB3> INFO: Test took 1112ms.
[16:35:48.807] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:49.914] <TB3> INFO: Test took 1107ms.
[16:35:49.918] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:51.023] <TB3> INFO: Test took 1106ms.
[16:35:51.026] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:52.134] <TB3> INFO: Test took 1108ms.
[16:35:52.138] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:53.260] <TB3> INFO: Test took 1122ms.
[16:35:53.264] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:54.373] <TB3> INFO: Test took 1109ms.
[16:35:54.377] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:55.500] <TB3> INFO: Test took 1124ms.
[16:35:55.504] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:56.613] <TB3> INFO: Test took 1109ms.
[16:35:56.617] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:57.725] <TB3> INFO: Test took 1109ms.
[16:35:57.729] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:58.850] <TB3> INFO: Test took 1121ms.
[16:35:58.854] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:35:59.962] <TB3> INFO: Test took 1109ms.
[16:35:59.966] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:36:01.076] <TB3> INFO: Test took 1111ms.
[16:36:01.079] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:36:02.190] <TB3> INFO: Test took 1111ms.
[16:36:02.194] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:36:03.300] <TB3> INFO: Test took 1107ms.
[16:36:03.836] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 518 seconds
[16:36:03.836] <TB3> INFO: PH scale (per ROC): 75 69 76 65 79 79 65 74 80 67 78 80 79 78 77 76
[16:36:03.836] <TB3> INFO: PH offset (per ROC): 171 188 195 175 176 167 186 176 184 171 176 176 189 174 176 176
[16:36:04.024] <TB3> INFO: ######################################################################
[16:36:04.024] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[16:36:04.024] <TB3> INFO: ######################################################################
[16:36:04.035] <TB3> INFO: scanning low vcal = 10
[16:36:07.877] <TB3> INFO: Test took 3842ms.
[16:36:07.881] <TB3> INFO: scanning low vcal = 20
[16:36:11.742] <TB3> INFO: Test took 3861ms.
[16:36:11.747] <TB3> INFO: scanning low vcal = 30
[16:36:15.608] <TB3> INFO: Test took 3861ms.
[16:36:15.620] <TB3> INFO: scanning low vcal = 40
[16:36:19.938] <TB3> INFO: Test took 4318ms.
[16:36:19.997] <TB3> INFO: scanning low vcal = 50
[16:36:24.358] <TB3> INFO: Test took 4361ms.
[16:36:24.418] <TB3> INFO: scanning low vcal = 60
[16:36:28.796] <TB3> INFO: Test took 4378ms.
[16:36:28.865] <TB3> INFO: scanning low vcal = 70
[16:36:33.220] <TB3> INFO: Test took 4355ms.
[16:36:33.284] <TB3> INFO: scanning low vcal = 80
[16:36:37.649] <TB3> INFO: Test took 4365ms.
[16:36:37.708] <TB3> INFO: scanning low vcal = 90
[16:36:42.068] <TB3> INFO: Test took 4360ms.
[16:36:42.132] <TB3> INFO: scanning low vcal = 100
[16:36:46.389] <TB3> INFO: Test took 4257ms.
[16:36:46.446] <TB3> INFO: scanning low vcal = 110
[16:36:50.805] <TB3> INFO: Test took 4359ms.
[16:36:50.868] <TB3> INFO: scanning low vcal = 120
[16:36:55.219] <TB3> INFO: Test took 4351ms.
[16:36:55.278] <TB3> INFO: scanning low vcal = 130
[16:36:59.615] <TB3> INFO: Test took 4337ms.
[16:36:59.677] <TB3> INFO: scanning low vcal = 140
[16:37:04.039] <TB3> INFO: Test took 4362ms.
[16:37:04.099] <TB3> INFO: scanning low vcal = 150
[16:37:08.442] <TB3> INFO: Test took 4343ms.
[16:37:08.507] <TB3> INFO: scanning low vcal = 160
[16:37:12.870] <TB3> INFO: Test took 4363ms.
[16:37:12.929] <TB3> INFO: scanning low vcal = 170
[16:37:17.306] <TB3> INFO: Test took 4377ms.
[16:37:17.369] <TB3> INFO: scanning low vcal = 180
[16:37:21.722] <TB3> INFO: Test took 4353ms.
[16:37:21.791] <TB3> INFO: scanning low vcal = 190
[16:37:26.276] <TB3> INFO: Test took 4485ms.
[16:37:26.339] <TB3> INFO: scanning low vcal = 200
[16:37:30.707] <TB3> INFO: Test took 4368ms.
[16:37:30.772] <TB3> INFO: scanning low vcal = 210
[16:37:35.092] <TB3> INFO: Test took 4319ms.
[16:37:35.150] <TB3> INFO: scanning low vcal = 220
[16:37:39.478] <TB3> INFO: Test took 4328ms.
[16:37:39.541] <TB3> INFO: scanning low vcal = 230
[16:37:43.864] <TB3> INFO: Test took 4323ms.
[16:37:43.932] <TB3> INFO: scanning low vcal = 240
[16:37:48.308] <TB3> INFO: Test took 4376ms.
[16:37:48.366] <TB3> INFO: scanning low vcal = 250
[16:37:52.714] <TB3> INFO: Test took 4348ms.
[16:37:52.780] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[16:37:57.138] <TB3> INFO: Test took 4358ms.
[16:37:57.198] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[16:38:01.558] <TB3> INFO: Test took 4360ms.
[16:38:01.621] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[16:38:05.951] <TB3> INFO: Test took 4330ms.
[16:38:06.033] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[16:38:10.400] <TB3> INFO: Test took 4367ms.
[16:38:10.463] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[16:38:14.840] <TB3> INFO: Test took 4377ms.
[16:38:15.354] <TB3> INFO: PixTestGainPedestal::measure() done
[16:38:49.122] <TB3> INFO: PixTestGainPedestal::fit() done
[16:38:49.122] <TB3> INFO: non-linearity mean: 0.950 0.956 0.959 0.960 0.962 0.959 0.957 0.960 0.961 0.949 0.955 0.964 0.954 0.965 0.963 0.956
[16:38:49.122] <TB3> INFO: non-linearity RMS: 0.008 0.007 0.007 0.007 0.005 0.005 0.006 0.006 0.006 0.009 0.007 0.004 0.007 0.006 0.004 0.008
[16:38:49.122] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C0.dat
[16:38:49.143] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C1.dat
[16:38:49.163] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C2.dat
[16:38:49.184] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C3.dat
[16:38:49.203] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C4.dat
[16:38:49.224] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C5.dat
[16:38:49.244] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C6.dat
[16:38:49.265] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C7.dat
[16:38:49.285] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C8.dat
[16:38:49.305] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C9.dat
[16:38:49.325] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C10.dat
[16:38:49.346] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C11.dat
[16:38:49.366] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C12.dat
[16:38:49.387] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C13.dat
[16:38:49.407] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C14.dat
[16:38:49.427] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2079_FullQualification_2015-08-21_12h37m_1440153422//004_FulltestPxar_p17//phCalibrationFitErr35_C15.dat
[16:38:49.448] <TB3> INFO: PixTestGainPedestal::doTest() done, duration: 165 seconds
[16:38:49.454] <TB3> INFO: enter test to run
[16:38:49.455] <TB3> INFO: test: exit no parameter change
[16:38:49.916] <TB3> QUIET: Connection to board 170 closed.
[16:38:49.995] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master