Test Date: 2015-08-13 09:40
Analysis date: 2016-05-26 01:38
Logfile
LogfileView
[07:48:04.423] <TB3> INFO: *** Welcome to pxar ***
[07:48:04.423] <TB3> INFO: *** Today: 2015/08/13
[07:48:04.423] <TB3> INFO: readRocDacs: /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C0.dat .. /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C15.dat
[07:48:04.424] <TB3> INFO: readTbmDacs: /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//tbmParameters_C0a.dat .. /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//tbmParameters_C0b.dat
[07:48:04.424] <TB3> INFO: readMaskFile: /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//defaultMaskFile.dat
[07:48:04.424] <TB3> INFO: readTrimFile: /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters_C0.dat .. /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters_C15.dat
[07:48:04.507] <TB3> INFO: clk: 4
[07:48:04.507] <TB3> INFO: ctr: 4
[07:48:04.507] <TB3> INFO: sda: 19
[07:48:04.507] <TB3> INFO: tin: 9
[07:48:04.507] <TB3> INFO: level: 15
[07:48:04.507] <TB3> INFO: triggerdelay: 0
[07:48:04.507] <TB3> QUIET: Instanciating API for pxar v2.2.5+88~g694c14c
[07:48:04.507] <TB3> INFO: Log level: INFO
[07:48:04.515] <TB3> INFO: Found DTB DTB_WZ4I6J
[07:48:04.525] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[07:48:04.529] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 170
HW version: DTB1.2
FW version: 4.0
SW version: 4.0
USB id: DTB_WZ4I6J
MAC address: 40D8551180AA
Hostname: pixelDTB170
Comment:
------------------------------------------------------
[07:48:04.532] <TB3> INFO: RPC call hashes of host and DTB match: 447413373
[07:48:06.093] <TB3> INFO: DUT info:
[07:48:06.093] <TB3> INFO: The DUT currently contains the following objects:
[07:48:06.093] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[07:48:06.093] <TB3> INFO: TBM Core alpha (0): 7 registers set
[07:48:06.093] <TB3> INFO: TBM Core beta (1): 7 registers set
[07:48:06.093] <TB3> INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[07:48:06.093] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.093] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.093] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.093] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.093] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.093] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.094] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[07:48:06.496] <TB3> INFO: enter 'restricted' command line mode
[07:48:06.496] <TB3> INFO: enter test to run
[07:48:06.496] <TB3> INFO: test: pretest no parameter change
[07:48:06.496] <TB3> INFO: running: pretest
[07:48:06.503] <TB3> INFO: ######################################################################
[07:48:06.503] <TB3> INFO: PixTestPretest::doTest()
[07:48:06.503] <TB3> INFO: ######################################################################
[07:48:06.506] <TB3> INFO: ----------------------------------------------------------------------
[07:48:06.506] <TB3> INFO: PixTestPretest::programROC()
[07:48:06.507] <TB3> INFO: ----------------------------------------------------------------------
[07:48:24.525] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[07:48:24.525] <TB3> INFO: IA differences per ROC: 17.7 16.1 20.1 17.7 17.7 19.3 20.1 20.1 18.5 18.5 18.5 20.1 20.1 17.7 18.5 19.3
[07:48:24.597] <TB3> INFO: ----------------------------------------------------------------------
[07:48:24.597] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[07:48:24.597] <TB3> INFO: ----------------------------------------------------------------------
[07:48:44.170] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[07:48:44.175] <TB3> INFO: ----------------------------------------------------------------------
[07:48:44.175] <TB3> INFO: PixTestPretest::findWorkingPixel()
[07:48:44.175] <TB3> INFO: ----------------------------------------------------------------------
[07:48:52.441] <TB3> INFO: Test took 8260ms.
[07:48:52.751] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[07:48:52.791] <TB3> INFO: ----------------------------------------------------------------------
[07:48:52.792] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[07:48:52.792] <TB3> INFO: ----------------------------------------------------------------------
[07:49:01.130] <TB3> INFO: Test took 8332ms.
[07:49:01.417] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[07:49:01.417] <TB3> INFO: CalDel: 125 121 118 136 117 136 150 118 148 143 149 139 130 128 144 142
[07:49:01.417] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[07:49:01.419] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C0.dat
[07:49:01.420] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C1.dat
[07:49:01.420] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C2.dat
[07:49:01.420] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C3.dat
[07:49:01.420] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C4.dat
[07:49:01.420] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C5.dat
[07:49:01.420] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C6.dat
[07:49:01.420] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C7.dat
[07:49:01.420] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C8.dat
[07:49:01.420] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C9.dat
[07:49:01.421] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C10.dat
[07:49:01.421] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C11.dat
[07:49:01.421] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C12.dat
[07:49:01.421] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C13.dat
[07:49:01.421] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C14.dat
[07:49:01.421] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters_C15.dat
[07:49:01.421] <TB3> INFO: PixTestPretest::doTest() done, duration: 54 seconds
[07:49:01.517] <TB3> INFO: enter test to run
[07:49:01.517] <TB3> INFO: test: fulltest no parameter change
[07:49:01.517] <TB3> INFO: running: fulltest
[07:49:01.517] <TB3> INFO: ######################################################################
[07:49:01.517] <TB3> INFO: PixTestFullTest::doTest()
[07:49:01.517] <TB3> INFO: ######################################################################
[07:49:01.518] <TB3> INFO: ######################################################################
[07:49:01.518] <TB3> INFO: PixTestAlive::doTest()
[07:49:01.518] <TB3> INFO: ######################################################################
[07:49:01.520] <TB3> INFO: ----------------------------------------------------------------------
[07:49:01.520] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[07:49:01.520] <TB3> INFO: ----------------------------------------------------------------------
[07:49:04.978] <TB3> INFO: Test took 3456ms.
[07:49:05.000] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:49:05.231] <TB3> INFO: PixTestAlive::aliveTest() done
[07:49:05.231] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 1 1 0 0 0 0 0 0 0 0 0 0 0
[07:49:05.233] <TB3> INFO: ----------------------------------------------------------------------
[07:49:05.233] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[07:49:05.233] <TB3> INFO: ----------------------------------------------------------------------
[07:49:07.981] <TB3> INFO: Test took 2746ms.
[07:49:07.985] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:49:07.985] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[07:49:08.217] <TB3> INFO: PixTestAlive::maskTest() done
[07:49:08.217] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[07:49:08.219] <TB3> INFO: ----------------------------------------------------------------------
[07:49:08.219] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[07:49:08.219] <TB3> INFO: ----------------------------------------------------------------------
[07:49:11.645] <TB3> INFO: Test took 3424ms.
[07:49:11.673] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:49:11.905] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[07:49:11.905] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[07:49:11.905] <TB3> INFO: PixTestAlive::doTest() done, duration: 10 seconds
[07:49:11.918] <TB3> INFO: ######################################################################
[07:49:11.918] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[07:49:11.918] <TB3> INFO: ######################################################################
[07:49:11.922] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (30) hits flags = 2 (plus default)
[07:49:11.977] <TB3> INFO: dacScan step from 0 .. 29
[07:49:33.220] <TB3> INFO: Test took 21243ms.
[07:49:33.257] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:49:33.257] <TB3> INFO: dacScan step from 30 .. 59
[07:49:55.867] <TB3> INFO: Test took 22610ms.
[07:49:55.987] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:49:56.002] <TB3> INFO: dacScan step from 60 .. 89
[07:50:24.867] <TB3> INFO: Test took 28864ms.
[07:50:25.130] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:50:25.202] <TB3> INFO: dacScan step from 90 .. 119
[07:50:53.754] <TB3> INFO: Test took 28552ms.
[07:50:54.021] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:50:54.101] <TB3> INFO: dacScan step from 120 .. 149
[07:51:19.007] <TB3> INFO: Test took 24906ms.
[07:51:19.248] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:51:44.351] <TB3> INFO: PixTestBBMap::doTest() done, duration: 152 seconds
[07:51:44.351] <TB3> INFO: number of dead bumps (per ROC): 5 0 0 0 0 0 0 1 0 0 0 0 0 0 2 10
[07:51:44.351] <TB3> INFO: separation cut (per ROC): 90 89 99 91 94 89 88 113 75 81 95 88 107 92 90 72
[07:51:44.425] <TB3> INFO: ######################################################################
[07:51:44.425] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50
[07:51:44.425] <TB3> INFO: ######################################################################
[07:51:44.425] <TB3> INFO: ----------------------------------------------------------------------
[07:51:44.425] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50
[07:51:44.425] <TB3> INFO: ----------------------------------------------------------------------
[07:51:44.425] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 0 .. 149 (4) hits flags = 16 (plus default)
[07:51:44.434] <TB3> INFO: dacScan step from 0 .. 3
[07:52:03.508] <TB3> INFO: Test took 19073ms.
[07:52:03.540] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:52:03.542] <TB3> INFO: dacScan step from 4 .. 7
[07:52:22.615] <TB3> INFO: Test took 19073ms.
[07:52:22.645] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:52:22.646] <TB3> INFO: dacScan step from 8 .. 11
[07:52:41.730] <TB3> INFO: Test took 19084ms.
[07:52:41.759] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:52:41.759] <TB3> INFO: dacScan step from 12 .. 15
[07:53:00.816] <TB3> INFO: Test took 19057ms.
[07:53:00.842] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:53:00.842] <TB3> INFO: dacScan step from 16 .. 19
[07:53:19.925] <TB3> INFO: Test took 19083ms.
[07:53:19.955] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:53:19.955] <TB3> INFO: dacScan step from 20 .. 23
[07:53:38.976] <TB3> INFO: Test took 19021ms.
[07:53:39.010] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:53:39.011] <TB3> INFO: dacScan step from 24 .. 27
[07:53:58.048] <TB3> INFO: Test took 19037ms.
[07:53:58.078] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:53:58.078] <TB3> INFO: dacScan step from 28 .. 31
[07:54:17.198] <TB3> INFO: Test took 19119ms.
[07:54:17.229] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:54:17.229] <TB3> INFO: dacScan step from 32 .. 35
[07:54:36.320] <TB3> INFO: Test took 19091ms.
[07:54:36.351] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:54:36.351] <TB3> INFO: dacScan step from 36 .. 39
[07:54:55.494] <TB3> INFO: Test took 19143ms.
[07:54:55.522] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:54:55.522] <TB3> INFO: dacScan step from 40 .. 43
[07:55:14.482] <TB3> INFO: Test took 18961ms.
[07:55:14.512] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:55:14.512] <TB3> INFO: dacScan step from 44 .. 47
[07:55:33.585] <TB3> INFO: Test took 19073ms.
[07:55:33.613] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:55:33.613] <TB3> INFO: dacScan step from 48 .. 51
[07:55:52.644] <TB3> INFO: Test took 19031ms.
[07:55:52.681] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:55:52.681] <TB3> INFO: dacScan step from 52 .. 55
[07:56:11.736] <TB3> INFO: Test took 19055ms.
[07:56:11.761] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:56:11.761] <TB3> INFO: dacScan step from 56 .. 59
[07:56:30.864] <TB3> INFO: Test took 19103ms.
[07:56:30.892] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:56:30.892] <TB3> INFO: dacScan step from 60 .. 63
[07:56:49.940] <TB3> INFO: Test took 19048ms.
[07:56:49.971] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:56:49.971] <TB3> INFO: dacScan step from 64 .. 67
[07:57:08.918] <TB3> INFO: Test took 18947ms.
[07:57:08.950] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:57:08.950] <TB3> INFO: dacScan step from 68 .. 71
[07:57:28.172] <TB3> INFO: Test took 19222ms.
[07:57:28.208] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:57:28.208] <TB3> INFO: dacScan step from 72 .. 75
[07:57:47.626] <TB3> INFO: Test took 19418ms.
[07:57:47.683] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:57:47.684] <TB3> INFO: dacScan step from 76 .. 79
[07:58:08.005] <TB3> INFO: Test took 20321ms.
[07:58:08.085] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:58:08.088] <TB3> INFO: dacScan step from 80 .. 83
[07:58:30.421] <TB3> INFO: Test took 22333ms.
[07:58:30.535] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:58:30.541] <TB3> INFO: dacScan step from 84 .. 87
[07:58:54.993] <TB3> INFO: Test took 24452ms.
[07:58:55.146] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:58:55.155] <TB3> INFO: dacScan step from 88 .. 91
[07:59:21.290] <TB3> INFO: Test took 26135ms.
[07:59:21.497] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:59:21.507] <TB3> INFO: dacScan step from 92 .. 95
[07:59:49.182] <TB3> INFO: Test took 27674ms.
[07:59:49.411] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[07:59:49.421] <TB3> INFO: dacScan step from 96 .. 99
[08:00:18.021] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[08:00:18.021] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (119) != TBM ID (120)

