Test Date: 2016-10-26 16:26
Analysis date: 2016-10-28 10:43
Logfile
LogfileView
[17:20:39.016] <TB1> INFO: *** Welcome to pxar ***
[17:20:39.016] <TB1> INFO: *** Today: 2016/10/26
[17:20:39.022] <TB1> INFO: *** Version: c8ba-dirty
[17:20:39.022] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C15.dat
[17:20:39.022] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C1b.dat
[17:20:39.022] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//defaultMaskFile.dat
[17:20:39.022] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters_C15.dat
[17:20:39.076] <TB1> INFO: clk: 4
[17:20:39.077] <TB1> INFO: ctr: 4
[17:20:39.077] <TB1> INFO: sda: 19
[17:20:39.077] <TB1> INFO: tin: 9
[17:20:39.077] <TB1> INFO: level: 15
[17:20:39.077] <TB1> INFO: triggerdelay: 0
[17:20:39.077] <TB1> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[17:20:39.077] <TB1> INFO: Log level: INFO
[17:20:39.085] <TB1> INFO: Found DTB DTB_WXBYFL
[17:20:39.096] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[17:20:39.098] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[17:20:39.099] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[17:20:40.585] <TB1> INFO: DUT info:
[17:20:40.585] <TB1> INFO: The DUT currently contains the following objects:
[17:20:40.585] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[17:20:40.585] <TB1> INFO: TBM Core alpha (0): 7 registers set
[17:20:40.585] <TB1> INFO: TBM Core beta (1): 7 registers set
[17:20:40.586] <TB1> INFO: TBM Core alpha (2): 7 registers set
[17:20:40.586] <TB1> INFO: TBM Core beta (3): 7 registers set
[17:20:40.586] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[17:20:40.586] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.586] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:40.987] <TB1> INFO: enter 'restricted' command line mode
[17:20:40.987] <TB1> INFO: enter test to run
[17:20:40.987] <TB1> INFO: test: pretest no parameter change
[17:20:40.987] <TB1> INFO: running: pretest
[17:20:41.921] <TB1> INFO: ######################################################################
[17:20:41.921] <TB1> INFO: PixTestPretest::doTest()
[17:20:41.921] <TB1> INFO: ######################################################################
[17:20:41.922] <TB1> INFO: ----------------------------------------------------------------------
[17:20:41.922] <TB1> INFO: PixTestPretest::programROC()
[17:20:41.922] <TB1> INFO: ----------------------------------------------------------------------
[17:20:59.935] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[17:20:59.935] <TB1> INFO: IA differences per ROC: 19.3 20.9 18.5 19.3 19.3 18.5 20.1 20.1 18.5 20.9 19.3 20.1 19.3 18.5 18.5 17.7
[17:20:59.970] <TB1> INFO: ----------------------------------------------------------------------
[17:20:59.970] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[17:20:59.970] <TB1> INFO: ----------------------------------------------------------------------
[17:21:21.214] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 388.3 mA = 24.2687 mA/ROC
[17:21:21.214] <TB1> INFO: i(loss) [mA/ROC]: 19.3 20.1 18.5 19.3 19.3 20.1 19.3 19.3 19.3 19.3 19.3 19.3 20.1 19.3 20.1 18.5
[17:21:21.244] <TB1> INFO: ----------------------------------------------------------------------
[17:21:21.244] <TB1> INFO: PixTestPretest::findTiming()
[17:21:21.244] <TB1> INFO: ----------------------------------------------------------------------
[17:21:21.244] <TB1> INFO: PixTestCmd::init()
[17:21:21.824] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[17:21:52.300] <TB1> INFO: TBM phases: 160MHz: 7, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[17:21:52.300] <TB1> INFO: (success/tries = 100/100), width = 4
[17:21:53.800] <TB1> INFO: ----------------------------------------------------------------------
[17:21:53.800] <TB1> INFO: PixTestPretest::findWorkingPixel()
[17:21:53.800] <TB1> INFO: ----------------------------------------------------------------------
[17:21:53.892] <TB1> INFO: Expecting 231680 events.
[17:22:03.512] <TB1> INFO: 231680 events read in total (9029ms).
[17:22:03.521] <TB1> INFO: Test took 9718ms.
[17:22:03.767] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[17:22:03.798] <TB1> INFO: ----------------------------------------------------------------------
[17:22:03.798] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[17:22:03.798] <TB1> INFO: ----------------------------------------------------------------------
[17:22:03.890] <TB1> INFO: Expecting 231680 events.
[17:22:13.513] <TB1> INFO: 231680 events read in total (9031ms).
[17:22:13.520] <TB1> INFO: Test took 9718ms.
[17:22:13.781] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[17:22:13.781] <TB1> INFO: CalDel: 103 109 100 126 91 103 107 95 104 130 87 94 87 72 100 106
[17:22:13.781] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[17:22:13.783] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C0.dat
[17:22:13.783] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C1.dat
[17:22:13.783] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C2.dat
[17:22:13.783] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C3.dat
[17:22:13.783] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C4.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C5.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C6.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C7.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C8.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C9.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C10.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C11.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C12.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C13.dat
[17:22:13.784] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C14.dat
[17:22:13.785] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C15.dat
[17:22:13.785] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C0a.dat
[17:22:13.785] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C0b.dat
[17:22:13.785] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C1a.dat
[17:22:13.785] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C1b.dat
[17:22:13.785] <TB1> INFO: PixTestPretest::doTest() done, duration: 92 seconds
[17:22:13.880] <TB1> INFO: enter test to run
[17:22:13.880] <TB1> INFO: test: FullTest no parameter change
[17:22:13.880] <TB1> INFO: running: fulltest
[17:22:13.880] <TB1> INFO: ######################################################################
[17:22:13.880] <TB1> INFO: PixTestFullTest::doTest()
[17:22:13.880] <TB1> INFO: ######################################################################
[17:22:13.881] <TB1> INFO: ######################################################################
[17:22:13.881] <TB1> INFO: PixTestAlive::doTest()
[17:22:13.881] <TB1> INFO: ######################################################################
[17:22:13.882] <TB1> INFO: ----------------------------------------------------------------------
[17:22:13.882] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:22:13.882] <TB1> INFO: ----------------------------------------------------------------------
[17:22:14.119] <TB1> INFO: Expecting 41600 events.
[17:22:17.576] <TB1> INFO: 41600 events read in total (2865ms).
[17:22:17.576] <TB1> INFO: Test took 3693ms.
[17:22:17.801] <TB1> INFO: PixTestAlive::aliveTest() done
[17:22:17.801] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:22:17.803] <TB1> INFO: ----------------------------------------------------------------------
[17:22:17.803] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:22:17.803] <TB1> INFO: ----------------------------------------------------------------------
[17:22:18.081] <TB1> INFO: Expecting 41600 events.
[17:22:20.997] <TB1> INFO: 41600 events read in total (2325ms).
[17:22:20.997] <TB1> INFO: Test took 3193ms.
[17:22:20.998] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[17:22:21.234] <TB1> INFO: PixTestAlive::maskTest() done
[17:22:21.235] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:22:21.236] <TB1> INFO: ----------------------------------------------------------------------
[17:22:21.236] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:22:21.236] <TB1> INFO: ----------------------------------------------------------------------
[17:22:21.472] <TB1> INFO: Expecting 41600 events.
[17:22:24.964] <TB1> INFO: 41600 events read in total (2901ms).
[17:22:24.965] <TB1> INFO: Test took 3728ms.
[17:22:25.191] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[17:22:25.191] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:22:25.191] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[17:22:25.191] <TB1> INFO: Decoding statistics:
[17:22:25.191] <TB1> INFO: General information:
[17:22:25.191] <TB1> INFO: 16bit words read: 0
[17:22:25.191] <TB1> INFO: valid events total: 0
[17:22:25.191] <TB1> INFO: empty events: 0
[17:22:25.191] <TB1> INFO: valid events with pixels: 0
[17:22:25.192] <TB1> INFO: valid pixel hits: 0
[17:22:25.192] <TB1> INFO: Event errors: 0
[17:22:25.192] <TB1> INFO: start marker: 0
[17:22:25.192] <TB1> INFO: stop marker: 0
[17:22:25.192] <TB1> INFO: overflow: 0
[17:22:25.192] <TB1> INFO: invalid 5bit words: 0
[17:22:25.192] <TB1> INFO: invalid XOR eye diagram: 0
[17:22:25.192] <TB1> INFO: frame (failed synchr.): 0
[17:22:25.192] <TB1> INFO: idle data (no TBM trl): 0
[17:22:25.192] <TB1> INFO: no data (only TBM hdr): 0
[17:22:25.192] <TB1> INFO: TBM errors: 0
[17:22:25.192] <TB1> INFO: flawed TBM headers: 0
[17:22:25.192] <TB1> INFO: flawed TBM trailers: 0
[17:22:25.192] <TB1> INFO: event ID mismatches: 0
[17:22:25.192] <TB1> INFO: ROC errors: 0
[17:22:25.192] <TB1> INFO: missing ROC header(s): 0
[17:22:25.192] <TB1> INFO: misplaced readback start: 0
[17:22:25.192] <TB1> INFO: Pixel decoding errors: 0
[17:22:25.192] <TB1> INFO: pixel data incomplete: 0
[17:22:25.192] <TB1> INFO: pixel address: 0
[17:22:25.192] <TB1> INFO: pulse height fill bit: 0
[17:22:25.192] <TB1> INFO: buffer corruption: 0
[17:22:25.199] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C15.dat
[17:22:25.199] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[17:22:25.199] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[17:22:25.199] <TB1> INFO: ######################################################################
[17:22:25.199] <TB1> INFO: PixTestReadback::doTest()
[17:22:25.199] <TB1> INFO: ######################################################################
[17:22:25.199] <TB1> INFO: ----------------------------------------------------------------------
[17:22:25.199] <TB1> INFO: PixTestReadback::CalibrateVd()
[17:22:25.199] <TB1> INFO: ----------------------------------------------------------------------
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C0.dat
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C1.dat
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C2.dat
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C3.dat
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C4.dat
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C5.dat
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C6.dat
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C7.dat
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C8.dat
[17:22:35.161] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C9.dat
[17:22:35.162] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C10.dat
[17:22:35.162] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C11.dat
[17:22:35.162] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C12.dat
[17:22:35.162] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C13.dat
[17:22:35.162] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C14.dat
[17:22:35.162] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C15.dat
[17:22:35.189] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[17:22:35.189] <TB1> INFO: ----------------------------------------------------------------------
[17:22:35.189] <TB1> INFO: PixTestReadback::CalibrateVa()
[17:22:35.189] <TB1> INFO: ----------------------------------------------------------------------
[17:22:45.082] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C0.dat
[17:22:45.082] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C1.dat
[17:22:45.082] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C2.dat
[17:22:45.082] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C3.dat
[17:22:45.082] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C4.dat
[17:22:45.082] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C5.dat
[17:22:45.082] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C6.dat
[17:22:45.082] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C7.dat
[17:22:45.082] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C8.dat
[17:22:45.083] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C9.dat
[17:22:45.083] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C10.dat
[17:22:45.083] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C11.dat
[17:22:45.083] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C12.dat
[17:22:45.083] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C13.dat
[17:22:45.083] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C14.dat
[17:22:45.083] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C15.dat
[17:22:45.116] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[17:22:45.116] <TB1> INFO: ----------------------------------------------------------------------
[17:22:45.116] <TB1> INFO: PixTestReadback::readbackVbg()
[17:22:45.116] <TB1> INFO: ----------------------------------------------------------------------
[17:22:52.764] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[17:22:52.764] <TB1> INFO: ----------------------------------------------------------------------
[17:22:52.764] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[17:22:52.764] <TB1> INFO: ----------------------------------------------------------------------
[17:22:52.764] <TB1> INFO: Vbg will be calibrated using Vd calibration
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 154calibrated Vbg = 1.14624 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 149.1calibrated Vbg = 1.1458 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 146.8calibrated Vbg = 1.13227 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 144.8calibrated Vbg = 1.14246 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 141calibrated Vbg = 1.1409 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 149.2calibrated Vbg = 1.15192 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 147calibrated Vbg = 1.14612 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 154.4calibrated Vbg = 1.14696 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 152.8calibrated Vbg = 1.14246 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 158.9calibrated Vbg = 1.14359 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 152.8calibrated Vbg = 1.13639 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 159calibrated Vbg = 1.13679 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 154.2calibrated Vbg = 1.1426 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 151.5calibrated Vbg = 1.14754 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 159calibrated Vbg = 1.15421 :::*/*/*/*/
[17:22:52.764] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 159.1calibrated Vbg = 1.14911 :::*/*/*/*/
[17:22:52.766] <TB1> INFO: ----------------------------------------------------------------------
[17:22:52.766] <TB1> INFO: PixTestReadback::CalibrateIa()
[17:22:52.766] <TB1> INFO: ----------------------------------------------------------------------
[17:25:33.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C0.dat
[17:25:33.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C1.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C2.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C3.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C4.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C5.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C6.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C7.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C8.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C9.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C10.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C11.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C12.dat
[17:25:33.093] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C13.dat
[17:25:33.094] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C14.dat
[17:25:33.094] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C15.dat
[17:25:33.124] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[17:25:33.125] <TB1> INFO: PixTestReadback::doTest() done
[17:25:33.125] <TB1> INFO: Decoding statistics:
[17:25:33.125] <TB1> INFO: General information:
[17:25:33.125] <TB1> INFO: 16bit words read: 1536
[17:25:33.125] <TB1> INFO: valid events total: 256
[17:25:33.125] <TB1> INFO: empty events: 256
[17:25:33.125] <TB1> INFO: valid events with pixels: 0
[17:25:33.125] <TB1> INFO: valid pixel hits: 0
[17:25:33.125] <TB1> INFO: Event errors: 0
[17:25:33.125] <TB1> INFO: start marker: 0
[17:25:33.125] <TB1> INFO: stop marker: 0
[17:25:33.125] <TB1> INFO: overflow: 0
[17:25:33.125] <TB1> INFO: invalid 5bit words: 0
[17:25:33.125] <TB1> INFO: invalid XOR eye diagram: 0
[17:25:33.125] <TB1> INFO: frame (failed synchr.): 0
[17:25:33.125] <TB1> INFO: idle data (no TBM trl): 0
[17:25:33.125] <TB1> INFO: no data (only TBM hdr): 0
[17:25:33.125] <TB1> INFO: TBM errors: 0
[17:25:33.125] <TB1> INFO: flawed TBM headers: 0
[17:25:33.125] <TB1> INFO: flawed TBM trailers: 0
[17:25:33.125] <TB1> INFO: event ID mismatches: 0
[17:25:33.125] <TB1> INFO: ROC errors: 0
[17:25:33.125] <TB1> INFO: missing ROC header(s): 0
[17:25:33.125] <TB1> INFO: misplaced readback start: 0
[17:25:33.125] <TB1> INFO: Pixel decoding errors: 0
[17:25:33.125] <TB1> INFO: pixel data incomplete: 0
[17:25:33.125] <TB1> INFO: pixel address: 0
[17:25:33.125] <TB1> INFO: pulse height fill bit: 0
[17:25:33.125] <TB1> INFO: buffer corruption: 0
[17:25:33.162] <TB1> INFO: ######################################################################
[17:25:33.162] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[17:25:33.162] <TB1> INFO: ######################################################################
[17:25:33.166] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[17:25:33.177] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[17:25:33.177] <TB1> INFO: run 1 of 1
[17:25:33.411] <TB1> INFO: Expecting 3120000 events.
[17:26:03.394] <TB1> INFO: 659185 events read in total (29391ms).
[17:26:15.370] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (114) != TBM ID (129)

[17:26:15.504] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 114 114 129 114 114 114 114 114

[17:26:15.504] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (115)

[17:26:15.504] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[17:26:15.504] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a076 80c0 40c0 252 2def 4180 252 2dac e022 c000

[17:26:15.505] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a070 8040 40c3 252 2def 41c3 252 2dc0 e022 c000

[17:26:15.505] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a071 80b1 40c0 252 2def 41c0 252 2daf e022 c000

[17:26:15.505] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 40c0 40c0 2def 41c1 252 2daf e022 c000

[17:26:15.505] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a073 8000 4180 252 2def 41c0 252 2daf e022 c000

[17:26:15.505] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a074 8040 4180 252 2def 41c1 252 2dac e022 c000

[17:26:15.505] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a075 80b1 40c0 252 2def 41c0 252 2dad e022 c000

[17:26:32.809] <TB1> INFO: 1310360 events read in total (58806ms).
[17:26:44.714] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (25) != TBM ID (129)

[17:26:44.852] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 25 25 129 25 25 25 25 25

[17:26:44.852] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (26)

[17:26:44.853] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[17:26:44.853] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01d 80b1 40c0 40c0 e022 c000

[17:26:44.853] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a017 8000 40c0 40c0 e022 c000

[17:26:44.853] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a018 8040 40c0 40c0 e022 c000

[17:26:44.853] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 40c0 40c0 e022 c000

[17:26:44.853] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01a 80c0 40c0 40c0 e022 c000

[17:26:44.853] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01b 8000 40c0 40c0 e022 c000

[17:26:44.853] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01c 8040 40c1 40c1 e022 c000

[17:27:01.703] <TB1> INFO: 1957905 events read in total (87700ms).
[17:27:13.644] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (146) != TBM ID (129)

[17:27:13.780] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 146 146 129 146 146 146 146 146

[17:27:13.780] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (147)

[17:27:13.780] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[17:27:13.780] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a096 80c0 40c0 80c 25ef 40c0 80c 25ef e022 c000

[17:27:13.780] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a090 8040 40c3 80c 25ef 40c3 80c 25ef e022 c000

[17:27:13.780] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a091 80b1 40c0 80c 25ef 40c0 80c 25ef e022 c000

[17:27:13.780] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 40c0 40c0 25ef 40c1 80c 25ef e022 c000

[17:27:13.780] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a093 8000 40c0 80c 25ef 41c0 80c 25ef e022 c000

[17:27:13.780] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a094 8040 41c0 80c 25ef 4181 80c 25ef e022 c000

[17:27:13.780] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a095 80b1 40c0 80c 25ef 40c0 80c 25ef e022 c000

[17:27:31.009] <TB1> INFO: 2606855 events read in total (117006ms).
[17:27:40.507] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (136) != TBM ID (129)

[17:27:40.648] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 136 136 129 136 136 136 136 136

[17:27:40.648] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (137)

[17:27:40.648] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[17:27:40.648] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08c 8040 40c1 a68 27ef 40c1 a68 27ef e022 c000

[17:27:40.648] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a086 80c0 40c0 a68 27ef 41c0 a68 27ef e022 c000

[17:27:40.648] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a087 8000 40c0 a68 27ef 41c0 a68 27ef e022 c000

[17:27:40.648] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 40c0 40c0 27ef 40c0 a68 27ef e022 c000

[17:27:40.648] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a089 80b1 40c0 a68 27ef 40c0 a68 27ef e022 c000

[17:27:40.648] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08a 80c0 4181 a68 27ef 41c1 a68 27ef e022 c000

[17:27:40.648] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08b 8000 40c1 a68 27ef 40c1 a68 27ef e022 c000

[17:27:54.424] <TB1> INFO: 3120000 events read in total (140421ms).
[17:27:54.481] <TB1> INFO: Test took 141304ms.
[17:28:20.394] <TB1> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 167 seconds
[17:28:20.394] <TB1> INFO: number of dead bumps (per ROC): 0 3 1 0 0 1 1 0 0 0 0 0 0 0 1 0
[17:28:20.394] <TB1> INFO: separation cut (per ROC): 103 109 102 106 100 104 103 106 99 97 106 107 107 109 101 103
[17:28:20.394] <TB1> INFO: Decoding statistics:
[17:28:20.394] <TB1> INFO: General information:
[17:28:20.394] <TB1> INFO: 16bit words read: 0
[17:28:20.394] <TB1> INFO: valid events total: 0
[17:28:20.394] <TB1> INFO: empty events: 0
[17:28:20.394] <TB1> INFO: valid events with pixels: 0
[17:28:20.394] <TB1> INFO: valid pixel hits: 0
[17:28:20.394] <TB1> INFO: Event errors: 0
[17:28:20.394] <TB1> INFO: start marker: 0
[17:28:20.394] <TB1> INFO: stop marker: 0
[17:28:20.394] <TB1> INFO: overflow: 0
[17:28:20.394] <TB1> INFO: invalid 5bit words: 0
[17:28:20.394] <TB1> INFO: invalid XOR eye diagram: 0
[17:28:20.394] <TB1> INFO: frame (failed synchr.): 0
[17:28:20.394] <TB1> INFO: idle data (no TBM trl): 0
[17:28:20.394] <TB1> INFO: no data (only TBM hdr): 0
[17:28:20.394] <TB1> INFO: TBM errors: 0
[17:28:20.394] <TB1> INFO: flawed TBM headers: 0
[17:28:20.394] <TB1> INFO: flawed TBM trailers: 0
[17:28:20.394] <TB1> INFO: event ID mismatches: 0
[17:28:20.394] <TB1> INFO: ROC errors: 0
[17:28:20.394] <TB1> INFO: missing ROC header(s): 0
[17:28:20.394] <TB1> INFO: misplaced readback start: 0
[17:28:20.394] <TB1> INFO: Pixel decoding errors: 0
[17:28:20.394] <TB1> INFO: pixel data incomplete: 0
[17:28:20.394] <TB1> INFO: pixel address: 0
[17:28:20.395] <TB1> INFO: pulse height fill bit: 0
[17:28:20.395] <TB1> INFO: buffer corruption: 0
[17:28:20.433] <TB1> INFO: ######################################################################
[17:28:20.433] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[17:28:20.433] <TB1> INFO: ######################################################################
[17:28:20.433] <TB1> INFO: ----------------------------------------------------------------------
[17:28:20.433] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[17:28:20.433] <TB1> INFO: ----------------------------------------------------------------------
[17:28:20.433] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[17:28:20.443] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[17:28:20.443] <TB1> INFO: run 1 of 1
[17:28:20.718] <TB1> INFO: Expecting 36608000 events.
[17:28:44.181] <TB1> INFO: 665900 events read in total (22871ms).
[17:29:06.787] <TB1> INFO: 1319850 events read in total (45477ms).
[17:29:29.310] <TB1> INFO: 1975350 events read in total (68000ms).
[17:29:51.778] <TB1> INFO: 2629100 events read in total (90468ms).
[17:30:14.227] <TB1> INFO: 3282350 events read in total (112917ms).
[17:30:36.925] <TB1> INFO: 3938000 events read in total (135615ms).
[17:30:59.799] <TB1> INFO: 4591600 events read in total (158489ms).
[17:31:22.375] <TB1> INFO: 5243900 events read in total (181065ms).
[17:31:45.070] <TB1> INFO: 5896050 events read in total (203760ms).
[17:32:07.423] <TB1> INFO: 6547950 events read in total (226113ms).
[17:32:30.106] <TB1> INFO: 7201300 events read in total (248796ms).
[17:32:53.074] <TB1> INFO: 7853600 events read in total (271764ms).
[17:33:15.633] <TB1> INFO: 8506250 events read in total (294323ms).
[17:33:38.165] <TB1> INFO: 9158500 events read in total (316855ms).
[17:34:00.099] <TB1> INFO: 9809650 events read in total (338789ms).
[17:34:22.587] <TB1> INFO: 10461750 events read in total (361277ms).
[17:34:45.053] <TB1> INFO: 11113550 events read in total (383743ms).
[17:35:07.298] <TB1> INFO: 11764500 events read in total (405988ms).
[17:35:29.514] <TB1> INFO: 12415500 events read in total (428204ms).
[17:35:51.907] <TB1> INFO: 13066900 events read in total (450597ms).
[17:36:14.495] <TB1> INFO: 13718150 events read in total (473185ms).
[17:36:36.962] <TB1> INFO: 14370050 events read in total (495652ms).
[17:36:59.262] <TB1> INFO: 15021250 events read in total (517952ms).
[17:37:21.494] <TB1> INFO: 15672850 events read in total (540184ms).
[17:37:44.210] <TB1> INFO: 16325200 events read in total (562900ms).
[17:38:06.746] <TB1> INFO: 16974650 events read in total (585436ms).
[17:38:29.084] <TB1> INFO: 17624700 events read in total (607774ms).
[17:38:51.218] <TB1> INFO: 18273950 events read in total (629908ms).
[17:39:13.784] <TB1> INFO: 18921050 events read in total (652474ms).
[17:39:36.233] <TB1> INFO: 19569300 events read in total (674923ms).
[17:39:58.515] <TB1> INFO: 20218200 events read in total (697205ms).
[17:40:20.818] <TB1> INFO: 20867200 events read in total (719508ms).
[17:40:43.114] <TB1> INFO: 21513200 events read in total (741804ms).
[17:41:05.409] <TB1> INFO: 22160150 events read in total (764099ms).
[17:41:27.846] <TB1> INFO: 22807200 events read in total (786536ms).
[17:41:50.306] <TB1> INFO: 23455150 events read in total (808996ms).
[17:42:12.591] <TB1> INFO: 24100600 events read in total (831281ms).
[17:42:35.466] <TB1> INFO: 24748100 events read in total (854156ms).
[17:42:58.241] <TB1> INFO: 25395850 events read in total (876931ms).
[17:43:20.541] <TB1> INFO: 26042650 events read in total (899231ms).
[17:43:43.062] <TB1> INFO: 26687450 events read in total (921752ms).
[17:44:05.311] <TB1> INFO: 27334650 events read in total (944001ms).
[17:44:27.640] <TB1> INFO: 27981750 events read in total (966330ms).
[17:44:50.451] <TB1> INFO: 28626150 events read in total (989141ms).
[17:45:13.012] <TB1> INFO: 29272700 events read in total (1011702ms).
[17:45:35.538] <TB1> INFO: 29918500 events read in total (1034228ms).
[17:45:57.869] <TB1> INFO: 30566200 events read in total (1056559ms).
[17:46:20.744] <TB1> INFO: 31212400 events read in total (1079434ms).
[17:46:43.522] <TB1> INFO: 31860150 events read in total (1102212ms).
[17:47:05.826] <TB1> INFO: 32505150 events read in total (1124516ms).
[17:47:28.174] <TB1> INFO: 33150000 events read in total (1146864ms).
[17:47:50.804] <TB1> INFO: 33797750 events read in total (1169494ms).
[17:48:13.232] <TB1> INFO: 34445600 events read in total (1191922ms).
[17:48:35.615] <TB1> INFO: 35093650 events read in total (1214305ms).
[17:48:58.359] <TB1> INFO: 35742000 events read in total (1237049ms).
[17:49:21.476] <TB1> INFO: 36398600 events read in total (1260166ms).
[17:49:29.234] <TB1> INFO: 36608000 events read in total (1267924ms).
[17:49:29.306] <TB1> INFO: Test took 1268863ms.
[17:49:29.787] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:31.608] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:33.605] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:35.532] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:37.328] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:39.009] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:40.545] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:42.271] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:44.297] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:46.107] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:48.300] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:50.494] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:52.895] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:54.880] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:56.838] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:49:59.069] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[17:50:01.037] <TB1> INFO: PixTestScurves::scurves() done
[17:50:01.037] <TB1> INFO: Vcal mean: 109.18 109.78 106.87 108.73 103.82 104.97 105.40 107.13 114.57 104.39 109.91 109.10 116.39 109.30 103.26 108.51
[17:50:01.037] <TB1> INFO: Vcal RMS: 4.54 4.75 4.94 5.00 4.75 4.83 4.79 4.46 7.96 5.30 5.25 4.42 5.02 4.43 5.02 4.48
[17:50:01.037] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1300 seconds
[17:50:01.037] <TB1> INFO: Decoding statistics:
[17:50:01.037] <TB1> INFO: General information:
[17:50:01.037] <TB1> INFO: 16bit words read: 0
[17:50:01.037] <TB1> INFO: valid events total: 0
[17:50:01.037] <TB1> INFO: empty events: 0
[17:50:01.037] <TB1> INFO: valid events with pixels: 0
[17:50:01.037] <TB1> INFO: valid pixel hits: 0
[17:50:01.037] <TB1> INFO: Event errors: 0
[17:50:01.037] <TB1> INFO: start marker: 0
[17:50:01.037] <TB1> INFO: stop marker: 0
[17:50:01.037] <TB1> INFO: overflow: 0
[17:50:01.037] <TB1> INFO: invalid 5bit words: 0
[17:50:01.038] <TB1> INFO: invalid XOR eye diagram: 0
[17:50:01.038] <TB1> INFO: frame (failed synchr.): 0
[17:50:01.038] <TB1> INFO: idle data (no TBM trl): 0
[17:50:01.038] <TB1> INFO: no data (only TBM hdr): 0
[17:50:01.038] <TB1> INFO: TBM errors: 0
[17:50:01.038] <TB1> INFO: flawed TBM headers: 0
[17:50:01.038] <TB1> INFO: flawed TBM trailers: 0
[17:50:01.038] <TB1> INFO: event ID mismatches: 0
[17:50:01.038] <TB1> INFO: ROC errors: 0
[17:50:01.038] <TB1> INFO: missing ROC header(s): 0
[17:50:01.038] <TB1> INFO: misplaced readback start: 0
[17:50:01.038] <TB1> INFO: Pixel decoding errors: 0
[17:50:01.038] <TB1> INFO: pixel data incomplete: 0
[17:50:01.038] <TB1> INFO: pixel address: 0
[17:50:01.038] <TB1> INFO: pulse height fill bit: 0
[17:50:01.038] <TB1> INFO: buffer corruption: 0
[17:50:01.111] <TB1> INFO: ######################################################################
[17:50:01.111] <TB1> INFO: PixTestTrim::doTest()
[17:50:01.111] <TB1> INFO: ######################################################################
[17:50:01.112] <TB1> INFO: ----------------------------------------------------------------------
[17:50:01.112] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[17:50:01.112] <TB1> INFO: ----------------------------------------------------------------------
[17:50:01.154] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[17:50:01.154] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[17:50:01.163] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[17:50:01.163] <TB1> INFO: run 1 of 1
[17:50:01.423] <TB1> INFO: Expecting 5025280 events.
[17:50:31.991] <TB1> INFO: 811408 events read in total (29973ms).
[17:51:01.344] <TB1> INFO: 1619632 events read in total (59326ms).
[17:51:30.733] <TB1> INFO: 2426272 events read in total (88716ms).
[17:52:00.101] <TB1> INFO: 3229504 events read in total (118083ms).
[17:52:29.602] <TB1> INFO: 4029064 events read in total (147584ms).
[17:52:58.823] <TB1> INFO: 4827168 events read in total (176805ms).
[17:53:06.410] <TB1> INFO: 5025280 events read in total (184392ms).
[17:53:06.453] <TB1> INFO: Test took 185291ms.
[17:53:27.619] <TB1> INFO: ROC 0 VthrComp = 118
[17:53:27.619] <TB1> INFO: ROC 1 VthrComp = 124
[17:53:27.619] <TB1> INFO: ROC 2 VthrComp = 109
[17:53:27.619] <TB1> INFO: ROC 3 VthrComp = 116
[17:53:27.620] <TB1> INFO: ROC 4 VthrComp = 110
[17:53:27.620] <TB1> INFO: ROC 5 VthrComp = 116
[17:53:27.620] <TB1> INFO: ROC 6 VthrComp = 115
[17:53:27.620] <TB1> INFO: ROC 7 VthrComp = 118
[17:53:27.620] <TB1> INFO: ROC 8 VthrComp = 117
[17:53:27.620] <TB1> INFO: ROC 9 VthrComp = 111
[17:53:27.620] <TB1> INFO: ROC 10 VthrComp = 120
[17:53:27.621] <TB1> INFO: ROC 11 VthrComp = 123
[17:53:27.621] <TB1> INFO: ROC 12 VthrComp = 125
[17:53:27.621] <TB1> INFO: ROC 13 VthrComp = 122
[17:53:27.621] <TB1> INFO: ROC 14 VthrComp = 112
[17:53:27.622] <TB1> INFO: ROC 15 VthrComp = 117
[17:53:27.863] <TB1> INFO: Expecting 41600 events.
[17:53:31.339] <TB1> INFO: 41600 events read in total (2885ms).
[17:53:31.340] <TB1> INFO: Test took 3717ms.
[17:53:31.351] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[17:53:31.351] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[17:53:31.362] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[17:53:31.362] <TB1> INFO: run 1 of 1
[17:53:31.640] <TB1> INFO: Expecting 5025280 events.
[17:53:57.002] <TB1> INFO: 588800 events read in total (25771ms).
[17:54:23.248] <TB1> INFO: 1176560 events read in total (51017ms).
[17:54:48.591] <TB1> INFO: 1764368 events read in total (76360ms).
[17:55:13.943] <TB1> INFO: 2351264 events read in total (101712ms).
[17:55:39.743] <TB1> INFO: 2936216 events read in total (127512ms).
[17:56:05.158] <TB1> INFO: 3520592 events read in total (152927ms).
[17:56:30.292] <TB1> INFO: 4103688 events read in total (178061ms).
[17:56:55.783] <TB1> INFO: 4685760 events read in total (203552ms).
[17:57:10.658] <TB1> INFO: 5025280 events read in total (218427ms).
[17:57:10.730] <TB1> INFO: Test took 219368ms.
[17:57:36.644] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 57.1707 for pixel 15/23 mean/min/max = 44.3938/31.546/57.2416
[17:57:36.644] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 57.356 for pixel 1/77 mean/min/max = 44.4384/31.4672/57.4096
[17:57:36.644] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 60.4173 for pixel 12/6 mean/min/max = 47.5446/34.5523/60.5368
[17:57:36.645] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 58.4507 for pixel 0/0 mean/min/max = 45.0892/31.4956/58.6828
[17:57:36.645] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 58.2053 for pixel 51/3 mean/min/max = 46.7781/35.2618/58.2945
[17:57:36.646] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 56.9957 for pixel 12/44 mean/min/max = 44.6965/32.3273/57.0657
[17:57:36.646] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 57.4647 for pixel 14/2 mean/min/max = 44.9865/32.4086/57.5645
[17:57:36.646] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 55.8919 for pixel 0/79 mean/min/max = 44.3417/32.4206/56.2627
[17:57:36.647] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 66.4187 for pixel 0/76 mean/min/max = 47.9961/29.4819/66.5102
[17:57:36.647] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 58.5445 for pixel 51/70 mean/min/max = 46.2995/33.9265/58.6724
[17:57:36.647] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 57.8954 for pixel 3/76 mean/min/max = 45.1729/31.9603/58.3854
[17:57:36.648] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 56.4322 for pixel 24/4 mean/min/max = 44.5331/32.4751/56.5911
[17:57:36.648] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 58.5743 for pixel 32/13 mean/min/max = 45.2554/31.8398/58.671
[17:57:36.648] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 56.7891 for pixel 19/3 mean/min/max = 44.2357/31.6096/56.8618
[17:57:36.649] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 57.164 for pixel 48/73 mean/min/max = 44.9652/32.7074/57.223
[17:57:36.649] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 57.8629 for pixel 1/12 mean/min/max = 45.0673/32.2499/57.8848
[17:57:36.649] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:57:36.738] <TB1> INFO: Expecting 411648 events.
[17:57:46.103] <TB1> INFO: 411648 events read in total (8773ms).
[17:57:46.109] <TB1> INFO: Expecting 411648 events.
[17:57:55.203] <TB1> INFO: 411648 events read in total (8691ms).
[17:57:55.212] <TB1> INFO: Expecting 411648 events.
[17:58:04.337] <TB1> INFO: 411648 events read in total (8722ms).
[17:58:04.349] <TB1> INFO: Expecting 411648 events.
[17:58:13.415] <TB1> INFO: 411648 events read in total (8663ms).
[17:58:13.429] <TB1> INFO: Expecting 411648 events.
[17:58:22.495] <TB1> INFO: 411648 events read in total (8663ms).
[17:58:22.512] <TB1> INFO: Expecting 411648 events.
[17:58:31.579] <TB1> INFO: 411648 events read in total (8665ms).
[17:58:31.598] <TB1> INFO: Expecting 411648 events.
[17:58:40.643] <TB1> INFO: 411648 events read in total (8642ms).
[17:58:40.664] <TB1> INFO: Expecting 411648 events.
[17:58:49.703] <TB1> INFO: 411648 events read in total (8636ms).
[17:58:49.735] <TB1> INFO: Expecting 411648 events.
[17:58:58.834] <TB1> INFO: 411648 events read in total (8696ms).
[17:58:58.861] <TB1> INFO: Expecting 411648 events.
[17:59:07.896] <TB1> INFO: 411648 events read in total (8632ms).
[17:59:07.925] <TB1> INFO: Expecting 411648 events.
[17:59:16.995] <TB1> INFO: 411648 events read in total (8667ms).
[17:59:17.028] <TB1> INFO: Expecting 411648 events.
[17:59:26.068] <TB1> INFO: 411648 events read in total (8637ms).
[17:59:26.105] <TB1> INFO: Expecting 411648 events.
[17:59:35.202] <TB1> INFO: 411648 events read in total (8694ms).
[17:59:35.252] <TB1> INFO: Expecting 411648 events.
[17:59:44.292] <TB1> INFO: 411648 events read in total (8637ms).
[17:59:44.344] <TB1> INFO: Expecting 411648 events.
[17:59:53.416] <TB1> INFO: 411648 events read in total (8669ms).
[17:59:53.458] <TB1> INFO: Expecting 411648 events.
[18:00:02.590] <TB1> INFO: 411648 events read in total (8729ms).
[18:00:02.635] <TB1> INFO: Test took 145986ms.
[18:00:03.545] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[18:00:03.555] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:00:03.555] <TB1> INFO: run 1 of 1
[18:00:03.789] <TB1> INFO: Expecting 5025280 events.
[18:00:29.586] <TB1> INFO: 584896 events read in total (25205ms).
[18:00:54.998] <TB1> INFO: 1166736 events read in total (50617ms).
[18:01:20.745] <TB1> INFO: 1749096 events read in total (76364ms).
[18:01:46.380] <TB1> INFO: 2331520 events read in total (101999ms).
[18:02:12.044] <TB1> INFO: 2913144 events read in total (127663ms).
[18:02:37.356] <TB1> INFO: 3493176 events read in total (152975ms).
[18:03:02.843] <TB1> INFO: 4073232 events read in total (178462ms).
[18:03:28.288] <TB1> INFO: 4651944 events read in total (203907ms).
[18:03:44.673] <TB1> INFO: 5025280 events read in total (220292ms).
[18:03:44.792] <TB1> INFO: Test took 221238ms.
[18:04:12.015] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.684391 .. 140.902270
[18:04:12.337] <TB1> INFO: Expecting 208000 events.
[18:04:22.054] <TB1> INFO: 208000 events read in total (9125ms).
[18:04:22.055] <TB1> INFO: Test took 10038ms.
[18:04:22.101] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[18:04:22.110] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:04:22.110] <TB1> INFO: run 1 of 1
[18:04:22.388] <TB1> INFO: Expecting 5025280 events.
[18:04:48.670] <TB1> INFO: 587928 events read in total (25690ms).
[18:05:14.269] <TB1> INFO: 1175864 events read in total (51289ms).
[18:05:39.536] <TB1> INFO: 1763456 events read in total (76556ms).
[18:06:04.800] <TB1> INFO: 2351168 events read in total (101820ms).
[18:06:29.958] <TB1> INFO: 2937952 events read in total (126978ms).
[18:06:55.437] <TB1> INFO: 3523952 events read in total (152457ms).
[18:07:21.076] <TB1> INFO: 4109224 events read in total (178096ms).
[18:07:47.231] <TB1> INFO: 4693720 events read in total (204251ms).
[18:08:01.747] <TB1> INFO: 5025280 events read in total (218767ms).
[18:08:01.830] <TB1> INFO: Test took 219720ms.
[18:08:27.349] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 27.726758 .. 43.380984
[18:08:27.645] <TB1> INFO: Expecting 208000 events.
[18:08:38.025] <TB1> INFO: 208000 events read in total (9788ms).
[18:08:38.026] <TB1> INFO: Test took 10676ms.
[18:08:38.074] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 53 (-1/-1) hits flags = 528 (plus default)
[18:08:38.083] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:08:38.083] <TB1> INFO: run 1 of 1
[18:08:38.361] <TB1> INFO: Expecting 1231360 events.
[18:09:06.734] <TB1> INFO: 666832 events read in total (27781ms).
[18:09:30.014] <TB1> INFO: 1231360 events read in total (51062ms).
[18:09:30.040] <TB1> INFO: Test took 51957ms.
[18:09:43.695] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 24.682601 .. 47.041283
[18:09:43.934] <TB1> INFO: Expecting 208000 events.
[18:09:53.814] <TB1> INFO: 208000 events read in total (9288ms).
[18:09:53.815] <TB1> INFO: Test took 10118ms.
[18:09:53.863] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 14 .. 57 (-1/-1) hits flags = 528 (plus default)
[18:09:53.874] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:09:53.874] <TB1> INFO: run 1 of 1
[18:09:54.189] <TB1> INFO: Expecting 1464320 events.
[18:10:22.130] <TB1> INFO: 662960 events read in total (27350ms).
[18:10:49.282] <TB1> INFO: 1325200 events read in total (54503ms).
[18:10:55.401] <TB1> INFO: 1464320 events read in total (60621ms).
[18:10:55.435] <TB1> INFO: Test took 61560ms.
[18:11:09.676] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 23.270454 .. 43.971820
[18:11:09.921] <TB1> INFO: Expecting 208000 events.
[18:11:20.252] <TB1> INFO: 208000 events read in total (9740ms).
[18:11:20.253] <TB1> INFO: Test took 10575ms.
[18:11:20.308] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 13 .. 53 (-1/-1) hits flags = 528 (plus default)
[18:11:20.318] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:11:20.318] <TB1> INFO: run 1 of 1
[18:11:20.596] <TB1> INFO: Expecting 1364480 events.
[18:11:49.261] <TB1> INFO: 684376 events read in total (28073ms).
[18:12:16.806] <TB1> INFO: 1364480 events read in total (55619ms).
[18:12:16.842] <TB1> INFO: Test took 56525ms.
[18:12:30.211] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[18:12:30.211] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[18:12:30.221] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:12:30.221] <TB1> INFO: run 1 of 1
[18:12:30.455] <TB1> INFO: Expecting 1364480 events.
[18:12:58.378] <TB1> INFO: 667152 events read in total (27331ms).
[18:13:25.693] <TB1> INFO: 1333784 events read in total (54646ms).
[18:13:27.436] <TB1> INFO: 1364480 events read in total (56390ms).
[18:13:27.463] <TB1> INFO: Test took 57241ms.
[18:13:41.634] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C0.dat
[18:13:41.634] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C1.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C2.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C3.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C4.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C5.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C6.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C7.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C8.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C9.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C10.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C11.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C12.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C13.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C14.dat
[18:13:41.635] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C15.dat
[18:13:41.635] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C0.dat
[18:13:41.641] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C1.dat
[18:13:41.647] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C2.dat
[18:13:41.652] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C3.dat
[18:13:41.658] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C4.dat
[18:13:41.665] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C5.dat
[18:13:41.673] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C6.dat
[18:13:41.681] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C7.dat
[18:13:41.689] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C8.dat
[18:13:41.697] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C9.dat
[18:13:41.705] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C10.dat
[18:13:41.713] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C11.dat
[18:13:41.721] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C12.dat
[18:13:41.728] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C13.dat
[18:13:41.735] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C14.dat
[18:13:41.742] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C15.dat
[18:13:41.751] <TB1> INFO: PixTestTrim::trimTest() done
[18:13:41.751] <TB1> INFO: vtrim: 137 133 143 115 120 137 130 114 150 134 133 133 144 117 130 137
[18:13:41.751] <TB1> INFO: vthrcomp: 118 124 109 116 110 116 115 118 117 111 120 123 125 122 112 117
[18:13:41.751] <TB1> INFO: vcal mean: 34.97 34.93 34.99 34.95 34.99 34.98 34.95 34.94 34.96 34.98 34.97 34.93 34.92 34.93 34.99 35.00
[18:13:41.751] <TB1> INFO: vcal RMS: 1.02 0.99 1.04 1.00 0.94 0.96 0.94 0.91 1.19 0.96 1.04 1.01 1.05 1.02 1.02 1.06
[18:13:41.751] <TB1> INFO: bits mean: 10.20 10.38 9.35 9.49 8.48 10.21 10.07 9.22 9.84 9.48 9.71 9.94 10.13 10.09 10.09 10.30
[18:13:41.751] <TB1> INFO: bits RMS: 2.52 2.45 2.31 2.82 2.62 2.38 2.44 2.85 2.70 2.38 2.61 2.46 2.48 2.55 2.37 2.38
[18:13:41.759] <TB1> INFO: ----------------------------------------------------------------------
[18:13:41.759] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[18:13:41.759] <TB1> INFO: ----------------------------------------------------------------------
[18:13:41.761] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[18:13:41.771] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:13:41.771] <TB1> INFO: run 1 of 1
[18:13:42.004] <TB1> INFO: Expecting 4160000 events.
[18:14:13.800] <TB1> INFO: 734335 events read in total (31205ms).
[18:14:44.863] <TB1> INFO: 1463765 events read in total (62268ms).
[18:15:16.045] <TB1> INFO: 2190725 events read in total (93451ms).
[18:15:46.915] <TB1> INFO: 2913335 events read in total (124320ms).
[18:16:17.529] <TB1> INFO: 3634125 events read in total (154934ms).
[18:16:39.876] <TB1> INFO: 4160000 events read in total (177281ms).
[18:16:39.936] <TB1> INFO: Test took 178164ms.
[18:17:09.623] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[18:17:09.634] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:17:09.634] <TB1> INFO: run 1 of 1
[18:17:09.867] <TB1> INFO: Expecting 4139200 events.
[18:17:40.868] <TB1> INFO: 710625 events read in total (30409ms).
[18:18:11.728] <TB1> INFO: 1416740 events read in total (61269ms).
[18:18:42.404] <TB1> INFO: 2121140 events read in total (91945ms).
[18:19:13.054] <TB1> INFO: 2821710 events read in total (122595ms).
[18:19:43.454] <TB1> INFO: 3521135 events read in total (152995ms).
[18:20:10.468] <TB1> INFO: 4139200 events read in total (180009ms).
[18:20:10.527] <TB1> INFO: Test took 180892ms.
[18:20:39.873] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 183 (-1/-1) hits flags = 528 (plus default)
[18:20:39.882] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:20:39.882] <TB1> INFO: run 1 of 1
[18:20:40.162] <TB1> INFO: Expecting 3827200 events.
[18:21:11.566] <TB1> INFO: 731010 events read in total (30812ms).
[18:21:42.563] <TB1> INFO: 1456850 events read in total (61809ms).
[18:22:13.493] <TB1> INFO: 2179780 events read in total (92739ms).
[18:22:44.572] <TB1> INFO: 2898640 events read in total (123818ms).
[18:23:15.400] <TB1> INFO: 3616585 events read in total (154646ms).
[18:23:24.946] <TB1> INFO: 3827200 events read in total (164192ms).
[18:23:24.993] <TB1> INFO: Test took 165111ms.
[18:23:54.195] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 183 (-1/-1) hits flags = 528 (plus default)
[18:23:54.208] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:23:54.208] <TB1> INFO: run 1 of 1
[18:23:54.468] <TB1> INFO: Expecting 3827200 events.
[18:24:26.005] <TB1> INFO: 730770 events read in total (30945ms).
[18:24:56.873] <TB1> INFO: 1456785 events read in total (61813ms).
[18:25:27.378] <TB1> INFO: 2180075 events read in total (92318ms).
[18:25:58.308] <TB1> INFO: 2899180 events read in total (123248ms).
[18:26:28.953] <TB1> INFO: 3617380 events read in total (153893ms).
[18:26:38.441] <TB1> INFO: 3827200 events read in total (163381ms).
[18:26:38.486] <TB1> INFO: Test took 164278ms.
[18:27:05.191] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 181 (-1/-1) hits flags = 528 (plus default)
[18:27:05.202] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:27:05.202] <TB1> INFO: run 1 of 1
[18:27:05.438] <TB1> INFO: Expecting 3785600 events.
[18:27:36.798] <TB1> INFO: 734255 events read in total (30768ms).
[18:28:07.480] <TB1> INFO: 1463220 events read in total (61450ms).
[18:28:38.302] <TB1> INFO: 2189080 events read in total (92272ms).
[18:29:09.583] <TB1> INFO: 2910770 events read in total (123553ms).
[18:29:40.553] <TB1> INFO: 3631770 events read in total (154523ms).
[18:29:47.527] <TB1> INFO: 3785600 events read in total (161497ms).
[18:29:47.584] <TB1> INFO: Test took 162381ms.
[18:30:14.085] <TB1> INFO: PixTestTrim::trimBitTest() done
[18:30:14.086] <TB1> INFO: PixTestTrim::doTest() done, duration: 2412 seconds
[18:30:14.086] <TB1> INFO: Decoding statistics:
[18:30:14.086] <TB1> INFO: General information:
[18:30:14.086] <TB1> INFO: 16bit words read: 0
[18:30:14.086] <TB1> INFO: valid events total: 0
[18:30:14.086] <TB1> INFO: empty events: 0
[18:30:14.086] <TB1> INFO: valid events with pixels: 0
[18:30:14.086] <TB1> INFO: valid pixel hits: 0
[18:30:14.086] <TB1> INFO: Event errors: 0
[18:30:14.086] <TB1> INFO: start marker: 0
[18:30:14.086] <TB1> INFO: stop marker: 0
[18:30:14.086] <TB1> INFO: overflow: 0
[18:30:14.086] <TB1> INFO: invalid 5bit words: 0
[18:30:14.086] <TB1> INFO: invalid XOR eye diagram: 0
[18:30:14.086] <TB1> INFO: frame (failed synchr.): 0
[18:30:14.086] <TB1> INFO: idle data (no TBM trl): 0
[18:30:14.086] <TB1> INFO: no data (only TBM hdr): 0
[18:30:14.086] <TB1> INFO: TBM errors: 0
[18:30:14.086] <TB1> INFO: flawed TBM headers: 0
[18:30:14.086] <TB1> INFO: flawed TBM trailers: 0
[18:30:14.086] <TB1> INFO: event ID mismatches: 0
[18:30:14.086] <TB1> INFO: ROC errors: 0
[18:30:14.086] <TB1> INFO: missing ROC header(s): 0
[18:30:14.087] <TB1> INFO: misplaced readback start: 0
[18:30:14.087] <TB1> INFO: Pixel decoding errors: 0
[18:30:14.087] <TB1> INFO: pixel data incomplete: 0
[18:30:14.087] <TB1> INFO: pixel address: 0
[18:30:14.087] <TB1> INFO: pulse height fill bit: 0
[18:30:14.087] <TB1> INFO: buffer corruption: 0
[18:30:14.714] <TB1> INFO: ######################################################################
[18:30:14.714] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[18:30:14.714] <TB1> INFO: ######################################################################
[18:30:14.947] <TB1> INFO: Expecting 41600 events.
[18:30:18.489] <TB1> INFO: 41600 events read in total (2950ms).
[18:30:18.491] <TB1> INFO: Test took 3776ms.
[18:30:18.928] <TB1> INFO: Expecting 41600 events.
[18:30:22.505] <TB1> INFO: 41600 events read in total (2986ms).
[18:30:22.506] <TB1> INFO: Test took 3811ms.
[18:30:22.798] <TB1> INFO: Expecting 41600 events.
[18:30:26.311] <TB1> INFO: 41600 events read in total (2921ms).
[18:30:26.313] <TB1> INFO: Test took 3779ms.
[18:30:26.601] <TB1> INFO: Expecting 41600 events.
[18:30:30.056] <TB1> INFO: 41600 events read in total (2863ms).
[18:30:30.056] <TB1> INFO: Test took 3720ms.
[18:30:30.344] <TB1> INFO: Expecting 41600 events.
[18:30:33.845] <TB1> INFO: 41600 events read in total (2909ms).
[18:30:33.845] <TB1> INFO: Test took 3765ms.
[18:30:34.133] <TB1> INFO: Expecting 41600 events.
[18:30:37.607] <TB1> INFO: 41600 events read in total (2882ms).
[18:30:37.608] <TB1> INFO: Test took 3740ms.
[18:30:37.896] <TB1> INFO: Expecting 41600 events.
[18:30:41.414] <TB1> INFO: 41600 events read in total (2926ms).
[18:30:41.415] <TB1> INFO: Test took 3784ms.
[18:30:41.703] <TB1> INFO: Expecting 41600 events.
[18:30:45.176] <TB1> INFO: 41600 events read in total (2881ms).
[18:30:45.177] <TB1> INFO: Test took 3739ms.
[18:30:45.465] <TB1> INFO: Expecting 41600 events.
[18:30:48.950] <TB1> INFO: 41600 events read in total (2894ms).
[18:30:48.951] <TB1> INFO: Test took 3751ms.
[18:30:49.239] <TB1> INFO: Expecting 41600 events.
[18:30:52.703] <TB1> INFO: 41600 events read in total (2872ms).
[18:30:52.704] <TB1> INFO: Test took 3730ms.
[18:30:52.992] <TB1> INFO: Expecting 41600 events.
[18:30:56.513] <TB1> INFO: 41600 events read in total (2930ms).
[18:30:56.514] <TB1> INFO: Test took 3787ms.
[18:30:56.805] <TB1> INFO: Expecting 41600 events.
[18:31:00.257] <TB1> INFO: 41600 events read in total (2861ms).
[18:31:00.257] <TB1> INFO: Test took 3717ms.
[18:31:00.547] <TB1> INFO: Expecting 41600 events.
[18:31:04.096] <TB1> INFO: 41600 events read in total (2957ms).
[18:31:04.097] <TB1> INFO: Test took 3814ms.
[18:31:04.384] <TB1> INFO: Expecting 41600 events.
[18:31:07.886] <TB1> INFO: 41600 events read in total (2910ms).
[18:31:07.887] <TB1> INFO: Test took 3767ms.
[18:31:08.178] <TB1> INFO: Expecting 41600 events.
[18:31:11.712] <TB1> INFO: 41600 events read in total (2942ms).
[18:31:11.713] <TB1> INFO: Test took 3801ms.
[18:31:11.000] <TB1> INFO: Expecting 41600 events.
[18:31:15.439] <TB1> INFO: 41600 events read in total (2847ms).
[18:31:15.440] <TB1> INFO: Test took 3704ms.
[18:31:15.728] <TB1> INFO: Expecting 41600 events.
[18:31:19.312] <TB1> INFO: 41600 events read in total (2992ms).
[18:31:19.312] <TB1> INFO: Test took 3849ms.
[18:31:19.600] <TB1> INFO: Expecting 41600 events.
[18:31:23.067] <TB1> INFO: 41600 events read in total (2876ms).
[18:31:23.068] <TB1> INFO: Test took 3732ms.
[18:31:23.356] <TB1> INFO: Expecting 41600 events.
[18:31:26.804] <TB1> INFO: 41600 events read in total (2856ms).
[18:31:26.804] <TB1> INFO: Test took 3712ms.
[18:31:27.093] <TB1> INFO: Expecting 41600 events.
[18:31:30.620] <TB1> INFO: 41600 events read in total (2935ms).
[18:31:30.621] <TB1> INFO: Test took 3793ms.
[18:31:30.917] <TB1> INFO: Expecting 41600 events.
[18:31:34.370] <TB1> INFO: 41600 events read in total (2862ms).
[18:31:34.371] <TB1> INFO: Test took 3727ms.
[18:31:34.662] <TB1> INFO: Expecting 41600 events.
[18:31:38.107] <TB1> INFO: 41600 events read in total (2853ms).
[18:31:38.108] <TB1> INFO: Test took 3711ms.
[18:31:38.399] <TB1> INFO: Expecting 41600 events.
[18:31:41.953] <TB1> INFO: 41600 events read in total (2963ms).
[18:31:41.954] <TB1> INFO: Test took 3820ms.
[18:31:42.242] <TB1> INFO: Expecting 41600 events.
[18:31:45.788] <TB1> INFO: 41600 events read in total (2954ms).
[18:31:45.789] <TB1> INFO: Test took 3812ms.
[18:31:46.080] <TB1> INFO: Expecting 41600 events.
[18:31:49.528] <TB1> INFO: 41600 events read in total (2857ms).
[18:31:49.528] <TB1> INFO: Test took 3713ms.
[18:31:49.816] <TB1> INFO: Expecting 41600 events.
[18:31:53.323] <TB1> INFO: 41600 events read in total (2916ms).
[18:31:53.323] <TB1> INFO: Test took 3772ms.
[18:31:53.611] <TB1> INFO: Expecting 41600 events.
[18:31:57.053] <TB1> INFO: 41600 events read in total (2850ms).
[18:31:57.054] <TB1> INFO: Test took 3707ms.
[18:31:57.345] <TB1> INFO: Expecting 41600 events.
[18:32:00.878] <TB1> INFO: 41600 events read in total (2942ms).
[18:32:00.879] <TB1> INFO: Test took 3799ms.
[18:32:01.168] <TB1> INFO: Expecting 41600 events.
[18:32:04.636] <TB1> INFO: 41600 events read in total (2876ms).
[18:32:04.637] <TB1> INFO: Test took 3733ms.
[18:32:04.926] <TB1> INFO: Expecting 2560 events.
[18:32:05.808] <TB1> INFO: 2560 events read in total (291ms).
[18:32:05.808] <TB1> INFO: Test took 1159ms.
[18:32:06.116] <TB1> INFO: Expecting 2560 events.
[18:32:06.999] <TB1> INFO: 2560 events read in total (292ms).
[18:32:06.999] <TB1> INFO: Test took 1190ms.
[18:32:07.307] <TB1> INFO: Expecting 2560 events.
[18:32:08.192] <TB1> INFO: 2560 events read in total (293ms).
[18:32:08.192] <TB1> INFO: Test took 1192ms.
[18:32:08.500] <TB1> INFO: Expecting 2560 events.
[18:32:09.382] <TB1> INFO: 2560 events read in total (291ms).
[18:32:09.382] <TB1> INFO: Test took 1189ms.
[18:32:09.690] <TB1> INFO: Expecting 2560 events.
[18:32:10.569] <TB1> INFO: 2560 events read in total (288ms).
[18:32:10.569] <TB1> INFO: Test took 1187ms.
[18:32:10.877] <TB1> INFO: Expecting 2560 events.
[18:32:11.757] <TB1> INFO: 2560 events read in total (288ms).
[18:32:11.757] <TB1> INFO: Test took 1187ms.
[18:32:12.065] <TB1> INFO: Expecting 2560 events.
[18:32:12.943] <TB1> INFO: 2560 events read in total (286ms).
[18:32:12.943] <TB1> INFO: Test took 1185ms.
[18:32:13.251] <TB1> INFO: Expecting 2560 events.
[18:32:14.128] <TB1> INFO: 2560 events read in total (286ms).
[18:32:14.128] <TB1> INFO: Test took 1185ms.
[18:32:14.436] <TB1> INFO: Expecting 2560 events.
[18:32:15.317] <TB1> INFO: 2560 events read in total (289ms).
[18:32:15.317] <TB1> INFO: Test took 1188ms.
[18:32:15.625] <TB1> INFO: Expecting 2560 events.
[18:32:16.503] <TB1> INFO: 2560 events read in total (286ms).
[18:32:16.503] <TB1> INFO: Test took 1185ms.
[18:32:16.811] <TB1> INFO: Expecting 2560 events.
[18:32:17.693] <TB1> INFO: 2560 events read in total (291ms).
[18:32:17.693] <TB1> INFO: Test took 1190ms.
[18:32:17.001] <TB1> INFO: Expecting 2560 events.
[18:32:18.880] <TB1> INFO: 2560 events read in total (287ms).
[18:32:18.880] <TB1> INFO: Test took 1186ms.
[18:32:19.192] <TB1> INFO: Expecting 2560 events.
[18:32:20.075] <TB1> INFO: 2560 events read in total (291ms).
[18:32:20.075] <TB1> INFO: Test took 1194ms.
[18:32:20.383] <TB1> INFO: Expecting 2560 events.
[18:32:21.268] <TB1> INFO: 2560 events read in total (294ms).
[18:32:21.268] <TB1> INFO: Test took 1193ms.
[18:32:21.577] <TB1> INFO: Expecting 2560 events.
[18:32:22.460] <TB1> INFO: 2560 events read in total (292ms).
[18:32:22.460] <TB1> INFO: Test took 1191ms.
[18:32:22.768] <TB1> INFO: Expecting 2560 events.
[18:32:23.649] <TB1> INFO: 2560 events read in total (289ms).
[18:32:23.649] <TB1> INFO: Test took 1189ms.
[18:32:23.653] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:32:23.959] <TB1> INFO: Expecting 655360 events.
[18:32:38.287] <TB1> INFO: 655360 events read in total (13737ms).
[18:32:38.298] <TB1> INFO: Expecting 655360 events.
[18:32:52.342] <TB1> INFO: 655360 events read in total (13641ms).
[18:32:52.356] <TB1> INFO: Expecting 655360 events.
[18:33:06.397] <TB1> INFO: 655360 events read in total (13638ms).
[18:33:06.423] <TB1> INFO: Expecting 655360 events.
[18:33:20.451] <TB1> INFO: 655360 events read in total (13625ms).
[18:33:20.474] <TB1> INFO: Expecting 655360 events.
[18:33:34.505] <TB1> INFO: 655360 events read in total (13628ms).
[18:33:34.540] <TB1> INFO: Expecting 655360 events.
[18:33:48.527] <TB1> INFO: 655360 events read in total (13584ms).
[18:33:48.568] <TB1> INFO: Expecting 655360 events.
[18:34:02.585] <TB1> INFO: 655360 events read in total (13614ms).
[18:34:02.632] <TB1> INFO: Expecting 655360 events.
[18:34:16.692] <TB1> INFO: 655360 events read in total (13657ms).
[18:34:16.733] <TB1> INFO: Expecting 655360 events.
[18:34:30.795] <TB1> INFO: 655360 events read in total (13659ms).
[18:34:30.853] <TB1> INFO: Expecting 655360 events.
[18:34:44.876] <TB1> INFO: 655360 events read in total (13620ms).
[18:34:44.926] <TB1> INFO: Expecting 655360 events.
[18:34:58.886] <TB1> INFO: 655360 events read in total (13557ms).
[18:34:58.957] <TB1> INFO: Expecting 655360 events.
[18:35:12.945] <TB1> INFO: 655360 events read in total (13585ms).
[18:35:12.003] <TB1> INFO: Expecting 655360 events.
[18:35:27.101] <TB1> INFO: 655360 events read in total (13695ms).
[18:35:27.163] <TB1> INFO: Expecting 655360 events.
[18:35:41.203] <TB1> INFO: 655360 events read in total (13637ms).
[18:35:41.269] <TB1> INFO: Expecting 655360 events.
[18:35:55.360] <TB1> INFO: 655360 events read in total (13688ms).
[18:35:55.454] <TB1> INFO: Expecting 655360 events.
[18:36:09.527] <TB1> INFO: 655360 events read in total (13671ms).
[18:36:09.603] <TB1> INFO: Test took 225950ms.
[18:36:09.684] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:36:09.949] <TB1> INFO: Expecting 655360 events.
[18:36:24.133] <TB1> INFO: 655360 events read in total (13593ms).
[18:36:24.147] <TB1> INFO: Expecting 655360 events.
[18:36:38.203] <TB1> INFO: 655360 events read in total (13653ms).
[18:36:38.218] <TB1> INFO: Expecting 655360 events.
[18:36:51.817] <TB1> INFO: 655360 events read in total (13197ms).
[18:36:51.839] <TB1> INFO: Expecting 655360 events.
[18:37:05.943] <TB1> INFO: 655360 events read in total (13700ms).
[18:37:05.966] <TB1> INFO: Expecting 655360 events.
[18:37:19.923] <TB1> INFO: 655360 events read in total (13554ms).
[18:37:19.957] <TB1> INFO: Expecting 655360 events.
[18:37:33.721] <TB1> INFO: 655360 events read in total (13361ms).
[18:37:33.749] <TB1> INFO: Expecting 655360 events.
[18:37:47.858] <TB1> INFO: 655360 events read in total (13706ms).
[18:37:47.907] <TB1> INFO: Expecting 655360 events.
[18:38:01.792] <TB1> INFO: 655360 events read in total (13482ms).
[18:38:01.840] <TB1> INFO: Expecting 655360 events.
[18:38:15.799] <TB1> INFO: 655360 events read in total (13556ms).
[18:38:15.842] <TB1> INFO: Expecting 655360 events.
[18:38:29.782] <TB1> INFO: 655360 events read in total (13537ms).
[18:38:29.830] <TB1> INFO: Expecting 655360 events.
[18:38:43.866] <TB1> INFO: 655360 events read in total (13633ms).
[18:38:43.919] <TB1> INFO: Expecting 655360 events.
[18:38:57.933] <TB1> INFO: 655360 events read in total (13611ms).
[18:38:58.008] <TB1> INFO: Expecting 655360 events.
[18:39:11.858] <TB1> INFO: 655360 events read in total (13447ms).
[18:39:11.940] <TB1> INFO: Expecting 655360 events.
[18:39:26.080] <TB1> INFO: 655360 events read in total (13737ms).
[18:39:26.145] <TB1> INFO: Expecting 655360 events.
[18:39:40.180] <TB1> INFO: 655360 events read in total (13632ms).
[18:39:40.250] <TB1> INFO: Expecting 655360 events.
[18:39:54.394] <TB1> INFO: 655360 events read in total (13740ms).
[18:39:54.467] <TB1> INFO: Test took 224783ms.
[18:39:54.662] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.666] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.671] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.675] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.680] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.684] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:39:54.689] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:39:54.693] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[18:39:54.698] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.703] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.707] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.712] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.716] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.721] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:39:54.725] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:39:54.730] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.735] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.739] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.744] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:39:54.748] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:39:54.753] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[18:39:54.757] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[18:39:54.762] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[18:39:54.766] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.771] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:39:54.775] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.781] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:39:54.787] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:39:54.793] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[18:39:54.800] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[18:39:54.806] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[18:39:54.812] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[18:39:54.818] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:54.825] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:39:54.831] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:39:54.837] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[18:39:54.843] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[18:39:54.850] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[18:39:54.856] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[18:39:54.890] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C0.dat
[18:39:54.890] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C1.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C2.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C3.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C4.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C5.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C6.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C7.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C8.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C9.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C10.dat
[18:39:54.891] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C11.dat
[18:39:54.892] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C12.dat
[18:39:54.892] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C13.dat
[18:39:54.892] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C14.dat
[18:39:54.892] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C15.dat
[18:39:55.130] <TB1> INFO: Expecting 41600 events.
[18:39:58.260] <TB1> INFO: 41600 events read in total (2538ms).
[18:39:58.261] <TB1> INFO: Test took 3366ms.
[18:39:58.703] <TB1> INFO: Expecting 41600 events.
[18:40:01.767] <TB1> INFO: 41600 events read in total (2472ms).
[18:40:01.768] <TB1> INFO: Test took 3297ms.
[18:40:02.212] <TB1> INFO: Expecting 41600 events.
[18:40:05.283] <TB1> INFO: 41600 events read in total (2480ms).
[18:40:05.284] <TB1> INFO: Test took 3305ms.
[18:40:05.498] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:05.586] <TB1> INFO: Expecting 2560 events.
[18:40:06.470] <TB1> INFO: 2560 events read in total (292ms).
[18:40:06.471] <TB1> INFO: Test took 973ms.
[18:40:06.473] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:06.779] <TB1> INFO: Expecting 2560 events.
[18:40:07.663] <TB1> INFO: 2560 events read in total (292ms).
[18:40:07.663] <TB1> INFO: Test took 1190ms.
[18:40:07.665] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:07.971] <TB1> INFO: Expecting 2560 events.
[18:40:08.854] <TB1> INFO: 2560 events read in total (291ms).
[18:40:08.854] <TB1> INFO: Test took 1189ms.
[18:40:08.856] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:09.162] <TB1> INFO: Expecting 2560 events.
[18:40:10.048] <TB1> INFO: 2560 events read in total (294ms).
[18:40:10.048] <TB1> INFO: Test took 1192ms.
[18:40:10.051] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:10.356] <TB1> INFO: Expecting 2560 events.
[18:40:11.241] <TB1> INFO: 2560 events read in total (293ms).
[18:40:11.241] <TB1> INFO: Test took 1190ms.
[18:40:11.243] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:11.549] <TB1> INFO: Expecting 2560 events.
[18:40:12.432] <TB1> INFO: 2560 events read in total (291ms).
[18:40:12.433] <TB1> INFO: Test took 1190ms.
[18:40:12.434] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:12.741] <TB1> INFO: Expecting 2560 events.
[18:40:13.623] <TB1> INFO: 2560 events read in total (290ms).
[18:40:13.624] <TB1> INFO: Test took 1190ms.
[18:40:13.626] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:13.932] <TB1> INFO: Expecting 2560 events.
[18:40:14.815] <TB1> INFO: 2560 events read in total (291ms).
[18:40:14.816] <TB1> INFO: Test took 1191ms.
[18:40:14.817] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:15.124] <TB1> INFO: Expecting 2560 events.
[18:40:16.003] <TB1> INFO: 2560 events read in total (287ms).
[18:40:16.004] <TB1> INFO: Test took 1187ms.
[18:40:16.005] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:16.312] <TB1> INFO: Expecting 2560 events.
[18:40:17.190] <TB1> INFO: 2560 events read in total (286ms).
[18:40:17.190] <TB1> INFO: Test took 1185ms.
[18:40:17.192] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:17.499] <TB1> INFO: Expecting 2560 events.
[18:40:18.378] <TB1> INFO: 2560 events read in total (287ms).
[18:40:18.378] <TB1> INFO: Test took 1186ms.
[18:40:18.380] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:18.687] <TB1> INFO: Expecting 2560 events.
[18:40:19.564] <TB1> INFO: 2560 events read in total (286ms).
[18:40:19.565] <TB1> INFO: Test took 1185ms.
[18:40:19.566] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:19.873] <TB1> INFO: Expecting 2560 events.
[18:40:20.755] <TB1> INFO: 2560 events read in total (290ms).
[18:40:20.755] <TB1> INFO: Test took 1189ms.
[18:40:20.756] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:21.063] <TB1> INFO: Expecting 2560 events.
[18:40:21.943] <TB1> INFO: 2560 events read in total (288ms).
[18:40:21.943] <TB1> INFO: Test took 1187ms.
[18:40:21.945] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:22.251] <TB1> INFO: Expecting 2560 events.
[18:40:23.129] <TB1> INFO: 2560 events read in total (286ms).
[18:40:23.130] <TB1> INFO: Test took 1185ms.
[18:40:23.131] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:23.438] <TB1> INFO: Expecting 2560 events.
[18:40:24.316] <TB1> INFO: 2560 events read in total (286ms).
[18:40:24.316] <TB1> INFO: Test took 1185ms.
[18:40:24.318] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:24.624] <TB1> INFO: Expecting 2560 events.
[18:40:25.504] <TB1> INFO: 2560 events read in total (288ms).
[18:40:25.505] <TB1> INFO: Test took 1187ms.
[18:40:25.506] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:25.813] <TB1> INFO: Expecting 2560 events.
[18:40:26.692] <TB1> INFO: 2560 events read in total (287ms).
[18:40:26.692] <TB1> INFO: Test took 1186ms.
[18:40:26.694] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:26.001] <TB1> INFO: Expecting 2560 events.
[18:40:27.878] <TB1> INFO: 2560 events read in total (286ms).
[18:40:27.878] <TB1> INFO: Test took 1184ms.
[18:40:27.880] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:28.187] <TB1> INFO: Expecting 2560 events.
[18:40:29.065] <TB1> INFO: 2560 events read in total (287ms).
[18:40:29.065] <TB1> INFO: Test took 1185ms.
[18:40:29.067] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:29.376] <TB1> INFO: Expecting 2560 events.
[18:40:30.255] <TB1> INFO: 2560 events read in total (287ms).
[18:40:30.255] <TB1> INFO: Test took 1188ms.
[18:40:30.257] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:30.563] <TB1> INFO: Expecting 2560 events.
[18:40:31.442] <TB1> INFO: 2560 events read in total (287ms).
[18:40:31.442] <TB1> INFO: Test took 1185ms.
[18:40:31.444] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:31.751] <TB1> INFO: Expecting 2560 events.
[18:40:32.637] <TB1> INFO: 2560 events read in total (295ms).
[18:40:32.637] <TB1> INFO: Test took 1193ms.
[18:40:32.639] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:32.946] <TB1> INFO: Expecting 2560 events.
[18:40:33.825] <TB1> INFO: 2560 events read in total (287ms).
[18:40:33.825] <TB1> INFO: Test took 1186ms.
[18:40:33.827] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:34.133] <TB1> INFO: Expecting 2560 events.
[18:40:35.018] <TB1> INFO: 2560 events read in total (293ms).
[18:40:35.019] <TB1> INFO: Test took 1192ms.
[18:40:35.020] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:35.327] <TB1> INFO: Expecting 2560 events.
[18:40:36.212] <TB1> INFO: 2560 events read in total (294ms).
[18:40:36.212] <TB1> INFO: Test took 1192ms.
[18:40:36.214] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:36.520] <TB1> INFO: Expecting 2560 events.
[18:40:37.406] <TB1> INFO: 2560 events read in total (294ms).
[18:40:37.406] <TB1> INFO: Test took 1193ms.
[18:40:37.408] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:37.715] <TB1> INFO: Expecting 2560 events.
[18:40:38.602] <TB1> INFO: 2560 events read in total (296ms).
[18:40:38.602] <TB1> INFO: Test took 1195ms.
[18:40:38.604] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:38.911] <TB1> INFO: Expecting 2560 events.
[18:40:39.795] <TB1> INFO: 2560 events read in total (293ms).
[18:40:39.795] <TB1> INFO: Test took 1191ms.
[18:40:39.797] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:40.104] <TB1> INFO: Expecting 2560 events.
[18:40:40.987] <TB1> INFO: 2560 events read in total (291ms).
[18:40:40.987] <TB1> INFO: Test took 1190ms.
[18:40:40.989] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:41.295] <TB1> INFO: Expecting 2560 events.
[18:40:42.179] <TB1> INFO: 2560 events read in total (292ms).
[18:40:42.179] <TB1> INFO: Test took 1190ms.
[18:40:42.181] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:42.487] <TB1> INFO: Expecting 2560 events.
[18:40:43.370] <TB1> INFO: 2560 events read in total (291ms).
[18:40:43.370] <TB1> INFO: Test took 1190ms.
[18:40:43.833] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 629 seconds
[18:40:43.833] <TB1> INFO: PH scale (per ROC): 68 49 58 59 43 46 48 55 59 69 60 62 48 46 48 49
[18:40:43.833] <TB1> INFO: PH offset (per ROC): 131 96 114 121 100 113 100 118 123 131 124 108 102 91 99 112
[18:40:43.839] <TB1> INFO: Decoding statistics:
[18:40:43.839] <TB1> INFO: General information:
[18:40:43.839] <TB1> INFO: 16bit words read: 127880
[18:40:43.839] <TB1> INFO: valid events total: 20480
[18:40:43.839] <TB1> INFO: empty events: 17980
[18:40:43.839] <TB1> INFO: valid events with pixels: 2500
[18:40:43.839] <TB1> INFO: valid pixel hits: 2500
[18:40:43.839] <TB1> INFO: Event errors: 0
[18:40:43.839] <TB1> INFO: start marker: 0
[18:40:43.839] <TB1> INFO: stop marker: 0
[18:40:43.839] <TB1> INFO: overflow: 0
[18:40:43.839] <TB1> INFO: invalid 5bit words: 0
[18:40:43.839] <TB1> INFO: invalid XOR eye diagram: 0
[18:40:43.839] <TB1> INFO: frame (failed synchr.): 0
[18:40:43.839] <TB1> INFO: idle data (no TBM trl): 0
[18:40:43.839] <TB1> INFO: no data (only TBM hdr): 0
[18:40:43.839] <TB1> INFO: TBM errors: 0
[18:40:43.839] <TB1> INFO: flawed TBM headers: 0
[18:40:43.839] <TB1> INFO: flawed TBM trailers: 0
[18:40:43.839] <TB1> INFO: event ID mismatches: 0
[18:40:43.839] <TB1> INFO: ROC errors: 0
[18:40:43.839] <TB1> INFO: missing ROC header(s): 0
[18:40:43.839] <TB1> INFO: misplaced readback start: 0
[18:40:43.839] <TB1> INFO: Pixel decoding errors: 0
[18:40:43.839] <TB1> INFO: pixel data incomplete: 0
[18:40:43.839] <TB1> INFO: pixel address: 0
[18:40:43.839] <TB1> INFO: pulse height fill bit: 0
[18:40:43.839] <TB1> INFO: buffer corruption: 0
[18:40:44.105] <TB1> INFO: ######################################################################
[18:40:44.105] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[18:40:44.105] <TB1> INFO: ######################################################################
[18:40:44.115] <TB1> INFO: scanning low vcal = 10
[18:40:44.348] <TB1> INFO: Expecting 41600 events.
[18:40:47.914] <TB1> INFO: 41600 events read in total (2975ms).
[18:40:47.915] <TB1> INFO: Test took 3800ms.
[18:40:47.916] <TB1> INFO: scanning low vcal = 20
[18:40:48.216] <TB1> INFO: Expecting 41600 events.
[18:40:51.775] <TB1> INFO: 41600 events read in total (2968ms).
[18:40:51.775] <TB1> INFO: Test took 3859ms.
[18:40:51.777] <TB1> INFO: scanning low vcal = 30
[18:40:52.076] <TB1> INFO: Expecting 41600 events.
[18:40:55.692] <TB1> INFO: 41600 events read in total (3024ms).
[18:40:55.693] <TB1> INFO: Test took 3916ms.
[18:40:55.695] <TB1> INFO: scanning low vcal = 40
[18:40:55.976] <TB1> INFO: Expecting 41600 events.
[18:40:59.882] <TB1> INFO: 41600 events read in total (3314ms).
[18:40:59.883] <TB1> INFO: Test took 4188ms.
[18:40:59.886] <TB1> INFO: scanning low vcal = 50
[18:41:00.162] <TB1> INFO: Expecting 41600 events.
[18:41:04.112] <TB1> INFO: 41600 events read in total (3358ms).
[18:41:04.113] <TB1> INFO: Test took 4227ms.
[18:41:04.116] <TB1> INFO: scanning low vcal = 60
[18:41:04.392] <TB1> INFO: Expecting 41600 events.
[18:41:08.335] <TB1> INFO: 41600 events read in total (3351ms).
[18:41:08.336] <TB1> INFO: Test took 4220ms.
[18:41:08.339] <TB1> INFO: scanning low vcal = 70
[18:41:08.615] <TB1> INFO: Expecting 41600 events.
[18:41:12.568] <TB1> INFO: 41600 events read in total (3361ms).
[18:41:12.568] <TB1> INFO: Test took 4229ms.
[18:41:12.571] <TB1> INFO: scanning low vcal = 80
[18:41:12.848] <TB1> INFO: Expecting 41600 events.
[18:41:16.823] <TB1> INFO: 41600 events read in total (3384ms).
[18:41:16.823] <TB1> INFO: Test took 4252ms.
[18:41:16.826] <TB1> INFO: scanning low vcal = 90
[18:41:17.103] <TB1> INFO: Expecting 41600 events.
[18:41:21.081] <TB1> INFO: 41600 events read in total (3387ms).
[18:41:21.082] <TB1> INFO: Test took 4256ms.
[18:41:21.084] <TB1> INFO: scanning low vcal = 100
[18:41:21.361] <TB1> INFO: Expecting 41600 events.
[18:41:25.290] <TB1> INFO: 41600 events read in total (3337ms).
[18:41:25.290] <TB1> INFO: Test took 4206ms.
[18:41:25.293] <TB1> INFO: scanning low vcal = 110
[18:41:25.569] <TB1> INFO: Expecting 41600 events.
[18:41:29.513] <TB1> INFO: 41600 events read in total (3352ms).
[18:41:29.513] <TB1> INFO: Test took 4220ms.
[18:41:29.516] <TB1> INFO: scanning low vcal = 120
[18:41:29.793] <TB1> INFO: Expecting 41600 events.
[18:41:33.735] <TB1> INFO: 41600 events read in total (3351ms).
[18:41:33.735] <TB1> INFO: Test took 4219ms.
[18:41:33.738] <TB1> INFO: scanning low vcal = 130
[18:41:34.015] <TB1> INFO: Expecting 41600 events.
[18:41:37.963] <TB1> INFO: 41600 events read in total (3357ms).
[18:41:37.964] <TB1> INFO: Test took 4226ms.
[18:41:37.966] <TB1> INFO: scanning low vcal = 140
[18:41:38.243] <TB1> INFO: Expecting 41600 events.
[18:41:42.177] <TB1> INFO: 41600 events read in total (3342ms).
[18:41:42.178] <TB1> INFO: Test took 4212ms.
[18:41:42.181] <TB1> INFO: scanning low vcal = 150
[18:41:42.457] <TB1> INFO: Expecting 41600 events.
[18:41:46.389] <TB1> INFO: 41600 events read in total (3340ms).
[18:41:46.390] <TB1> INFO: Test took 4209ms.
[18:41:46.392] <TB1> INFO: scanning low vcal = 160
[18:41:46.669] <TB1> INFO: Expecting 41600 events.
[18:41:50.648] <TB1> INFO: 41600 events read in total (3387ms).
[18:41:50.648] <TB1> INFO: Test took 4256ms.
[18:41:50.651] <TB1> INFO: scanning low vcal = 170
[18:41:50.928] <TB1> INFO: Expecting 41600 events.
[18:41:54.910] <TB1> INFO: 41600 events read in total (3390ms).
[18:41:54.911] <TB1> INFO: Test took 4260ms.
[18:41:54.914] <TB1> INFO: scanning low vcal = 180
[18:41:55.190] <TB1> INFO: Expecting 41600 events.
[18:41:59.134] <TB1> INFO: 41600 events read in total (3352ms).
[18:41:59.135] <TB1> INFO: Test took 4221ms.
[18:41:59.137] <TB1> INFO: scanning low vcal = 190
[18:41:59.414] <TB1> INFO: Expecting 41600 events.
[18:42:03.410] <TB1> INFO: 41600 events read in total (3405ms).
[18:42:03.411] <TB1> INFO: Test took 4274ms.
[18:42:03.414] <TB1> INFO: scanning low vcal = 200
[18:42:03.691] <TB1> INFO: Expecting 41600 events.
[18:42:07.627] <TB1> INFO: 41600 events read in total (3345ms).
[18:42:07.628] <TB1> INFO: Test took 4214ms.
[18:42:07.630] <TB1> INFO: scanning low vcal = 210
[18:42:07.907] <TB1> INFO: Expecting 41600 events.
[18:42:11.881] <TB1> INFO: 41600 events read in total (3383ms).
[18:42:11.882] <TB1> INFO: Test took 4252ms.
[18:42:11.884] <TB1> INFO: scanning low vcal = 220
[18:42:12.161] <TB1> INFO: Expecting 41600 events.
[18:42:16.107] <TB1> INFO: 41600 events read in total (3354ms).
[18:42:16.108] <TB1> INFO: Test took 4223ms.
[18:42:16.111] <TB1> INFO: scanning low vcal = 230
[18:42:16.388] <TB1> INFO: Expecting 41600 events.
[18:42:20.346] <TB1> INFO: 41600 events read in total (3367ms).
[18:42:20.346] <TB1> INFO: Test took 4235ms.
[18:42:20.349] <TB1> INFO: scanning low vcal = 240
[18:42:20.626] <TB1> INFO: Expecting 41600 events.
[18:42:24.592] <TB1> INFO: 41600 events read in total (3375ms).
[18:42:24.593] <TB1> INFO: Test took 4244ms.
[18:42:24.595] <TB1> INFO: scanning low vcal = 250
[18:42:24.872] <TB1> INFO: Expecting 41600 events.
[18:42:28.858] <TB1> INFO: 41600 events read in total (3395ms).
[18:42:28.859] <TB1> INFO: Test took 4263ms.
[18:42:28.863] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[18:42:29.138] <TB1> INFO: Expecting 41600 events.
[18:42:33.114] <TB1> INFO: 41600 events read in total (3384ms).
[18:42:33.115] <TB1> INFO: Test took 4252ms.
[18:42:33.118] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[18:42:33.394] <TB1> INFO: Expecting 41600 events.
[18:42:37.332] <TB1> INFO: 41600 events read in total (3346ms).
[18:42:37.332] <TB1> INFO: Test took 4214ms.
[18:42:37.335] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[18:42:37.611] <TB1> INFO: Expecting 41600 events.
[18:42:41.589] <TB1> INFO: 41600 events read in total (3386ms).
[18:42:41.590] <TB1> INFO: Test took 4255ms.
[18:42:41.593] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[18:42:41.870] <TB1> INFO: Expecting 41600 events.
[18:42:45.817] <TB1> INFO: 41600 events read in total (3356ms).
[18:42:45.818] <TB1> INFO: Test took 4225ms.
[18:42:45.821] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[18:42:46.097] <TB1> INFO: Expecting 41600 events.
[18:42:50.044] <TB1> INFO: 41600 events read in total (3355ms).
[18:42:50.044] <TB1> INFO: Test took 4223ms.
[18:42:50.591] <TB1> INFO: PixTestGainPedestal::measure() done
[18:43:28.269] <TB1> INFO: PixTestGainPedestal::fit() done
[18:43:28.269] <TB1> INFO: non-linearity mean: 0.986 0.933 0.970 0.982 0.918 0.919 0.917 0.976 0.982 0.985 0.976 0.972 0.928 0.897 0.933 0.964
[18:43:28.269] <TB1> INFO: non-linearity RMS: 0.004 0.062 0.008 0.005 0.129 0.089 0.087 0.005 0.003 0.003 0.004 0.023 0.084 0.135 0.064 0.023
[18:43:28.269] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[18:43:28.284] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[18:43:28.298] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[18:43:28.311] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[18:43:28.325] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[18:43:28.341] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[18:43:28.359] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[18:43:28.380] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[18:43:28.401] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[18:43:28.423] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[18:43:28.444] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[18:43:28.466] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[18:43:28.487] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[18:43:28.509] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[18:43:28.530] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[18:43:28.552] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1094_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[18:43:28.567] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 164 seconds
[18:43:28.567] <TB1> INFO: Decoding statistics:
[18:43:28.567] <TB1> INFO: General information:
[18:43:28.567] <TB1> INFO: 16bit words read: 3327966
[18:43:28.567] <TB1> INFO: valid events total: 332800
[18:43:28.567] <TB1> INFO: empty events: 0
[18:43:28.567] <TB1> INFO: valid events with pixels: 332800
[18:43:28.567] <TB1> INFO: valid pixel hits: 665583
[18:43:28.567] <TB1> INFO: Event errors: 0
[18:43:28.567] <TB1> INFO: start marker: 0
[18:43:28.567] <TB1> INFO: stop marker: 0
[18:43:28.567] <TB1> INFO: overflow: 0
[18:43:28.567] <TB1> INFO: invalid 5bit words: 0
[18:43:28.567] <TB1> INFO: invalid XOR eye diagram: 0
[18:43:28.567] <TB1> INFO: frame (failed synchr.): 0
[18:43:28.567] <TB1> INFO: idle data (no TBM trl): 0
[18:43:28.567] <TB1> INFO: no data (only TBM hdr): 0
[18:43:28.567] <TB1> INFO: TBM errors: 0
[18:43:28.567] <TB1> INFO: flawed TBM headers: 0
[18:43:28.567] <TB1> INFO: flawed TBM trailers: 0
[18:43:28.567] <TB1> INFO: event ID mismatches: 0
[18:43:28.567] <TB1> INFO: ROC errors: 0
[18:43:28.567] <TB1> INFO: missing ROC header(s): 0
[18:43:28.567] <TB1> INFO: misplaced readback start: 0
[18:43:28.567] <TB1> INFO: Pixel decoding errors: 0
[18:43:28.567] <TB1> INFO: pixel data incomplete: 0
[18:43:28.567] <TB1> INFO: pixel address: 0
[18:43:28.567] <TB1> INFO: pulse height fill bit: 0
[18:43:28.567] <TB1> INFO: buffer corruption: 0
[18:43:28.582] <TB1> INFO: Decoding statistics:
[18:43:28.582] <TB1> INFO: General information:
[18:43:28.582] <TB1> INFO: 16bit words read: 3457382
[18:43:28.582] <TB1> INFO: valid events total: 353536
[18:43:28.582] <TB1> INFO: empty events: 18236
[18:43:28.582] <TB1> INFO: valid events with pixels: 335300
[18:43:28.582] <TB1> INFO: valid pixel hits: 668083
[18:43:28.582] <TB1> INFO: Event errors: 0
[18:43:28.582] <TB1> INFO: start marker: 0
[18:43:28.582] <TB1> INFO: stop marker: 0
[18:43:28.582] <TB1> INFO: overflow: 0
[18:43:28.582] <TB1> INFO: invalid 5bit words: 0
[18:43:28.582] <TB1> INFO: invalid XOR eye diagram: 0
[18:43:28.582] <TB1> INFO: frame (failed synchr.): 0
[18:43:28.582] <TB1> INFO: idle data (no TBM trl): 0
[18:43:28.582] <TB1> INFO: no data (only TBM hdr): 0
[18:43:28.582] <TB1> INFO: TBM errors: 0
[18:43:28.582] <TB1> INFO: flawed TBM headers: 0
[18:43:28.582] <TB1> INFO: flawed TBM trailers: 0
[18:43:28.582] <TB1> INFO: event ID mismatches: 0
[18:43:28.582] <TB1> INFO: ROC errors: 0
[18:43:28.582] <TB1> INFO: missing ROC header(s): 0
[18:43:28.582] <TB1> INFO: misplaced readback start: 0
[18:43:28.582] <TB1> INFO: Pixel decoding errors: 0
[18:43:28.582] <TB1> INFO: pixel data incomplete: 0
[18:43:28.582] <TB1> INFO: pixel address: 0
[18:43:28.582] <TB1> INFO: pulse height fill bit: 0
[18:43:28.582] <TB1> INFO: buffer corruption: 0
[18:43:28.582] <TB1> INFO: enter test to run
[18:43:28.582] <TB1> INFO: test: exit no parameter change
[18:43:28.620] <TB1> QUIET: Connection to board 153 closed.
[18:43:28.621] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud