Test Date: 2015-07-24 10:42
Analysis date: 2016-05-25 23:08
Logfile
LogfileView
[13:35:23.904] <TB1> INFO: *** Welcome to pxar ***
[13:35:23.905] <TB1> INFO: *** Today: 2015/07/24
[13:35:23.905] <TB1> INFO: readRocDacs: /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C15.dat
[13:35:23.906] <TB1> INFO: readTbmDacs: /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//tbmParameters_C0b.dat
[13:35:23.906] <TB1> INFO: readMaskFile: /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//defaultMaskFile.dat
[13:35:23.906] <TB1> INFO: readTrimFile: /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters_C15.dat
[13:35:23.973] <TB1> INFO: clk: 4
[13:35:23.973] <TB1> INFO: ctr: 4
[13:35:23.973] <TB1> INFO: sda: 19
[13:35:23.973] <TB1> INFO: tin: 9
[13:35:23.973] <TB1> INFO: level: 15
[13:35:23.973] <TB1> INFO: triggerdelay: 0
[13:35:23.973] <TB1> QUIET: Instanciating API for pxar v2.2.5+46~gdbe75a1
[13:35:23.973] <TB1> INFO: Log level: INFO
[13:35:23.981] <TB1> INFO: Found DTB DTB_WXBYFL
[13:35:23.993] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[13:35:23.996] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[13:35:23.999] <TB1> INFO: RPC call hashes of host and DTB match: 447413373
[13:35:25.522] <TB1> INFO: DUT info:
[13:35:25.522] <TB1> INFO: The DUT currently contains the following objects:
[13:35:25.522] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[13:35:25.522] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:35:25.522] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:35:25.522] <TB1> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:35:25.522] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.523] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:35:25.924] <TB1> INFO: enter 'restricted' command line mode
[13:35:25.924] <TB1> INFO: enter test to run
[13:35:25.924] <TB1> INFO: test: pretest no parameter change
[13:35:25.924] <TB1> INFO: running: pretest
[13:35:25.929] <TB1> INFO: ######################################################################
[13:35:25.929] <TB1> INFO: PixTestPretest::doTest()
[13:35:25.929] <TB1> INFO: ######################################################################
[13:35:25.930] <TB1> INFO: ----------------------------------------------------------------------
[13:35:25.930] <TB1> INFO: PixTestPretest::programROC()
[13:35:25.930] <TB1> INFO: ----------------------------------------------------------------------
[13:35:43.952] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[13:35:43.952] <TB1> INFO: IA differences per ROC: 17.7 16.9 18.5 17.7 19.3 18.5 18.5 18.5 16.9 18.5 20.1 20.9 18.5 18.5 19.3 18.5
[13:35:44.038] <TB1> INFO: ----------------------------------------------------------------------
[13:35:44.038] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[13:35:44.038] <TB1> INFO: ----------------------------------------------------------------------
[13:35:48.932] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[13:35:48.935] <TB1> INFO: ----------------------------------------------------------------------
[13:35:48.935] <TB1> INFO: PixTestPretest::findWorkingPixel()
[13:35:48.935] <TB1> INFO: ----------------------------------------------------------------------
[13:35:57.257] <TB1> INFO: Test took 8316ms.
[13:35:57.565] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[13:35:57.614] <TB1> INFO: ----------------------------------------------------------------------
[13:35:57.614] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[13:35:57.614] <TB1> INFO: ----------------------------------------------------------------------
[13:36:05.967] <TB1> INFO: Test took 8347ms.
[13:36:06.294] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[13:36:06.294] <TB1> INFO: CalDel: 138 143 127 132 141 125 144 126 127 129 140 121 112 149 130 124
[13:36:06.294] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[13:36:06.299] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C0.dat
[13:36:06.299] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C1.dat
[13:36:06.299] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C2.dat
[13:36:06.300] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C3.dat
[13:36:06.300] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C4.dat
[13:36:06.300] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C5.dat
[13:36:06.300] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C6.dat
[13:36:06.301] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C7.dat
[13:36:06.301] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C8.dat
[13:36:06.301] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C9.dat
[13:36:06.301] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C10.dat
[13:36:06.301] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C11.dat
[13:36:06.301] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C12.dat
[13:36:06.301] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C13.dat
[13:36:06.301] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C14.dat
[13:36:06.301] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters_C15.dat
[13:36:06.301] <TB1> INFO: PixTestPretest::doTest() done, duration: 40 seconds
[13:36:06.391] <TB1> INFO: enter test to run
[13:36:06.391] <TB1> INFO: test: fulltest no parameter change
[13:36:06.391] <TB1> INFO: running: fulltest
[13:36:06.391] <TB1> INFO: ######################################################################
[13:36:06.391] <TB1> INFO: PixTestFullTest::doTest()
[13:36:06.391] <TB1> INFO: ######################################################################
[13:36:06.393] <TB1> INFO: ######################################################################
[13:36:06.393] <TB1> INFO: PixTestAlive::doTest()
[13:36:06.393] <TB1> INFO: ######################################################################
[13:36:06.394] <TB1> INFO: ----------------------------------------------------------------------
[13:36:06.394] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:36:06.395] <TB1> INFO: ----------------------------------------------------------------------
[13:36:09.862] <TB1> INFO: Test took 3465ms.
[13:36:09.885] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:10.125] <TB1> INFO: PixTestAlive::aliveTest() done
[13:36:10.125] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:36:10.127] <TB1> INFO: ----------------------------------------------------------------------
[13:36:10.127] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:36:10.127] <TB1> INFO: ----------------------------------------------------------------------
[13:36:12.902] <TB1> INFO: Test took 2773ms.
[13:36:12.905] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:12.906] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[13:36:13.147] <TB1> INFO: PixTestAlive::maskTest() done
[13:36:13.147] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:36:13.149] <TB1> INFO: ----------------------------------------------------------------------
[13:36:13.149] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:36:13.149] <TB1> INFO: ----------------------------------------------------------------------
[13:36:16.614] <TB1> INFO: Test took 3463ms.
[13:36:16.641] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:16.882] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[13:36:16.882] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:36:16.883] <TB1> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[13:36:16.894] <TB1> INFO: ######################################################################
[13:36:16.894] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[13:36:16.894] <TB1> INFO: ######################################################################
[13:36:16.898] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[13:36:16.913] <TB1> INFO: dacScan step from 0 .. 29
[13:36:38.483] <TB1> INFO: Test took 21570ms.
[13:36:38.516] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:38.516] <TB1> INFO: dacScan step from 30 .. 59
[13:37:00.888] <TB1> INFO: Test took 22373ms.
[13:37:00.964] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:00.972] <TB1> INFO: dacScan step from 60 .. 89
[13:37:29.969] <TB1> INFO: Test took 28997ms.
[13:37:30.221] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:37:30.299] <TB1> INFO: dacScan step from 90 .. 119
[13:38:00.021] <TB1> INFO: Test took 29722ms.
[13:38:00.288] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:00.363] <TB1> INFO: dacScan step from 120 .. 149
[13:38:25.507] <TB1> INFO: Test took 25144ms.
[13:38:25.716] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:38:49.278] <TB1> INFO: PixTestBBMap::doTest() done, duration: 152 seconds
[13:38:49.278] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 4 0 0 0 0 0 0 0 0
[13:38:49.278] <TB1> INFO: separation cut (per ROC): 89 92 98 95 93 96 85 96 95 94 78 106 101 106 96 94
[13:38:49.347] <TB1> INFO: ######################################################################
[13:38:49.347] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50
[13:38:49.347] <TB1> INFO: ######################################################################
[13:38:49.347] <TB1> INFO: ----------------------------------------------------------------------
[13:38:49.347] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[13:38:49.347] <TB1> INFO: ----------------------------------------------------------------------
[13:38:49.347] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[13:38:49.355] <TB1> INFO: dacScan step from 0 .. 3
[13:39:07.036] <TB1> INFO: Test took 17681ms.
[13:39:07.062] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:07.064] <TB1> INFO: dacScan step from 4 .. 7
[13:39:24.901] <TB1> INFO: Test took 17837ms.
[13:39:24.935] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:24.935] <TB1> INFO: dacScan step from 8 .. 11
[13:39:44.382] <TB1> INFO: Test took 19447ms.
[13:39:44.416] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:39:44.417] <TB1> INFO: dacScan step from 12 .. 15
[13:40:03.542] <TB1> INFO: Test took 19125ms.
[13:40:03.573] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:03.573] <TB1> INFO: dacScan step from 16 .. 19
[13:40:22.790] <TB1> INFO: Test took 19217ms.
[13:40:22.821] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:22.822] <TB1> INFO: dacScan step from 20 .. 23
[13:40:42.115] <TB1> INFO: Test took 19293ms.
[13:40:42.144] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:40:42.144] <TB1> INFO: dacScan step from 24 .. 27
[13:41:01.249] <TB1> INFO: Test took 19105ms.
[13:41:01.276] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:01.276] <TB1> INFO: dacScan step from 28 .. 31
[13:41:20.420] <TB1> INFO: Test took 19144ms.
[13:41:20.457] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:20.457] <TB1> INFO: dacScan step from 32 .. 35
[13:41:39.774] <TB1> INFO: Test took 19317ms.
[13:41:39.805] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:39.805] <TB1> INFO: dacScan step from 36 .. 39
[13:41:58.999] <TB1> INFO: Test took 19194ms.
[13:41:59.027] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:41:59.027] <TB1> INFO: dacScan step from 40 .. 43
[13:42:18.359] <TB1> INFO: Test took 19332ms.
[13:42:18.390] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:18.390] <TB1> INFO: dacScan step from 44 .. 47
[13:42:37.525] <TB1> INFO: Test took 19134ms.
[13:42:37.554] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:37.554] <TB1> INFO: dacScan step from 48 .. 51
[13:42:56.833] <TB1> INFO: Test took 19278ms.
[13:42:56.862] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:42:56.862] <TB1> INFO: dacScan step from 52 .. 55
[13:43:16.156] <TB1> INFO: Test took 19294ms.
[13:43:16.184] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:16.184] <TB1> INFO: dacScan step from 56 .. 59
[13:43:35.610] <TB1> INFO: Test took 19425ms.
[13:43:35.642] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:35.643] <TB1> INFO: dacScan step from 60 .. 63
[13:43:55.031] <TB1> INFO: Test took 19388ms.
[13:43:55.063] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:43:55.063] <TB1> INFO: dacScan step from 64 .. 67
[13:44:14.248] <TB1> INFO: Test took 19185ms.
[13:44:14.275] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:14.275] <TB1> INFO: dacScan step from 68 .. 71
[13:44:33.583] <TB1> INFO: Test took 19308ms.
[13:44:33.615] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:33.615] <TB1> INFO: dacScan step from 72 .. 75
[13:44:53.244] <TB1> INFO: Test took 19628ms.
[13:44:53.279] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:44:53.280] <TB1> INFO: dacScan step from 76 .. 79
[13:45:13.016] <TB1> INFO: Test took 19736ms.
[13:45:13.062] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:13.063] <TB1> INFO: dacScan step from 80 .. 83
[13:45:34.461] <TB1> INFO: Test took 21398ms.
[13:45:34.550] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:34.554] <TB1> INFO: dacScan step from 84 .. 87
[13:45:57.599] <TB1> INFO: Test took 23044ms.
[13:45:57.731] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:45:57.736] <TB1> INFO: dacScan step from 88 .. 91
[13:46:22.128] <TB1> INFO: Test took 24392ms.
[13:46:22.272] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:22.279] <TB1> INFO: dacScan step from 92 .. 95
[13:46:48.767] <TB1> INFO: Test took 26488ms.
[13:46:48.978] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:46:48.989] <TB1> INFO: dacScan step from 96 .. 99
[13:47:16.902] <TB1> INFO: Test took 27913ms.
[13:47:17.161] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:17.172] <TB1> INFO: dacScan step from 100 .. 103
[13:47:46.115] <TB1> INFO: Test took 28943ms.
[13:47:46.371] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:46.384] <TB1> INFO: dacScan step from 104 .. 107
[13:48:15.296] <TB1> INFO: Test took 28912ms.
[13:48:15.512] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:15.524] <TB1> INFO: dacScan step from 108 .. 111
[13:48:44.808] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

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

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

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

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