[08:00:18.021] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[08:00:18.021] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[08:00:18.032] <TB3> INFO: Test took 28611ms.
[08:00:18.288] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:00:18.299] <TB3> INFO: dacScan step from 100 .. 103
[08:00:47.391] <TB3> INFO: Test took 29092ms.
[08:00:47.663] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:00:47.674] <TB3> INFO: dacScan step from 104 .. 107
[08:01:16.061] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[08:01:16.061] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (155) != TBM ID (156)

[08:01:16.061] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[08:01:16.061] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[08:01:17.212] <TB3> INFO: Test took 29538ms.
[08:01:17.502] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:01:17.517] <TB3> INFO: dacScan step from 108 .. 111
[08:01:45.811] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[08:01:46.997] <TB3> INFO: Test took 29480ms.
[08:01:47.239] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:01:47.254] <TB3> INFO: dacScan step from 112 .. 115
[08:02:16.658] <TB3> INFO: Test took 29403ms.
[08:02:16.948] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:02:16.962] <TB3> INFO: dacScan step from 116 .. 119
[08:02:45.310] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[08:02:46.575] <TB3> INFO: Test took 29613ms.
[08:02:46.798] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:02:46.810] <TB3> INFO: dacScan step from 120 .. 123
[08:03:15.208] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[08:03:15.208] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (195) != TBM ID (196)