[13:48:45.414] <TB1> INFO: Test took 29890ms.
[13:48:45.648] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:45.659] <TB1> INFO: dacScan step from 112 .. 115
[13:49:15.655] <TB1> INFO: Test took 29995ms.
[13:49:15.907] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:15.920] <TB1> INFO: dacScan step from 116 .. 119
[13:49:44.758] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[13:49:46.002] <TB1> INFO: Test took 30082ms.
[13:49:46.232] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:49:46.244] <TB1> INFO: dacScan step from 120 .. 123
[13:50:14.679] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[13:50:14.679] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (126) != TBM ID (127)

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

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

[13:50:14.679] <TB1> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[13:50:15.926] <TB1> INFO: Test took 29682ms.
[13:50:16.158] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:16.169] <TB1> INFO: dacScan step from 124 .. 127
[13:50:44.808] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[13:50:46.152] <TB1> INFO: Test took 29983ms.
[13:50:46.369] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:50:46.380] <TB1> INFO: dacScan step from 128 .. 131
[13:51:14.963] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[13:51:14.963] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (215) != TBM ID (216)

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

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

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

[13:51:16.208] <TB1> INFO: Test took 29828ms.
[13:51:16.449] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:16.459] <TB1> INFO: dacScan step from 132 .. 135
[13:51:44.854] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[13:51:46.177] <TB1> INFO: Test took 29717ms.
[13:51:46.423] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:46.434] <TB1> INFO: dacScan step from 136 .. 139
[13:52:14.965] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[13:52:14.965] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (195) != TBM ID (196)

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

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

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