[08:03:15.208] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[08:03:15.208] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[08:03:16.529] <TB3> INFO: Test took 29719ms.
[08:03:16.767] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:03:16.783] <TB3> INFO: dacScan step from 124 .. 127
[08:03:46.199] <TB3> INFO: Test took 29416ms.
[08:03:46.441] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:03:46.456] <TB3> INFO: dacScan step from 128 .. 131
[08:04:15.720] <TB3> INFO: Test took 29264ms.
[08:04:15.979] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:04:15.991] <TB3> INFO: dacScan step from 132 .. 135
[08:04:45.334] <TB3> INFO: Test took 29343ms.
[08:04:45.567] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:04:45.580] <TB3> INFO: dacScan step from 136 .. 139
[08:05:13.594] <TB3> INFO: Test took 28014ms.
[08:05:13.832] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:05:13.847] <TB3> INFO: dacScan step from 140 .. 143
[08:05:40.279] <TB3> INFO: Test took 26431ms.
[08:05:40.520] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:05:40.534] <TB3> INFO: dacScan step from 144 .. 147
[08:06:07.203] <TB3> INFO: Test took 26669ms.
[08:06:07.607] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:06:07.629] <TB3> INFO: dacScan step from 148 .. 149
[08:06:22.332] <TB3> INFO: Test took 14703ms.
[08:06:22.455] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:06:22.463] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:24.026] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:25.696] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:27.215] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:28.733] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:30.310] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:31.935] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:33.427] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:34.870] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:36.359] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:37.809] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:39.260] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:40.734] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:42.245] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:43.829] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:45.380] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[08:06:46.917] <TB3> INFO: PixTestScurves::scurves() done
[08:06:46.917] <TB3> INFO: Vcal mean: 91.32 81.47 86.92 86.79 90.59 85.01 86.17 102.50 82.05 82.08 100.82 87.24 96.10 92.93 91.34 76.09
[08:06:46.917] <TB3> INFO: Vcal RMS: 6.33 4.65 5.11 4.91 5.15 5.23 5.02 6.16 4.95 4.13 5.98 4.81 5.49 5.79 5.31 4.78
[08:06:46.917] <TB3> INFO: PixTestScurves::fullTest() done, duration: 902 seconds
[08:06:46.992] <TB3> INFO: ######################################################################
[08:06:46.992] <TB3> INFO: PixTestTrim::doTest()
[08:06:46.992] <TB3> INFO: ######################################################################
[08:06:46.994] <TB3> INFO: ----------------------------------------------------------------------
[08:06:46.994] <TB3> INFO: PixTestTrim::trimTest() ntrig = 10, vcal = 35
[08:06:46.994] <TB3> INFO: ----------------------------------------------------------------------
[08:06:47.079] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[08:06:47.079] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[08:06:47.088] <TB3> INFO: dacScan step from 0 .. 19
[08:07:02.101] <TB3> INFO: Test took 15013ms.
[08:07:02.132] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:07:02.132] <TB3> INFO: dacScan step from 20 .. 39
[08:07:17.227] <TB3> INFO: Test took 15095ms.
[08:07:17.252] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:07:17.252] <TB3> INFO: dacScan step from 40 .. 59
[08:07:31.557] <TB3> INFO: Test took 14305ms.
[08:07:31.578] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:07:31.578] <TB3> INFO: dacScan step from 60 .. 79
[08:07:45.899] <TB3> INFO: Test took 14321ms.
[08:07:45.921] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:07:45.921] <TB3> INFO: dacScan step from 80 .. 99
[08:08:00.781] <TB3> INFO: Test took 14860ms.
[08:08:00.831] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:08:00.838] <TB3> INFO: dacScan step from 100 .. 119
[08:08:19.427] <TB3> INFO: Test took 18589ms.
[08:08:19.597] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:08:19.632] <TB3> INFO: dacScan step from 120 .. 139
[08:08:38.752] <TB3> INFO: Test took 19120ms.
[08:08:38.908] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:08:38.943] <TB3> INFO: dacScan step from 140 .. 159
[08:08:54.696] <TB3> INFO: Test took 15753ms.
[08:08:54.809] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:09:15.905] <TB3> INFO: ROC 0 VthrComp = 94
[08:09:15.905] <TB3> INFO: ROC 1 VthrComp = 87
[08:09:15.905] <TB3> INFO: ROC 2 VthrComp = 96
[08:09:15.906] <TB3> INFO: ROC 3 VthrComp = 93
[08:09:15.906] <TB3> INFO: ROC 4 VthrComp = 98
[08:09:15.906] <TB3> INFO: ROC 5 VthrComp = 89
[08:09:15.906] <TB3> INFO: ROC 6 VthrComp = 92
[08:09:15.906] <TB3> INFO: ROC 7 VthrComp = 104
[08:09:15.906] <TB3> INFO: ROC 8 VthrComp = 85
[08:09:15.906] <TB3> INFO: ROC 9 VthrComp = 90
[08:09:15.906] <TB3> INFO: ROC 10 VthrComp = 101
[08:09:15.906] <TB3> INFO: ROC 11 VthrComp = 94
[08:09:15.907] <TB3> INFO: ROC 12 VthrComp = 104
[08:09:15.907] <TB3> INFO: ROC 13 VthrComp = 95
[08:09:15.907] <TB3> INFO: ROC 14 VthrComp = 97
[08:09:15.907] <TB3> INFO: ROC 15 VthrComp = 81
[08:09:15.907] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[08:09:15.907] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 5 dacrange: 0 .. 159 (20) hits flags = 16 (plus default)
[08:09:15.916] <TB3> INFO: dacScan step from 0 .. 19
[08:09:31.077] <TB3> INFO: Test took 15161ms.
[08:09:31.102] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:09:31.102] <TB3> INFO: dacScan step from 20 .. 39
[08:09:46.384] <TB3> INFO: Test took 15282ms.
[08:09:46.416] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:09:46.419] <TB3> INFO: dacScan step from 40 .. 59
[08:10:05.060] <TB3> INFO: Test took 18641ms.
[08:10:05.211] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:10:05.251] <TB3> INFO: dacScan step from 60 .. 79
[08:10:24.029] <TB3> INFO: Test took 18778ms.
[08:10:24.286] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:10:24.358] <TB3> INFO: dacScan step from 80 .. 99
[08:10:43.231] <TB3> INFO: Test took 18872ms.
[08:10:43.401] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:10:43.459] <TB3> INFO: dacScan step from 100 .. 119
[08:11:03.660] <TB3> INFO: Test took 20201ms.
[08:11:03.830] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:11:03.887] <TB3> INFO: dacScan step from 120 .. 139
[08:11:24.069] <TB3> INFO: Test took 20182ms.
[08:11:24.233] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:11:24.287] <TB3> INFO: dacScan step from 140 .. 159
[08:11:43.090] <TB3> INFO: Test took 18803ms.
[08:11:43.264] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:12:07.086] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 63.2379 for pixel 22/77 mean/min/max = 47.4407/31.4474/63.4341
[08:12:07.086] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 58.3991 for pixel 0/8 mean/min/max = 45.0592/31.6565/58.4618
[08:12:07.087] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 56.572 for pixel 14/1 mean/min/max = 44.2252/31.8748/56.5757
[08:12:07.087] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 57.1136 for pixel 17/13 mean/min/max = 44.9867/32.8134/57.1601
[08:12:07.087] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 56.779 for pixel 12/64 mean/min/max = 44.1244/31.3667/56.882
[08:12:07.087] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 59.5892 for pixel 26/47 mean/min/max = 46.2274/32.6803/59.7745
[08:12:07.088] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 57.4351 for pixel 0/39 mean/min/max = 45.0035/32.1364/57.8705
[08:12:07.088] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 61.9722 for pixel 20/76 mean/min/max = 47.8258/33.4044/62.2472
[08:12:07.088] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 59.3624 for pixel 6/2 mean/min/max = 45.9684/32.5472/59.3896
[08:12:07.088] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 57.0145 for pixel 5/78 mean/min/max = 45.1224/33.2257/57.0192
[08:12:07.089] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 62.3788 for pixel 12/5 mean/min/max = 47.632/32.7159/62.5482
[08:12:07.089] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 57.353 for pixel 17/11 mean/min/max = 44.8147/32.0983/57.5311
[08:12:07.089] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 59.8392 for pixel 19/0 mean/min/max = 46.3816/32.8412/59.9219
[08:12:07.089] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 60.9466 for pixel 18/0 mean/min/max = 46.1728/31.3932/60.9525
[08:12:07.090] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 57.7793 for pixel 33/2 mean/min/max = 44.8158/31.7879/57.8436
[08:12:07.090] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 58.3491 for pixel 12/46 mean/min/max = 45.1094/31.8644/58.3543
[08:12:07.090] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:13:39.936] <TB3> INFO: Test took 92846ms.
[08:13:41.459] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[08:13:41.468] <TB3> INFO: dacScan step from 0 .. 19
[08:14:04.283] <TB3> INFO: Test took 22815ms.
[08:14:04.330] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:14:04.333] <TB3> INFO: dacScan step from 20 .. 39
[08:14:32.796] <TB3> INFO: Test took 28463ms.
[08:14:33.030] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:14:33.061] <TB3> INFO: dacScan step from 40 .. 59
[08:15:05.057] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[08:15:06.325] <TB3> INFO: Test took 33264ms.
[08:15:06.604] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:15:06.654] <TB3> INFO: dacScan step from 60 .. 79
[08:15:38.094] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[08:15:39.303] <TB3> INFO: Test took 32649ms.
[08:15:39.595] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:15:39.647] <TB3> INFO: dacScan step from 80 .. 99
[08:16:11.460] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[08:16:11.460] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (196) != TBM ID (197)

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

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

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