[13:52:16.265] <TB1> INFO: Test took 29831ms.
[13:52:16.518] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:16.530] <TB1> INFO: dacScan step from 140 .. 143
[13:52:46.351] <TB1> INFO: Test took 29821ms.
[13:52:46.663] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:52:46.676] <TB1> INFO: dacScan step from 144 .. 147
[13:53:16.384] <TB1> INFO: Test took 29707ms.
[13:53:16.623] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:16.635] <TB1> INFO: dacScan step from 148 .. 149
[13:53:32.987] <TB1> INFO: Test took 16351ms.
[13:53:33.102] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:53:33.108] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:34.633] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:36.341] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:37.761] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:39.201] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:40.622] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:41.982] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:43.467] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:44.973] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:46.498] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:48.016] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:49.538] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:50.917] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:52.263] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:53.626] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:54.975] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:53:56.413] <TB1> INFO: PixTestScurves::scurves() done
[13:53:56.413] <TB1> INFO: Vcal mean: 89.53 87.94 98.71 92.60 90.19 93.17 86.79 85.20 96.03 90.46 79.68 106.11 105.96 106.31 93.17 89.59
[13:53:56.413] <TB1> INFO: Vcal RMS: 4.77 5.86 5.68 5.29 5.29 5.60 5.04 5.68 5.26 6.45 3.89 5.90 5.98 5.37 5.71 5.19
[13:53:56.413] <TB1> INFO: PixTestScurves::fullTest() done, duration: 907 seconds
[13:53:56.486] <TB1> INFO: ######################################################################
[13:53:56.486] <TB1> INFO: PixTestTrim::doTest()
[13:53:56.486] <TB1> INFO: ######################################################################
[13:53:56.488] <TB1> INFO: ----------------------------------------------------------------------
[13:53:56.488] <TB1> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[13:53:56.488] <TB1> INFO: ----------------------------------------------------------------------
[13:53:56.574] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[13:53:56.574] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[13:53:56.582] <TB1> INFO: dacScan step from 0 .. 19
[13:54:11.173] <TB1> INFO: Test took 14591ms.
[13:54:11.196] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:11.196] <TB1> INFO: dacScan step from 20 .. 39
[13:54:26.329] <TB1> INFO: Test took 15133ms.
[13:54:26.359] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:26.359] <TB1> INFO: dacScan step from 40 .. 59
[13:54:41.678] <TB1> INFO: Test took 15319ms.
[13:54:41.700] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:41.700] <TB1> INFO: dacScan step from 60 .. 79
[13:54:56.840] <TB1> INFO: Test took 15140ms.
[13:54:56.869] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:56.869] <TB1> INFO: dacScan step from 80 .. 99
[13:55:12.593] <TB1> INFO: Test took 15724ms.
[13:55:12.639] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:12.643] <TB1> INFO: dacScan step from 100 .. 119
[13:55:31.388] <TB1> INFO: Test took 18745ms.
[13:55:31.567] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:31.592] <TB1> INFO: dacScan step from 120 .. 139
[13:55:51.295] <TB1> INFO: Test took 19703ms.
[13:55:51.455] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:55:51.485] <TB1> INFO: dacScan step from 140 .. 159
[13:56:08.044] <TB1> INFO: Test took 16559ms.
[13:56:08.121] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:30.094] <TB1> INFO: ROC 0 VthrComp = 95
[13:56:30.094] <TB1> INFO: ROC 1 VthrComp = 91
[13:56:30.094] <TB1> INFO: ROC 2 VthrComp = 102
[13:56:30.094] <TB1> INFO: ROC 3 VthrComp = 97
[13:56:30.094] <TB1> INFO: ROC 4 VthrComp = 94
[13:56:30.094] <TB1> INFO: ROC 5 VthrComp = 98
[13:56:30.095] <TB1> INFO: ROC 6 VthrComp = 89
[13:56:30.095] <TB1> INFO: ROC 7 VthrComp = 87
[13:56:30.095] <TB1> INFO: ROC 8 VthrComp = 99
[13:56:30.095] <TB1> INFO: ROC 9 VthrComp = 92
[13:56:30.095] <TB1> INFO: ROC 10 VthrComp = 84
[13:56:30.096] <TB1> INFO: ROC 11 VthrComp = 106
[13:56:30.096] <TB1> INFO: ROC 12 VthrComp = 104
[13:56:30.096] <TB1> INFO: ROC 13 VthrComp = 105
[13:56:30.096] <TB1> INFO: ROC 14 VthrComp = 98
[13:56:30.096] <TB1> INFO: ROC 15 VthrComp = 93
[13:56:30.096] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[13:56:30.096] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[13:56:30.104] <TB1> INFO: dacScan step from 0 .. 19
[13:56:44.711] <TB1> INFO: Test took 14607ms.
[13:56:44.739] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:44.739] <TB1> INFO: dacScan step from 20 .. 39
[13:57:00.294] <TB1> INFO: Test took 15555ms.
[13:57:00.328] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:00.330] <TB1> INFO: dacScan step from 40 .. 59
[13:57:19.324] <TB1> INFO: Test took 18994ms.
[13:57:19.477] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:19.514] <TB1> INFO: dacScan step from 60 .. 79
[13:57:39.824] <TB1> INFO: Test took 20310ms.
[13:57:39.986] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:40.035] <TB1> INFO: dacScan step from 80 .. 99
[13:58:00.454] <TB1> INFO: Test took 20419ms.
[13:58:00.643] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:00.700] <TB1> INFO: dacScan step from 100 .. 119
[13:58:21.228] <TB1> INFO: Test took 20528ms.
[13:58:21.393] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:21.444] <TB1> INFO: dacScan step from 120 .. 139
[13:58:41.485] <TB1> INFO: Test took 20041ms.
[13:58:41.675] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:41.730] <TB1> INFO: dacScan step from 140 .. 159
[13:59:02.109] <TB1> INFO: Test took 20379ms.
[13:59:02.277] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:28.220] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 56.1059 for pixel 35/5 mean/min/max = 43.9968/31.8579/56.1357
[13:59:28.220] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 60.1988 for pixel 0/1 mean/min/max = 46.2603/32.2988/60.2218
[13:59:28.220] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 59.8192 for pixel 2/2 mean/min/max = 45.998/32.1049/59.8911
[13:59:28.220] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 56.2103 for pixel 7/0 mean/min/max = 44.4537/32.4176/56.4898
[13:59:28.221] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 57.6103 for pixel 3/79 mean/min/max = 45.2498/32.7654/57.7342
[13:59:28.221] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 57.6666 for pixel 5/43 mean/min/max = 44.517/31.3063/57.7276
[13:59:28.221] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 57.844 for pixel 19/1 mean/min/max = 46.0714/34.2283/57.9145
[13:59:28.221] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 58.5338 for pixel 0/77 mean/min/max = 45.3188/32.0497/58.5878
[13:59:28.222] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 57.2522 for pixel 8/73 mean/min/max = 44.2834/31.1706/57.3962
[13:59:28.222] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 61.355 for pixel 1/61 mean/min/max = 46.7149/32.0168/61.413
[13:59:28.222] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 55.3012 for pixel 12/2 mean/min/max = 44.1764/32.9343/55.4185
[13:59:28.222] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 63.5832 for pixel 25/79 mean/min/max = 48.7862/33.8184/63.754
[13:59:28.223] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 65.1021 for pixel 0/74 mean/min/max = 49.26/33.4075/65.1124
[13:59:28.223] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 63.0921 for pixel 20/10 mean/min/max = 48.9073/34.5229/63.2916
[13:59:28.223] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 58.028 for pixel 0/30 mean/min/max = 44.8092/31.1072/58.5112
[13:59:28.223] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 58.5833 for pixel 12/79 mean/min/max = 45.7382/32.7556/58.7207
[13:59:28.224] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:01:02.799] <TB1> INFO: Test took 94575ms.
[14:01:04.376] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[14:01:04.384] <TB1> INFO: dacScan step from 0 .. 19
[14:01:27.096] <TB1> INFO: Test took 22712ms.
[14:01:27.149] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:27.150] <TB1> INFO: dacScan step from 20 .. 39
[14:01:55.868] <TB1> INFO: Test took 28718ms.
[14:01:56.084] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:56.117] <TB1> INFO: dacScan step from 40 .. 59
[14:02:28.282] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (213) != TBM ID (0)

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

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