[08:16:12.728] <TB3> INFO: Test took 33081ms.
[08:16:13.008] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:16:13.059] <TB3> INFO: dacScan step from 100 .. 119
[08:16:46.341] <TB3> INFO: Test took 33282ms.
[08:16:46.633] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:16:46.685] <TB3> INFO: dacScan step from 120 .. 139
[08:17:18.365] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[08:17:19.645] <TB3> INFO: Test took 32960ms.
[08:17:19.909] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:17:19.967] <TB3> INFO: dacScan step from 140 .. 159
[08:17:51.823] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[08:17:51.823] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (199) != TBM ID (200)

[08:17:51.823] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 15 readouts!

[08:17:51.823] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 15 readouts!

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

[08:17:53.099] <TB3> INFO: Test took 33132ms.
[08:17:53.386] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:17:53.437] <TB3> INFO: dacScan step from 160 .. 179
[08:18:25.355] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[08:18:26.587] <TB3> INFO: Test took 33150ms.
[08:18:26.897] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:18:26.948] <TB3> INFO: dacScan step from 180 .. 199
[08:19:00.068] <TB3> INFO: Test took 33120ms.
[08:19:00.334] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:19:25.859] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 0.162258 .. 255.000000
[08:19:25.936] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 4 dacrange: 0 .. 255 (20) hits flags = 16 (plus default)
[08:19:25.945] <TB3> INFO: dacScan step from 0 .. 19
[08:19:39.507] <TB3> INFO: Test took 13562ms.
[08:19:39.533] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:19:39.533] <TB3> INFO: dacScan step from 20 .. 39
[08:19:54.473] <TB3> INFO: Test took 14940ms.
[08:19:54.559] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:19:54.574] <TB3> INFO: dacScan step from 40 .. 59
[08:20:12.074] <TB3> INFO: Test took 17500ms.
[08:20:12.266] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:20:12.325] <TB3> INFO: dacScan step from 60 .. 79
[08:20:30.095] <TB3> INFO: Test took 17770ms.
[08:20:30.259] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:20:30.312] <TB3> INFO: dacScan step from 80 .. 99
[08:20:47.997] <TB3> INFO: Test took 17685ms.
[08:20:48.144] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:20:48.195] <TB3> INFO: dacScan step from 100 .. 119
[08:21:04.596] <TB3> INFO: Test took 16401ms.
[08:21:04.821] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:21:04.901] <TB3> INFO: dacScan step from 120 .. 139
[08:21:21.657] <TB3> INFO: Test took 16756ms.
[08:21:21.877] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:21:21.938] <TB3> INFO: dacScan step from 140 .. 159
[08:21:38.480] <TB3> INFO: Test took 16542ms.
[08:21:38.625] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:21:38.674] <TB3> INFO: dacScan step from 160 .. 179
[08:21:56.380] <TB3> INFO: Test took 17706ms.
[08:21:56.559] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:21:56.606] <TB3> INFO: dacScan step from 180 .. 199
[08:22:14.965] <TB3> INFO: Test took 18359ms.
[08:22:15.103] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:22:15.156] <TB3> INFO: dacScan step from 200 .. 219
[08:22:32.760] <TB3> INFO: Test took 17604ms.
[08:22:32.897] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:22:32.945] <TB3> INFO: dacScan step from 220 .. 239
[08:22:50.502] <TB3> INFO: Test took 17557ms.
[08:22:50.648] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:22:50.700] <TB3> INFO: dacScan step from 240 .. 255
[08:23:04.525] <TB3> INFO: Test took 13825ms.
[08:23:04.641] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:23:35.837] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 13.867504 .. 46.658140
[08:23:35.917] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 4 dacrange: 3 .. 56 (20) hits flags = 16 (plus default)
[08:23:35.926] <TB3> INFO: dacScan step from 3 .. 22
[08:23:49.481] <TB3> INFO: Test took 13555ms.
[08:23:49.506] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:23:49.506] <TB3> INFO: dacScan step from 23 .. 42
[08:24:04.748] <TB3> INFO: Test took 15242ms.
[08:24:04.864] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:24:04.889] <TB3> INFO: dacScan step from 43 .. 56
[08:24:18.127] <TB3> INFO: Test took 13238ms.
[08:24:18.235] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:24:34.902] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 4.620083 .. 43.486680
[08:24:34.983] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 4 dacrange: 4 .. 53 (20) hits flags = 16 (plus default)
[08:24:34.991] <TB3> INFO: dacScan step from 4 .. 23
[08:24:48.537] <TB3> INFO: Test took 13546ms.
[08:24:48.561] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:24:48.561] <TB3> INFO: dacScan step from 24 .. 43
[08:25:03.968] <TB3> INFO: Test took 15407ms.
[08:25:04.068] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:25:04.093] <TB3> INFO: dacScan step from 44 .. 53
[08:25:14.329] <TB3> INFO: Test took 10236ms.
[08:25:14.402] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:25:30.385] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 1.016035 .. 42.850125
[08:25:30.461] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 4 dacrange: 1 .. 52 (20) hits flags = 16 (plus default)
[08:25:30.469] <TB3> INFO: dacScan step from 1 .. 20
[08:25:43.620] <TB3> INFO: Test took 13151ms.
[08:25:43.639] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:25:43.639] <TB3> INFO: dacScan step from 21 .. 40
[08:25:57.675] <TB3> INFO: Test took 14036ms.
[08:25:57.759] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:25:57.779] <TB3> INFO: dacScan step from 41 .. 52
[08:26:09.027] <TB3> INFO: Test took 11248ms.
[08:26:09.119] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:26:24.276] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[08:26:24.276] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 10 dacrange: 15 .. 55 (20) hits flags = 16 (plus default)
[08:26:24.285] <TB3> INFO: dacScan step from 15 .. 34
[08:26:45.939] <TB3> INFO: Test took 21654ms.
[08:26:46.008] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:26:46.020] <TB3> INFO: dacScan step from 35 .. 54
[08:27:16.569] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[08:27:17.279] <TB3> INFO: Test took 31259ms.
[08:27:17.554] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:27:17.603] <TB3> INFO: dacScan step from 55 .. 55
[08:27:21.794] <TB3> INFO: Test took 4191ms.
[08:27:21.808] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:27:35.465] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C0.dat
[08:27:35.465] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C1.dat
[08:27:35.465] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C2.dat
[08:27:35.465] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C3.dat
[08:27:35.466] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C4.dat
[08:27:35.466] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C5.dat
[08:27:35.466] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C6.dat
[08:27:35.466] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C7.dat
[08:27:35.466] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C8.dat
[08:27:35.466] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C9.dat
[08:27:35.466] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C10.dat
[08:27:35.467] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C11.dat
[08:27:35.467] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C12.dat
[08:27:35.467] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C13.dat
[08:27:35.467] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C14.dat
[08:27:35.467] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C15.dat
[08:27:35.467] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C0.dat
[08:27:35.477] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C1.dat
[08:27:35.487] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C2.dat
[08:27:35.497] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C3.dat
[08:27:35.507] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C4.dat
[08:27:35.517] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C5.dat
[08:27:35.527] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C6.dat
[08:27:35.537] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C7.dat
[08:27:35.547] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C8.dat
[08:27:35.557] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C9.dat
[08:27:35.567] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C10.dat
[08:27:35.577] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C11.dat
[08:27:35.587] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C12.dat
[08:27:35.597] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C13.dat
[08:27:35.607] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C14.dat
[08:27:35.617] <TB3> INFO: write trim parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//trimParameters35_C15.dat
[08:27:35.626] <TB3> INFO: PixTestTrim::trimTest() done
[08:27:35.626] <TB3> INFO: vtrim: 155 107 104 108 103 116 102 123 99 102 119 113 118 122 95 107
[08:27:35.626] <TB3> INFO: vthrcomp: 94 87 96 93 98 89 92 104 85 90 101 94 104 95 97 81
[08:27:35.627] <TB3> INFO: vcal mean: 35.07 35.01 35.02 35.04 34.99 35.04 35.01 35.05 35.03 35.05 35.06 35.02 35.04 35.04 35.06 35.08
[08:27:35.627] <TB3> INFO: vcal RMS: 1.26 1.01 1.04 1.14 1.22 1.01 1.01 1.06 1.00 0.99 1.21 0.96 0.99 1.07 0.98 1.03
[08:27:35.627] <TB3> INFO: bits mean: 9.80 10.03 10.40 10.04 10.35 9.57 9.21 9.29 9.68 9.69 9.40 9.85 9.46 9.90 9.87 10.02
[08:27:35.627] <TB3> INFO: bits RMS: 2.52 2.56 2.38 2.43 2.45 2.60 2.83 2.46 2.51 2.47 2.57 2.56 2.54 2.55 2.61 2.50
[08:27:35.635] <TB3> INFO: ----------------------------------------------------------------------
[08:27:35.635] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 10, vtrims = 254 126 63 32
[08:27:35.635] <TB3> INFO: ----------------------------------------------------------------------
[08:27:35.638] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 10 dacrange: 0 .. 199 (20) hits flags = 16 (plus default)
[08:27:35.650] <TB3> INFO: dacScan step from 0 .. 19
[08:27:56.835] <TB3> INFO: Test took 21185ms.
[08:27:56.869] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:27:56.869] <TB3> INFO: dacScan step from 20 .. 39
[08:28:19.064] <TB3> INFO: Test took 22195ms.
[08:28:19.100] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:28:19.100] <TB3> INFO: dacScan step from 40 .. 59
[08:28:41.631] <TB3> INFO: Test took 22531ms.
[08:28:41.667] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:28:41.667] <TB3> INFO: dacScan step from 60 .. 79
[08:29:03.735] <TB3> INFO: Test took 22068ms.
[08:29:03.773] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:29:03.773] <TB3> INFO: dacScan step from 80 .. 99
[08:29:26.718] <TB3> INFO: Test took 22945ms.
[08:29:26.775] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:29:26.778] <TB3> INFO: dacScan step from 100 .. 119
[08:29:52.525] <TB3> INFO: Test took 25747ms.
[08:29:52.722] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:29:52.745] <TB3> INFO: dacScan step from 120 .. 139
[08:30:23.171] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[08:30:23.964] <TB3> INFO: Test took 31219ms.
[08:30:24.247] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:30:24.293] <TB3> INFO: dacScan step from 140 .. 159
[08:30:57.428] <TB3> INFO: Test took 33135ms.
[08:30:57.709] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:30:57.775] <TB3> INFO: dacScan step from 160 .. 179
[08:31:30.926] <TB3> INFO: Test took 33151ms.
[08:31:31.212] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:31:31.261] <TB3> INFO: dacScan step from 180 .. 199
[08:32:05.178] <TB3> INFO: Test took 33917ms.
[08:32:05.480] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:32:33.662] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 10 dacrange: 0 .. 164 (20) hits flags = 16 (plus default)
[08:32:33.671] <TB3> INFO: dacScan step from 0 .. 19
[08:32:54.884] <TB3> INFO: Test took 21213ms.
[08:32:54.930] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:32:54.930] <TB3> INFO: dacScan step from 20 .. 39
[08:33:17.667] <TB3> INFO: Test took 22737ms.
[08:33:17.710] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:33:17.710] <TB3> INFO: dacScan step from 40 .. 59
[08:33:40.368] <TB3> INFO: Test took 22658ms.
[08:33:40.405] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:33:40.405] <TB3> INFO: dacScan step from 60 .. 79
[08:34:03.114] <TB3> INFO: Test took 22708ms.
[08:34:03.149] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:34:03.149] <TB3> INFO: dacScan step from 80 .. 99
[08:34:27.239] <TB3> INFO: Test took 24090ms.
[08:34:27.336] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:34:27.346] <TB3> INFO: dacScan step from 100 .. 119
[08:34:55.848] <TB3> INFO: Test took 28502ms.
[08:34:56.109] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:34:56.146] <TB3> INFO: dacScan step from 120 .. 139
[08:35:25.536] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[08:35:26.571] <TB3> INFO: Test took 30424ms.
[08:35:26.854] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:35:26.911] <TB3> INFO: dacScan step from 140 .. 159
[08:35:57.511] <TB3> INFO: Test took 30600ms.
[08:35:57.801] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:35:57.880] <TB3> INFO: dacScan step from 160 .. 164
[08:36:07.673] <TB3> INFO: Test took 9793ms.
[08:36:07.791] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:36:32.519] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 10 dacrange: 0 .. 152 (20) hits flags = 16 (plus default)
[08:36:32.528] <TB3> INFO: dacScan step from 0 .. 19
[08:36:54.279] <TB3> INFO: Test took 21751ms.
[08:36:54.315] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:36:54.315] <TB3> INFO: dacScan step from 20 .. 39
[08:37:16.850] <TB3> INFO: Test took 22535ms.
[08:37:16.891] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:37:16.891] <TB3> INFO: dacScan step from 40 .. 59
[08:37:39.558] <TB3> INFO: Test took 22667ms.
[08:37:39.601] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:37:39.601] <TB3> INFO: dacScan step from 60 .. 79
[08:38:02.402] <TB3> INFO: Test took 22801ms.
[08:38:02.442] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:02.443] <TB3> INFO: dacScan step from 80 .. 99
[08:38:26.404] <TB3> INFO: Test took 23961ms.
[08:38:26.503] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:26.514] <TB3> INFO: dacScan step from 100 .. 119
[08:38:57.433] <TB3> INFO: Test took 30919ms.
[08:38:57.698] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:38:57.729] <TB3> INFO: dacScan step from 120 .. 139
[08:39:29.679] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (3) != Token Chain Length (4)