[14:02:29.370] <TB1> INFO: Test took 33253ms.
[14:02:29.720] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:29.789] <TB1> INFO: dacScan step from 60 .. 79
[14:03:00.029] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:03:01.348] <TB1> INFO: Test took 31559ms.
[14:03:01.639] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:01.699] <TB1> INFO: dacScan step from 80 .. 99
[14:03:35.276] <TB1> INFO: Test took 33577ms.
[14:03:35.543] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:35.599] <TB1> INFO: dacScan step from 100 .. 119
[14:04:07.952] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[14:04:07.952] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (198) != TBM ID (199)

[14:04:07.952] <TB1> WARNING: Channel 3 ROC 0: Readback start marker after 15 readouts!

[14:04:07.952] <TB1> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

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

[14:04:09.232] <TB1> INFO: Test took 33633ms.
[14:04:09.600] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:09.665] <TB1> INFO: dacScan step from 120 .. 139
[14:04:43.207] <TB1> INFO: Test took 33542ms.
[14:04:43.496] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:43.554] <TB1> INFO: dacScan step from 140 .. 159
[14:05:16.068] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (200) != TBM ID (0)

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

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

[14:05:17.389] <TB1> INFO: Test took 33835ms.
[14:05:17.649] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:17.703] <TB1> INFO: dacScan step from 160 .. 179
[14:05:50.307] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[14:05:51.654] <TB1> INFO: Test took 33951ms.
[14:05:51.935] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:51.991] <TB1> INFO: dacScan step from 180 .. 199
[14:06:25.178] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (201) != TBM ID (0)

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

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