[08:39:30.736] <TB3> INFO: Test took 33006ms.
[08:39:31.035] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:39:31.095] <TB3> INFO: dacScan step from 140 .. 152
[08:39:51.601] <TB3> INFO: Test took 20506ms.
[08:39:51.776] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:40:13.562] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 10 dacrange: 0 .. 152 (20) hits flags = 16 (plus default)
[08:40:13.571] <TB3> INFO: dacScan step from 0 .. 19
[08:40:36.276] <TB3> INFO: Test took 22705ms.
[08:40:36.315] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:40:36.315] <TB3> INFO: dacScan step from 20 .. 39
[08:40:59.057] <TB3> INFO: Test took 22742ms.
[08:40:59.095] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:40:59.095] <TB3> INFO: dacScan step from 40 .. 59
[08:41:21.793] <TB3> INFO: Test took 22698ms.
[08:41:21.827] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:41:21.827] <TB3> INFO: dacScan step from 60 .. 79
[08:41:44.513] <TB3> INFO: Test took 22685ms.
[08:41:44.550] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:41:44.550] <TB3> INFO: dacScan step from 80 .. 99
[08:42:08.470] <TB3> INFO: Test took 23920ms.
[08:42:08.565] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:42:08.575] <TB3> INFO: dacScan step from 100 .. 119
[08:42:39.404] <TB3> INFO: Test took 30829ms.
[08:42:39.674] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:42:39.709] <TB3> INFO: dacScan step from 120 .. 139
[08:43:11.571] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (8) != Token Chain Length (4)