[14:06:26.448] <TB1> INFO: Test took 34457ms.
[14:06:26.826] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:06:52.022] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.112192 .. 54.254899
[14:06:52.106] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 64 (20) hits flags = 16 (plus default)
[14:06:52.115] <TB1> INFO: dacScan step from 0 .. 19
[14:07:05.748] <TB1> INFO: Test took 13633ms.
[14:07:05.778] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:05.778] <TB1> INFO: dacScan step from 20 .. 39
[14:07:20.827] <TB1> INFO: Test took 15049ms.
[14:07:20.903] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:20.918] <TB1> INFO: dacScan step from 40 .. 59
[14:07:38.577] <TB1> INFO: Test took 17659ms.
[14:07:38.772] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:07:38.827] <TB1> INFO: dacScan step from 60 .. 64
[14:07:45.421] <TB1> INFO: Test took 6594ms.
[14:07:45.465] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:02.577] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 16.115774 .. 46.649062
[14:08:02.653] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 6 .. 56 (20) hits flags = 16 (plus default)
[14:08:02.661] <TB1> INFO: dacScan step from 6 .. 25
[14:08:16.279] <TB1> INFO: Test took 13618ms.
[14:08:16.305] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:16.305] <TB1> INFO: dacScan step from 26 .. 45
[14:08:32.517] <TB1> INFO: Test took 16212ms.
[14:08:32.643] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:08:32.676] <TB1> INFO: dacScan step from 46 .. 56
[14:08:43.568] <TB1> INFO: Test took 10892ms.
[14:08:43.673] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:00.571] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 18.327117 .. 43.405057
[14:09:00.669] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 8 .. 53 (20) hits flags = 16 (plus default)
[14:09:00.678] <TB1> INFO: dacScan step from 8 .. 27
[14:09:14.301] <TB1> INFO: Test took 13622ms.
[14:09:14.326] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:14.326] <TB1> INFO: dacScan step from 28 .. 47
[14:09:30.722] <TB1> INFO: Test took 16396ms.
[14:09:30.857] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:30.895] <TB1> INFO: dacScan step from 48 .. 53
[14:09:38.279] <TB1> INFO: Test took 7384ms.
[14:09:38.331] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:54.146] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 21.084817 .. 43.405057
[14:09:54.223] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 11 .. 53 (20) hits flags = 16 (plus default)
[14:09:54.230] <TB1> INFO: dacScan step from 11 .. 30
[14:10:07.905] <TB1> INFO: Test took 13674ms.
[14:10:07.939] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:07.940] <TB1> INFO: dacScan step from 31 .. 50
[14:10:23.942] <TB1> INFO: Test took 16002ms.
[14:10:24.080] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:24.126] <TB1> INFO: dacScan step from 51 .. 53
[14:10:29.048] <TB1> INFO: Test took 4922ms.
[14:10:29.076] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:44.751] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[14:10:44.751] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[14:10:44.759] <TB1> INFO: dacScan step from 15 .. 34
[14:11:06.780] <TB1> INFO: Test took 22021ms.
[14:11:06.851] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:06.861] <TB1> INFO: dacScan step from 35 .. 54
[14:11:39.378] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:11:40.099] <TB1> INFO: Test took 33238ms.
[14:11:40.423] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:40.482] <TB1> INFO: dacScan step from 55 .. 55
[14:11:44.886] <TB1> INFO: Test took 4404ms.
[14:11:44.903] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:58.140] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C0.dat
[14:11:58.140] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C1.dat
[14:11:58.140] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C2.dat
[14:11:58.140] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C3.dat
[14:11:58.140] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C4.dat
[14:11:58.140] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C5.dat
[14:11:58.140] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C6.dat
[14:11:58.140] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C7.dat
[14:11:58.140] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C8.dat
[14:11:58.141] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C9.dat
[14:11:58.141] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C10.dat
[14:11:58.141] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C11.dat
[14:11:58.141] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C12.dat
[14:11:58.141] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C13.dat
[14:11:58.141] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C14.dat
[14:11:58.141] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C15.dat
[14:11:58.141] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C0.dat
[14:11:58.148] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C1.dat
[14:11:58.154] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C2.dat
[14:11:58.160] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C3.dat
[14:11:58.167] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C4.dat
[14:11:58.174] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C5.dat
[14:11:58.181] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C6.dat
[14:11:58.187] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C7.dat
[14:11:58.194] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C8.dat
[14:11:58.201] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C9.dat
[14:11:58.207] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C10.dat
[14:11:58.213] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C11.dat
[14:11:58.220] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C12.dat
[14:11:58.228] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C13.dat
[14:11:58.237] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C14.dat
[14:11:58.245] <TB1> INFO: write trim parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//trimParameters35_C15.dat
[14:11:58.252] <TB1> INFO: PixTestTrim::trimTest() done
[14:11:58.252] <TB1> INFO: vtrim: 97 96 111 107 102 113 120 106 111 120 113 127 120 122 119 103
[14:11:58.252] <TB1> INFO: vthrcomp: 95 91 102 97 94 98 89 87 99 92 84 106 104 105 98 93
[14:11:58.252] <TB1> INFO: vcal mean: 35.01 35.04 35.06 35.07 35.11 35.07 35.05 35.13 35.01 35.06 35.05 35.07 35.08 35.13 35.05 35.05
[14:11:58.252] <TB1> INFO: vcal RMS: 1.03 0.99 1.06 1.02 0.98 1.08 1.12 1.08 1.16 1.03 0.99 1.06 1.08 1.11 1.02 0.99
[14:11:58.252] <TB1> INFO: bits mean: 10.35 9.41 9.72 10.18 9.93 10.38 9.70 9.91 10.38 9.33 10.45 8.85 8.84 8.83 9.84 9.48
[14:11:58.252] <TB1> INFO: bits RMS: 2.40 2.68 2.62 2.46 2.46 2.49 2.32 2.57 2.50 2.77 2.25 2.51 2.55 2.46 2.70 2.60
[14:11:58.261] <TB1> INFO: ----------------------------------------------------------------------
[14:11:58.261] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[14:11:58.261] <TB1> INFO: ----------------------------------------------------------------------
[14:11:58.265] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[14:11:58.274] <TB1> INFO: dacScan step from 0 .. 19
[14:12:21.067] <TB1> INFO: Test took 22793ms.
[14:12:21.109] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:21.109] <TB1> INFO: dacScan step from 20 .. 39
[14:12:43.855] <TB1> INFO: Test took 22746ms.
[14:12:43.891] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:43.891] <TB1> INFO: dacScan step from 40 .. 59
[14:13:05.543] <TB1> INFO: Test took 21652ms.
[14:13:05.589] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:05.589] <TB1> INFO: dacScan step from 60 .. 79
[14:13:28.723] <TB1> INFO: Test took 23134ms.
[14:13:28.763] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:28.763] <TB1> INFO: dacScan step from 80 .. 99
[14:13:50.430] <TB1> INFO: Test took 21667ms.
[14:13:50.469] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:50.470] <TB1> INFO: dacScan step from 100 .. 119
[14:14:16.351] <TB1> INFO: Test took 25881ms.
[14:14:16.492] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:16.512] <TB1> INFO: dacScan step from 120 .. 139
[14:14:47.844] <TB1> INFO: Test took 31332ms.
[14:14:48.258] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:48.316] <TB1> INFO: dacScan step from 140 .. 159
[14:15:19.507] <TB1> INFO: Test took 31190ms.
[14:15:19.811] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:19.864] <TB1> INFO: dacScan step from 160 .. 179
[14:15:50.263] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[14:15:50.263] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (70) != TBM ID (71)

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

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

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

[14:15:51.562] <TB1> INFO: Test took 31698ms.
[14:15:51.859] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:51.914] <TB1> INFO: dacScan step from 180 .. 199
[14:16:26.333] <TB1> INFO: Test took 34419ms.
[14:16:26.596] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:16:57.005] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 195 (20) hits flags = 16 (plus default)
[14:16:57.017] <TB1> INFO: dacScan step from 0 .. 19
[14:17:18.647] <TB1> INFO: Test took 21630ms.
[14:17:18.682] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:18.682] <TB1> INFO: dacScan step from 20 .. 39
[14:17:41.513] <TB1> INFO: Test took 22831ms.
[14:17:41.552] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:41.552] <TB1> INFO: dacScan step from 40 .. 59
[14:18:04.056] <TB1> INFO: Test took 22503ms.
[14:18:04.094] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:04.094] <TB1> INFO: dacScan step from 60 .. 79
[14:18:26.763] <TB1> INFO: Test took 22669ms.
[14:18:26.801] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:26.801] <TB1> INFO: dacScan step from 80 .. 99
[14:18:48.557] <TB1> INFO: Test took 21756ms.
[14:18:48.625] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:48.628] <TB1> INFO: dacScan step from 100 .. 119
[14:19:15.774] <TB1> INFO: Test took 27145ms.
[14:19:15.992] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:16.019] <TB1> INFO: dacScan step from 120 .. 139
[14:19:46.570] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[14:19:47.242] <TB1> INFO: Test took 31222ms.
[14:19:47.509] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:47.561] <TB1> INFO: dacScan step from 140 .. 159
[14:20:18.896] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:20:18.896] <TB1> WARNING: Channel 3 ROC 2: Readback start marker after 32 readouts!