[08:43:11.571] <TB3> ERROR: <datapipe.cc/CheckEventID:L420> Channel 3 Event ID mismatch: local ID (127) != TBM ID (128)

[08:43:11.571] <TB3> WARNING: Channel 3 ROC 1: Readback start marker after 31 readouts!

[08:43:11.571] <TB3> WARNING: Channel 3 ROC 2: Readback start marker after 31 readouts!

[08:43:11.571] <TB3> WARNING: Channel 3 ROC 3: Readback start marker after 31 readouts!

[08:43:12.830] <TB3> INFO: Test took 33121ms.
[08:43:13.103] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:43:13.152] <TB3> INFO: dacScan step from 140 .. 152
[08:43:34.586] <TB3> INFO: Test took 21434ms.
[08:43:34.761] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:43:56.964] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 10 dacrange: 0 .. 152 (20) hits flags = 16 (plus default)
[08:43:56.974] <TB3> INFO: dacScan step from 0 .. 19
[08:44:19.702] <TB3> INFO: Test took 22728ms.
[08:44:19.737] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:44:19.737] <TB3> INFO: dacScan step from 20 .. 39
[08:44:40.949] <TB3> INFO: Test took 21211ms.
[08:44:40.983] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:44:40.984] <TB3> INFO: dacScan step from 40 .. 59
[08:45:03.583] <TB3> INFO: Test took 22599ms.
[08:45:03.619] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:45:03.619] <TB3> INFO: dacScan step from 60 .. 79
[08:45:26.290] <TB3> INFO: Test took 22671ms.
[08:45:26.331] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:45:26.331] <TB3> INFO: dacScan step from 80 .. 99
[08:45:50.308] <TB3> INFO: Test took 23977ms.
[08:45:50.405] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:45:50.415] <TB3> INFO: dacScan step from 100 .. 119
[08:46:21.536] <TB3> INFO: Test took 31121ms.
[08:46:21.800] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:46:21.834] <TB3> INFO: dacScan step from 120 .. 139
[08:46:53.989] <TB3> ERROR: <datapipe.cc/CheckEventValidity:L437> Channel 3 Number of ROCs (2) != Token Chain Length (4)

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