[14:20:20.164] <TB1> INFO: Test took 32603ms.
[14:20:20.454] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:20.505] <TB1> INFO: dacScan step from 160 .. 179
[14:20:53.558] <TB1> INFO: Test took 33053ms.
[14:20:53.859] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:53.912] <TB1> INFO: dacScan step from 180 .. 195
[14:21:20.203] <TB1> INFO: Test took 26290ms.
[14:21:20.419] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:47.502] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 179 (20) hits flags = 16 (plus default)
[14:21:47.511] <TB1> INFO: dacScan step from 0 .. 19
[14:22:10.512] <TB1> INFO: Test took 23001ms.
[14:22:10.553] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:10.553] <TB1> INFO: dacScan step from 20 .. 39
[14:22:33.444] <TB1> INFO: Test took 22891ms.
[14:22:33.482] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:33.482] <TB1> INFO: dacScan step from 40 .. 59
[14:22:56.425] <TB1> INFO: Test took 22943ms.
[14:22:56.462] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:56.462] <TB1> INFO: dacScan step from 60 .. 79
[14:23:19.549] <TB1> INFO: Test took 23087ms.
[14:23:19.589] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:19.589] <TB1> INFO: dacScan step from 80 .. 99
[14:23:43.164] <TB1> INFO: Test took 23575ms.
[14:23:43.225] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:43.228] <TB1> INFO: dacScan step from 100 .. 119
[14:24:09.990] <TB1> INFO: Test took 26754ms.
[14:24:10.217] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:10.242] <TB1> INFO: dacScan step from 120 .. 139
[14:24:43.265] <TB1> INFO: Test took 33023ms.
[14:24:43.548] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:43.596] <TB1> INFO: dacScan step from 140 .. 159
[14:25:15.927] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[14:25:17.259] <TB1> INFO: Test took 33663ms.
[14:25:17.541] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:17.591] <TB1> INFO: dacScan step from 160 .. 179
[14:25:50.479] <TB1> INFO: Test took 32888ms.
[14:25:50.764] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:15.882] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 187 (20) hits flags = 16 (plus default)
[14:26:15.890] <TB1> INFO: dacScan step from 0 .. 19
[14:26:38.707] <TB1> INFO: Test took 22817ms.
[14:26:38.749] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:38.750] <TB1> INFO: dacScan step from 20 .. 39
[14:27:01.767] <TB1> INFO: Test took 23017ms.
[14:27:01.805] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:01.805] <TB1> INFO: dacScan step from 40 .. 59
[14:27:24.758] <TB1> INFO: Test took 22953ms.
[14:27:24.793] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:24.793] <TB1> INFO: dacScan step from 60 .. 79
[14:27:47.945] <TB1> INFO: Test took 23152ms.
[14:27:47.982] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:47.983] <TB1> INFO: dacScan step from 80 .. 99
[14:28:09.805] <TB1> INFO: Test took 21822ms.
[14:28:09.885] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:09.889] <TB1> INFO: dacScan step from 100 .. 119
[14:28:38.650] <TB1> INFO: Test took 28761ms.
[14:28:38.871] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:38.895] <TB1> INFO: dacScan step from 120 .. 139
[14:29:11.775] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:29:12.551] <TB1> INFO: Test took 33656ms.
[14:29:12.838] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:12.888] <TB1> INFO: dacScan step from 140 .. 159
[14:29:45.335] <TB1> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (177) != TBM ID (0)

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

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