[08:46:55.206] <TB3> INFO: Test took 33372ms.
[08:46:55.476] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:46:55.525] <TB3> INFO: dacScan step from 140 .. 152
[08:47:17.607] <TB3> INFO: Test took 22082ms.
[08:47:17.781] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:47:39.928] <TB3> INFO: PixTestTrim::trimBitTest() done
[08:47:39.929] <TB3> INFO: PixTestTrim::doTest() done, duration: 2452 seconds
[08:47:40.609] <TB3> INFO: ######################################################################
[08:47:40.609] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[08:47:40.609] <TB3> INFO: ######################################################################
[08:47:43.891] <TB3> INFO: Test took 3280ms.
[08:47:43.910] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:47:47.533] <TB3> INFO: Test took 3427ms.
[08:47:47.603] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:47:51.048] <TB3> INFO: Test took 3434ms.
[08:47:51.116] <TB3> INFO: Fetched DAQ statistics. Counters are being reset now.
[08:47:51.123] <TB3> INFO: The DUT currently contains the following objects:
[08:47:51.123] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:47:51.123] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:47:51.123] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:47:51.123] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:47:51.123] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.123] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.123] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.123] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.123] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.123] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.123] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.123] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.123] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.124] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.124] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.124] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.124] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.124] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.124] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:51.124] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.233] <TB3> INFO: Test took 1109ms.
[08:47:52.235] <TB3> INFO: The DUT currently contains the following objects:
[08:47:52.235] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:47:52.235] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:47:52.235] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:47:52.235] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:47:52.235] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.235] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.236] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:52.236] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.342] <TB3> INFO: Test took 1106ms.
[08:47:53.343] <TB3> INFO: The DUT currently contains the following objects:
[08:47:53.343] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:47:53.343] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:47:53.343] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:47:53.343] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:47:53.343] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.343] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.343] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.343] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.343] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.343] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.343] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.343] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.344] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.344] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.344] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.344] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.344] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.344] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.344] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:53.344] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.451] <TB3> INFO: Test took 1107ms.
[08:47:54.452] <TB3> INFO: The DUT currently contains the following objects:
[08:47:54.452] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:47:54.452] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:47:54.452] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:47:54.452] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:47:54.452] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.452] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.452] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.452] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.452] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:54.453] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.560] <TB3> INFO: Test took 1107ms.
[08:47:55.561] <TB3> INFO: The DUT currently contains the following objects:
[08:47:55.561] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:47:55.561] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:47:55.561] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:47:55.561] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:47:55.561] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.561] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.561] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.561] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.561] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.561] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.561] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.561] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.561] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.561] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.562] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.562] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.562] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.562] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.562] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:55.562] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.669] <TB3> INFO: Test took 1107ms.
[08:47:56.670] <TB3> INFO: The DUT currently contains the following objects:
[08:47:56.670] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:47:56.670] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:47:56.670] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:47:56.671] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:47:56.671] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:56.671] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.779] <TB3> INFO: Test took 1108ms.
[08:47:57.781] <TB3> INFO: The DUT currently contains the following objects:
[08:47:57.781] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:47:57.781] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:47:57.781] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:47:57.781] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:47:57.781] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.781] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.782] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.782] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.782] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.782] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:57.782] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.890] <TB3> INFO: Test took 1108ms.
[08:47:58.891] <TB3> INFO: The DUT currently contains the following objects:
[08:47:58.891] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:47:58.891] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:47:58.891] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:47:58.891] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:47:58.891] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.892] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.893] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.893] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.893] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.893] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:58.893] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:47:59.999] <TB3> INFO: Test took 1106ms.
[08:48:00.001] <TB3> INFO: The DUT currently contains the following objects:
[08:48:00.001] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:48:00.001] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:48:00.001] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:48:00.001] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:48:00.001] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.001] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.001] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.001] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.001] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.001] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.001] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.001] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.001] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.001] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.002] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.002] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.002] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.002] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.002] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:00.002] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.110] <TB3> INFO: Test took 1108ms.
[08:48:01.111] <TB3> INFO: The DUT currently contains the following objects:
[08:48:01.111] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:48:01.111] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:48:01.111] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:48:01.111] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:48:01.111] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.111] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.111] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.111] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.111] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.111] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.111] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.111] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.111] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.111] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.112] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.112] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.112] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.112] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.112] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:01.112] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.219] <TB3> INFO: Test took 1107ms.
[08:48:02.220] <TB3> INFO: The DUT currently contains the following objects:
[08:48:02.220] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:48:02.220] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:48:02.220] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:48:02.220] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:48:02.220] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:02.221] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.329] <TB3> INFO: Test took 1108ms.
[08:48:03.330] <TB3> INFO: The DUT currently contains the following objects:
[08:48:03.330] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:48:03.330] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:48:03.330] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:48:03.330] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:48:03.330] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.330] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.330] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.330] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.330] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.330] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.330] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.330] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.331] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.331] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.331] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.331] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.331] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.331] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.331] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:03.331] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.437] <TB3> INFO: Test took 1106ms.
[08:48:04.439] <TB3> INFO: The DUT currently contains the following objects:
[08:48:04.439] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:48:04.439] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:48:04.439] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:48:04.439] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:48:04.439] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.439] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:04.440] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.547] <TB3> INFO: Test took 1107ms.
[08:48:05.549] <TB3> INFO: The DUT currently contains the following objects:
[08:48:05.549] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:48:05.549] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:48:05.549] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:48:05.549] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:48:05.549] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.549] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.550] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.550] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.550] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.550] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:05.550] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.657] <TB3> INFO: Test took 1107ms.
[08:48:06.658] <TB3> INFO: The DUT currently contains the following objects:
[08:48:06.658] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:48:06.658] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:48:06.658] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:48:06.658] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:48:06.658] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.658] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.658] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.658] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.658] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.658] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.658] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.658] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.658] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.658] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.659] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.659] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.659] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.659] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.659] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:06.659] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.765] <TB3> INFO: Test took 1106ms.
[08:48:07.766] <TB3> INFO: The DUT currently contains the following objects:
[08:48:07.766] <TB3> INFO: 2 TBM Cores tbm09c (2 ON)
[08:48:07.766] <TB3> INFO: TBM Core alpha (0): 7 registers set
[08:48:07.766] <TB3> INFO: TBM Core beta (1): 7 registers set
[08:48:07.766] <TB3> INFO: 16 ROCs psi46digv21respin (1 ON) with 4160 pixelConfigs
[08:48:07.766] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.766] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.766] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:07.767] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 4159 masked, 1 active.
[08:48:08.875] <TB3> INFO: Test took 1108ms.
[08:48:08.879] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:51:50.840] <TB3> INFO: Test took 221961ms.
[08:51:52.634] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:55:37.252] <TB3> INFO: Test took 224618ms.
[08:55:39.233] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.241] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.249] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.257] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.267] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.276] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.284] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.291] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.298] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.306] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.314] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.322] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.329] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.337] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.344] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.352] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[08:55:39.360] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[08:55:39.368] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[08:55:39.376] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[08:55:39.428] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C0.dat
[08:55:39.492] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C1.dat
[08:55:39.504] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C2.dat
[08:55:39.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C3.dat
[08:55:39.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C4.dat
[08:55:39.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C5.dat
[08:55:39.505] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C6.dat
[08:55:39.512] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C7.dat
[08:55:39.512] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C8.dat
[08:55:39.512] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C9.dat
[08:55:39.513] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C10.dat
[08:55:39.518] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C11.dat
[08:55:39.548] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C12.dat
[08:55:39.548] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C13.dat
[08:55:39.566] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C14.dat
[08:55:39.595] <TB3> INFO: write dac parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//dacParameters35_C15.dat
[08:55:43.035] <TB3> INFO: Test took 3436ms.
[08:55:46.767] <TB3> INFO: Test took 3438ms.
[08:55:50.475] <TB3> INFO: Test took 3426ms.
[08:55:50.757] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:55:51.673] <TB3> INFO: Test took 916ms.
[08:55:51.676] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:55:52.785] <TB3> INFO: Test took 1109ms.
[08:55:52.789] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:55:53.897] <TB3> INFO: Test took 1108ms.
[08:55:53.901] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:55:55.005] <TB3> INFO: Test took 1104ms.
[08:55:55.008] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:55:56.118] <TB3> INFO: Test took 1110ms.
[08:55:56.120] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:55:57.227] <TB3> INFO: Test took 1107ms.
[08:55:57.231] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:55:58.337] <TB3> INFO: Test took 1106ms.
[08:55:58.340] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:55:59.448] <TB3> INFO: Test took 1108ms.
[08:55:59.452] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:00.558] <TB3> INFO: Test took 1107ms.
[08:56:00.563] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:01.670] <TB3> INFO: Test took 1108ms.
[08:56:01.674] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:02.781] <TB3> INFO: Test took 1108ms.
[08:56:02.785] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:03.891] <TB3> INFO: Test took 1107ms.
[08:56:03.895] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:05.005] <TB3> INFO: Test took 1110ms.
[08:56:05.009] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:06.118] <TB3> INFO: Test took 1109ms.
[08:56:06.122] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:07.230] <TB3> INFO: Test took 1108ms.
[08:56:07.233] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:08.341] <TB3> INFO: Test took 1108ms.
[08:56:08.344] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:09.452] <TB3> INFO: Test took 1108ms.
[08:56:09.456] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:10.564] <TB3> INFO: Test took 1108ms.
[08:56:10.567] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:11.675] <TB3> INFO: Test took 1108ms.
[08:56:11.678] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:12.787] <TB3> INFO: Test took 1109ms.
[08:56:12.791] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:13.901] <TB3> INFO: Test took 1111ms.
[08:56:13.905] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:15.012] <TB3> INFO: Test took 1108ms.
[08:56:15.016] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:16.124] <TB3> INFO: Test took 1108ms.
[08:56:16.127] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:17.232] <TB3> INFO: Test took 1105ms.
[08:56:17.235] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:18.336] <TB3> INFO: Test took 1101ms.
[08:56:18.340] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:19.445] <TB3> INFO: Test took 1105ms.
[08:56:19.451] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:20.558] <TB3> INFO: Test took 1108ms.
[08:56:20.561] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:21.668] <TB3> INFO: Test took 1107ms.
[08:56:21.672] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:22.781] <TB3> INFO: Test took 1109ms.
[08:56:22.785] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:23.893] <TB3> INFO: Test took 1109ms.
[08:56:23.898] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:25.007] <TB3> INFO: Test took 1110ms.
[08:56:25.010] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[08:56:26.118] <TB3> INFO: Test took 1108ms.
[08:56:26.665] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 526 seconds
[08:56:26.665] <TB3> INFO: PH scale (per ROC): 82 90 82 95 87 94 84 77 80 81 78 84 87 81 77 80
[08:56:26.665] <TB3> INFO: PH offset (per ROC): 162 155 160 154 154 166 159 174 154 162 166 161 161 189 157 142
[08:56:26.932] <TB3> INFO: ######################################################################
[08:56:26.932] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[08:56:26.932] <TB3> INFO: ######################################################################
[08:56:26.943] <TB3> INFO: scanning low vcal = 10
[08:56:30.792] <TB3> INFO: Test took 3849ms.
[08:56:30.797] <TB3> INFO: scanning low vcal = 20
[08:56:34.644] <TB3> INFO: Test took 3847ms.
[08:56:34.649] <TB3> INFO: scanning low vcal = 30
[08:56:38.533] <TB3> INFO: Test took 3884ms.
[08:56:38.547] <TB3> INFO: scanning low vcal = 40
[08:56:42.922] <TB3> INFO: Test took 4375ms.
[08:56:42.977] <TB3> INFO: scanning low vcal = 50
[08:56:47.339] <TB3> INFO: Test took 4362ms.
[08:56:47.407] <TB3> INFO: scanning low vcal = 60
[08:56:51.741] <TB3> INFO: Test took 4334ms.
[08:56:51.804] <TB3> INFO: scanning low vcal = 70
[08:56:56.182] <TB3> INFO: Test took 4378ms.
[08:56:56.246] <TB3> INFO: scanning low vcal = 80
[08:57:00.608] <TB3> INFO: Test took 4362ms.
[08:57:00.669] <TB3> INFO: scanning low vcal = 90
[08:57:05.092] <TB3> INFO: Test took 4423ms.
[08:57:05.169] <TB3> INFO: scanning low vcal = 100
[08:57:09.519] <TB3> INFO: Test took 4350ms.
[08:57:09.585] <TB3> INFO: scanning low vcal = 110
[08:57:13.957] <TB3> INFO: Test took 4372ms.
[08:57:14.017] <TB3> INFO: scanning low vcal = 120
[08:57:18.389] <TB3> INFO: Test took 4372ms.
[08:57:18.450] <TB3> INFO: scanning low vcal = 130
[08:57:22.814] <TB3> INFO: Test took 4364ms.
[08:57:22.882] <TB3> INFO: scanning low vcal = 140
[08:57:27.135] <TB3> INFO: Test took 4253ms.
[08:57:27.205] <TB3> INFO: scanning low vcal = 150
[08:57:31.595] <TB3> INFO: Test took 4390ms.
[08:57:31.657] <TB3> INFO: scanning low vcal = 160
[08:57:36.026] <TB3> INFO: Test took 4369ms.
[08:57:36.089] <TB3> INFO: scanning low vcal = 170
[08:57:40.494] <TB3> INFO: Test took 4406ms.
[08:57:40.565] <TB3> INFO: scanning low vcal = 180
[08:57:44.955] <TB3> INFO: Test took 4390ms.
[08:57:45.025] <TB3> INFO: scanning low vcal = 190
[08:57:49.499] <TB3> INFO: Test took 4474ms.
[08:57:49.558] <TB3> INFO: scanning low vcal = 200
[08:57:53.940] <TB3> INFO: Test took 4382ms.
[08:57:54.007] <TB3> INFO: scanning low vcal = 210
[08:57:58.374] <TB3> INFO: Test took 4367ms.
[08:57:58.438] <TB3> INFO: scanning low vcal = 220
[08:58:02.834] <TB3> INFO: Test took 4396ms.
[08:58:02.898] <TB3> INFO: scanning low vcal = 230
[08:58:07.263] <TB3> INFO: Test took 4365ms.
[08:58:07.326] <TB3> INFO: scanning low vcal = 240
[08:58:11.683] <TB3> INFO: Test took 4357ms.
[08:58:11.747] <TB3> INFO: scanning low vcal = 250
[08:58:16.112] <TB3> INFO: Test took 4365ms.
[08:58:16.177] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[08:58:20.546] <TB3> INFO: Test took 4369ms.
[08:58:20.613] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[08:58:24.987] <TB3> INFO: Test took 4374ms.
[08:58:25.053] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[08:58:29.423] <TB3> INFO: Test took 4370ms.
[08:58:29.490] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[08:58:33.863] <TB3> INFO: Test took 4373ms.
[08:58:33.944] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[08:58:38.327] <TB3> INFO: Test took 4383ms.
[08:58:38.873] <TB3> INFO: PixTestGainPedestal::measure() done
[08:59:12.591] <TB3> INFO: PixTestGainPedestal::fit() done
[08:59:12.591] <TB3> INFO: non-linearity mean: 0.958 0.955 0.957 0.962 0.954 0.956 0.956 0.951 0.956 0.957 0.954 0.958 0.957 0.958 0.958 0.957
[08:59:12.591] <TB3> INFO: non-linearity RMS: 0.005 0.005 0.005 0.004 0.007 0.005 0.006 0.006 0.005 0.005 0.006 0.006 0.006 0.006 0.006 0.005
[08:59:12.625] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C0.dat
[08:59:12.658] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C1.dat
[08:59:12.691] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C2.dat
[08:59:12.723] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C3.dat
[08:59:12.755] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C4.dat
[08:59:12.788] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C5.dat
[08:59:12.820] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C6.dat
[08:59:12.853] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C7.dat
[08:59:12.885] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C8.dat
[08:59:12.918] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C9.dat
[08:59:12.951] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C10.dat
[08:59:12.983] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C11.dat
[08:59:13.016] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C12.dat
[08:59:13.048] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C13.dat
[08:59:13.081] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C14.dat
[08:59:13.114] <TB3> INFO: write gain/ped parameters into /usr/local/coldboxDATA/M2073_FullQualification_2015-08-13_09h40m_1439451613//000_FulltestPxar_m20//phCalibrationFitErr35_C15.dat
[08:59:13.146] <TB3> INFO: PixTestGainPedestal::doTest() done, duration: 166 seconds
[08:59:13.154] <TB3> INFO: enter test to run
[08:59:13.156] <TB3> INFO: test: exit no parameter change
[08:59:13.770] <TB3> QUIET: Connection to board 170 closed.
[08:59:13.849] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.0-5-g82d9ff6 on branch psi46master