[14:29:46.673] <TB1> INFO: Test took 33785ms.
[14:29:46.965] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:47.018] <TB1> INFO: dacScan step from 160 .. 179
[14:30:19.257] <TB1> INFO: Test took 32239ms.
[14:30:19.568] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:19.624] <TB1> INFO: dacScan step from 180 .. 187
[14:30:33.638] <TB1> INFO: Test took 14014ms.
[14:30:33.751] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:00.967] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 169 (20) hits flags = 16 (plus default)
[14:31:00.975] <TB1> INFO: dacScan step from 0 .. 19
[14:31:22.496] <TB1> INFO: Test took 21521ms.
[14:31:22.530] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:22.530] <TB1> INFO: dacScan step from 20 .. 39
[14:31:45.568] <TB1> INFO: Test took 23038ms.
[14:31:45.603] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:45.603] <TB1> INFO: dacScan step from 40 .. 59
[14:32:06.980] <TB1> INFO: Test took 21377ms.
[14:32:07.018] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:07.018] <TB1> INFO: dacScan step from 60 .. 79
[14:32:30.052] <TB1> INFO: Test took 23034ms.
[14:32:30.091] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:30.091] <TB1> INFO: dacScan step from 80 .. 99
[14:32:53.566] <TB1> INFO: Test took 23475ms.
[14:32:53.629] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:32:53.632] <TB1> INFO: dacScan step from 100 .. 119
[14:33:23.125] <TB1> INFO: Test took 29493ms.
[14:33:23.348] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:23.372] <TB1> INFO: dacScan step from 120 .. 139
[14:33:56.201] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[14:33:56.969] <TB1> INFO: Test took 33597ms.
[14:33:57.285] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:33:57.343] <TB1> INFO: dacScan step from 140 .. 159
[14:34:27.232] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[14:34:28.506] <TB1> INFO: Test took 31163ms.
[14:34:28.819] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:28.880] <TB1> INFO: dacScan step from 160 .. 169
[14:34:47.095] <TB1> INFO: Test took 18215ms.
[14:34:47.284] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:13.262] <TB1> INFO: PixTestTrim::trimBitTest() done
[14:35:13.264] <TB1> INFO: PixTestTrim::doTest() done, duration: 2476 seconds
[14:35:13.956] <TB1> INFO: ######################################################################
[14:35:13.956] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[14:35:13.956] <TB1> INFO: ######################################################################
[14:35:17.431] <TB1> INFO: Test took 3474ms.
[14:35:17.455] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:21.142] <TB1> INFO: Test took 3488ms.
[14:35:21.208] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:24.699] <TB1> INFO: Test took 3477ms.
[14:35:24.760] <TB1> INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:24.767] <TB1> INFO: The DUT currently contains the following objects:
[14:35:24.767] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:24.767] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:24.767] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:24.767] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:24.767] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.767] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.767] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.767] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.767] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.767] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.767] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.767] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.767] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.768] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.768] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.768] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.768] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.768] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.768] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:24.768] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.879] <TB1> INFO: Test took 1111ms.
[14:35:25.880] <TB1> INFO: The DUT currently contains the following objects:
[14:35:25.880] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:25.880] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:25.880] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:25.880] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:25.880] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.880] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:25.881] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.991] <TB1> INFO: Test took 1110ms.
[14:35:26.993] <TB1> INFO: The DUT currently contains the following objects:
[14:35:26.993] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:26.993] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:26.993] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:26.993] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:26.993] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:26.993] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.106] <TB1> INFO: Test took 1113ms.
[14:35:28.108] <TB1> INFO: The DUT currently contains the following objects:
[14:35:28.108] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:28.108] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:28.108] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:28.108] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:28.108] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:28.108] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.217] <TB1> INFO: Test took 1109ms.
[14:35:29.218] <TB1> INFO: The DUT currently contains the following objects:
[14:35:29.218] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:29.218] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:29.218] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:29.218] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:29.218] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.218] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.218] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:29.219] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.329] <TB1> INFO: Test took 1110ms.
[14:35:30.331] <TB1> INFO: The DUT currently contains the following objects:
[14:35:30.331] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:30.331] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:30.331] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:30.331] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:30.331] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:30.331] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.437] <TB1> INFO: Test took 1106ms.
[14:35:31.437] <TB1> INFO: The DUT currently contains the following objects:
[14:35:31.437] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:31.437] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:31.437] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:31.437] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:31.437] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.437] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.437] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.437] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.437] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.437] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.437] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.437] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.438] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.438] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.438] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.438] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.438] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.438] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.438] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:31.438] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.542] <TB1> INFO: Test took 1104ms.
[14:35:32.542] <TB1> INFO: The DUT currently contains the following objects:
[14:35:32.543] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:32.543] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:32.543] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:32.543] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:32.543] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:32.543] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.646] <TB1> INFO: Test took 1103ms.
[14:35:33.647] <TB1> INFO: The DUT currently contains the following objects:
[14:35:33.647] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:33.647] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:33.647] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:33.647] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:33.647] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:33.647] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.750] <TB1> INFO: Test took 1103ms.
[14:35:34.750] <TB1> INFO: The DUT currently contains the following objects:
[14:35:34.750] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:34.750] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:34.750] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:34.750] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:34.750] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.750] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.750] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.750] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.750] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.750] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.750] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.750] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.751] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.751] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.751] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.751] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.751] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.751] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.751] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:34.751] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.854] <TB1> INFO: Test took 1103ms.
[14:35:35.855] <TB1> INFO: The DUT currently contains the following objects:
[14:35:35.855] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:35.855] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:35.855] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:35.855] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:35.855] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:35.855] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.959] <TB1> INFO: Test took 1104ms.
[14:35:36.959] <TB1> INFO: The DUT currently contains the following objects:
[14:35:36.959] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:36.960] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:36.960] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:36.960] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:36.960] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:36.960] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.063] <TB1> INFO: Test took 1103ms.
[14:35:38.064] <TB1> INFO: The DUT currently contains the following objects:
[14:35:38.064] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:38.064] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:38.064] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:38.064] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:38.064] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:38.064] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.168] <TB1> INFO: Test took 1104ms.
[14:35:39.169] <TB1> INFO: The DUT currently contains the following objects:
[14:35:39.169] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:39.169] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:39.169] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:39.169] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:39.169] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:39.169] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.273] <TB1> INFO: Test took 1104ms.
[14:35:40.274] <TB1> INFO: The DUT currently contains the following objects:
[14:35:40.274] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:40.274] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:40.274] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:40.274] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:40.274] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:40.274] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.378] <TB1> INFO: Test took 1104ms.
[14:35:41.379] <TB1> INFO: The DUT currently contains the following objects:
[14:35:41.379] <TB1> INFO: 2 TBM Cores tbm09c (2 ON)
[14:35:41.379] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:35:41.379] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:35:41.379] <TB1> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[14:35:41.379] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:41.379] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[14:35:42.482] <TB1> INFO: Test took 1103ms.
[14:35:42.487] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:39:29.295] <TB1> INFO: Test took 226808ms.
[14:39:30.915] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:17.355] <TB1> INFO: Test took 226440ms.
[14:43:19.100] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.106] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.113] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.119] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.126] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:43:19.133] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[14:43:19.139] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[14:43:19.146] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[14:43:19.152] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[14:43:19.159] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[14:43:19.165] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[14:43:19.172] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[14:43:19.179] <TB1> INFO: safety margin for low PH: adding 9, margin is now 29
[14:43:19.185] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.192] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.198] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.205] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.211] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:43:19.218] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.225] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.231] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.238] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.244] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.251] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.258] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:43:19.264] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.271] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:43:19.326] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C0.dat
[14:43:19.326] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C1.dat
[14:43:19.326] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C2.dat
[14:43:19.326] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C3.dat
[14:43:19.326] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C4.dat
[14:43:19.326] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C5.dat
[14:43:19.327] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C6.dat
[14:43:19.327] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C7.dat
[14:43:19.327] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C8.dat
[14:43:19.327] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C9.dat
[14:43:19.327] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C10.dat
[14:43:19.327] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C11.dat
[14:43:19.327] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C12.dat
[14:43:19.327] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C13.dat
[14:43:19.327] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C14.dat
[14:43:19.328] <TB1> INFO: write dac parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//dacParameters35_C15.dat
[14:43:22.813] <TB1> INFO: Test took 3481ms.
[14:43:26.585] <TB1> INFO: Test took 3471ms.
[14:43:30.387] <TB1> INFO: Test took 3512ms.
[14:43:30.678] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:31.603] <TB1> INFO: Test took 925ms.
[14:43:31.607] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:32.722] <TB1> INFO: Test took 1115ms.
[14:43:32.727] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:33.838] <TB1> INFO: Test took 1111ms.
[14:43:33.842] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:34.952] <TB1> INFO: Test took 1110ms.
[14:43:34.956] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:36.066] <TB1> INFO: Test took 1110ms.
[14:43:36.070] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:37.183] <TB1> INFO: Test took 1113ms.
[14:43:37.188] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:38.297] <TB1> INFO: Test took 1109ms.
[14:43:38.301] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:39.411] <TB1> INFO: Test took 1110ms.
[14:43:39.416] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:40.531] <TB1> INFO: Test took 1115ms.
[14:43:40.536] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:41.650] <TB1> INFO: Test took 1114ms.
[14:43:41.655] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:42.766] <TB1> INFO: Test took 1112ms.
[14:43:42.770] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:43.882] <TB1> INFO: Test took 1112ms.
[14:43:43.887] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:44.997] <TB1> INFO: Test took 1110ms.
[14:43:45.001] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:46.112] <TB1> INFO: Test took 1111ms.
[14:43:46.116] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:47.227] <TB1> INFO: Test took 1111ms.
[14:43:47.231] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:48.343] <TB1> INFO: Test took 1112ms.
[14:43:48.347] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:49.450] <TB1> INFO: Test took 1104ms.
[14:43:49.453] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:50.558] <TB1> INFO: Test took 1105ms.
[14:43:50.561] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:51.687] <TB1> INFO: Test took 1126ms.
[14:43:51.691] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:52.802] <TB1> INFO: Test took 1111ms.
[14:43:52.806] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:53.918] <TB1> INFO: Test took 1112ms.
[14:43:53.923] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:55.048] <TB1> INFO: Test took 1126ms.
[14:43:55.052] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:56.176] <TB1> INFO: Test took 1124ms.
[14:43:56.181] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:57.292] <TB1> INFO: Test took 1112ms.
[14:43:57.296] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:58.423] <TB1> INFO: Test took 1128ms.
[14:43:58.429] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:43:59.536] <TB1> INFO: Test took 1107ms.
[14:43:59.540] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:44:00.668] <TB1> INFO: Test took 1128ms.
[14:44:00.672] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:44:01.797] <TB1> INFO: Test took 1125ms.
[14:44:01.801] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:44:02.924] <TB1> INFO: Test took 1123ms.
[14:44:02.929] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:44:04.039] <TB1> INFO: Test took 1111ms.
[14:44:04.043] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:44:05.153] <TB1> INFO: Test took 1110ms.
[14:44:05.157] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:44:06.268] <TB1> INFO: Test took 1111ms.
[14:44:06.855] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 532 seconds
[14:44:06.855] <TB1> INFO: PH scale (per ROC): 80 81 79 78 74 79 72 79 70 76 82 73 71 80 79 76
[14:44:06.855] <TB1> INFO: PH offset (per ROC): 162 164 162 176 179 194 160 154 174 173 164 191 194 181 175 167
[14:44:07.036] <TB1> INFO: ######################################################################
[14:44:07.036] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[14:44:07.036] <TB1> INFO: ######################################################################
[14:44:07.046] <TB1> INFO: scanning low vcal = 10
[14:44:10.895] <TB1> INFO: Test took 3848ms.
[14:44:10.900] <TB1> INFO: scanning low vcal = 20
[14:44:14.793] <TB1> INFO: Test took 3893ms.
[14:44:14.799] <TB1> INFO: scanning low vcal = 30
[14:44:18.693] <TB1> INFO: Test took 3894ms.
[14:44:18.704] <TB1> INFO: scanning low vcal = 40
[14:44:23.094] <TB1> INFO: Test took 4389ms.
[14:44:23.166] <TB1> INFO: scanning low vcal = 50
[14:44:27.605] <TB1> INFO: Test took 4439ms.
[14:44:27.668] <TB1> INFO: scanning low vcal = 60
[14:44:31.997] <TB1> INFO: Test took 4329ms.
[14:44:32.057] <TB1> INFO: scanning low vcal = 70
[14:44:36.472] <TB1> INFO: Test took 4415ms.
[14:44:36.564] <TB1> INFO: scanning low vcal = 80
[14:44:40.973] <TB1> INFO: Test took 4409ms.
[14:44:41.037] <TB1> INFO: scanning low vcal = 90
[14:44:45.405] <TB1> INFO: Test took 4368ms.
[14:44:45.477] <TB1> INFO: scanning low vcal = 100
[14:44:49.860] <TB1> INFO: Test took 4383ms.
[14:44:49.931] <TB1> INFO: scanning low vcal = 110
[14:44:54.451] <TB1> INFO: Test took 4520ms.
[14:44:54.515] <TB1> INFO: scanning low vcal = 120
[14:44:58.865] <TB1> INFO: Test took 4350ms.
[14:44:58.930] <TB1> INFO: scanning low vcal = 130
[14:45:03.317] <TB1> INFO: Test took 4387ms.
[14:45:03.403] <TB1> INFO: scanning low vcal = 140
[14:45:07.789] <TB1> INFO: Test took 4386ms.
[14:45:07.846] <TB1> INFO: scanning low vcal = 150
[14:45:12.227] <TB1> INFO: Test took 4381ms.
[14:45:12.287] <TB1> INFO: scanning low vcal = 160
[14:45:16.624] <TB1> INFO: Test took 4337ms.
[14:45:16.680] <TB1> INFO: scanning low vcal = 170
[14:45:21.081] <TB1> INFO: Test took 4401ms.
[14:45:21.150] <TB1> INFO: scanning low vcal = 180
[14:45:25.508] <TB1> INFO: Test took 4358ms.
[14:45:25.572] <TB1> INFO: scanning low vcal = 190
[14:45:30.029] <TB1> INFO: Test took 4457ms.
[14:45:30.117] <TB1> INFO: scanning low vcal = 200
[14:45:34.492] <TB1> INFO: Test took 4375ms.
[14:45:34.557] <TB1> INFO: scanning low vcal = 210
[14:45:38.864] <TB1> INFO: Test took 4307ms.
[14:45:38.924] <TB1> INFO: scanning low vcal = 220
[14:45:43.195] <TB1> INFO: Test took 4271ms.
[14:45:43.257] <TB1> INFO: scanning low vcal = 230
[14:45:47.498] <TB1> INFO: Test took 4241ms.
[14:45:47.557] <TB1> INFO: scanning low vcal = 240
[14:45:51.799] <TB1> INFO: Test took 4242ms.
[14:45:51.897] <TB1> INFO: scanning low vcal = 250
[14:45:56.139] <TB1> INFO: Test took 4242ms.
[14:45:56.196] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[14:46:00.425] <TB1> INFO: Test took 4229ms.
[14:46:00.484] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[14:46:04.706] <TB1> INFO: Test took 4221ms.
[14:46:04.765] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[14:46:09.075] <TB1> INFO: Test took 4310ms.
[14:46:09.135] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[14:46:13.530] <TB1> INFO: Test took 4395ms.
[14:46:13.605] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[14:46:17.960] <TB1> INFO: Test took 4355ms.
[14:46:18.516] <TB1> INFO: PixTestGainPedestal::measure() done
[14:46:58.282] <TB1> INFO: PixTestGainPedestal::fit() done
[14:46:58.282] <TB1> INFO: non-linearity mean: 0.955 0.962 0.960 0.968 0.960 0.952 0.949 0.954 0.954 0.949 0.962 0.956 0.964 0.964 0.959 0.958
[14:46:58.282] <TB1> INFO: non-linearity RMS: 0.007 0.005 0.006 0.004 0.005 0.007 0.008 0.006 0.007 0.008 0.006 0.009 0.006 0.006 0.006 0.007
[14:46:58.282] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C0.dat
[14:46:58.306] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C1.dat
[14:46:58.328] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C2.dat
[14:46:58.351] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C3.dat
[14:46:58.372] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C4.dat
[14:46:58.394] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C5.dat
[14:46:58.415] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C6.dat
[14:46:58.434] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C7.dat
[14:46:58.454] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C8.dat
[14:46:58.475] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C9.dat
[14:46:58.497] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C10.dat
[14:46:58.518] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C11.dat
[14:46:58.540] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C12.dat
[14:46:58.558] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C13.dat
[14:46:58.577] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C14.dat
[14:46:58.596] <TB1> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2047_FullQualification_2015-07-24_10h42m_1437727338//004_FulltestPxar_p17//phCalibrationFitErr35_C15.dat
[14:46:58.615] <TB1> INFO: PixTestGainPedestal::doTest() done, duration: 171 seconds
[14:46:58.621] <TB1> INFO: enter test to run
[14:46:58.621] <TB1> INFO: test: exit no parameter change
[14:46:59.149] <TB1> QUIET: Connection to board 153 closed.
[14:46:59.229] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master