Test Date: 2016-11-14 09:59
Analysis date: 2016-11-14 14:02
Logfile
LogfileView
[10:10:14.747] <TB0> INFO: *** Welcome to pxar ***
[10:10:14.747] <TB0> INFO: *** Today: 2016/11/14
[10:10:14.752] <TB0> INFO: *** Version: c8ba-dirty
[10:10:14.753] <TB0> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C15.dat
[10:10:14.753] <TB0> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//tbmParameters_C1b.dat
[10:10:14.754] <TB0> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//defaultMaskFile.dat
[10:10:14.754] <TB0> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters_C15.dat
[10:10:14.813] <TB0> INFO: clk: 4
[10:10:14.813] <TB0> INFO: ctr: 4
[10:10:14.813] <TB0> INFO: sda: 19
[10:10:14.813] <TB0> INFO: tin: 9
[10:10:14.813] <TB0> INFO: level: 15
[10:10:14.813] <TB0> INFO: triggerdelay: 0
[10:10:14.813] <TB0> QUIET: Instanciating API for pxar v2.7.6+61~g7f4a123
[10:10:14.813] <TB0> INFO: Log level: INFO
[10:10:14.821] <TB0> INFO: Found DTB DTB_WRQ4OZ
[10:10:14.841] <TB0> QUIET: Connection to board DTB_WRQ4OZ opened.
[10:10:14.843] <TB0> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 71
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WRQ4OZ
MAC address: 40D855118047
Hostname: pixelDTB071
Comment:
------------------------------------------------------
[10:10:14.845] <TB0> INFO: RPC call hashes of host and DTB match: 486171790
[10:10:16.329] <TB0> INFO: DUT info:
[10:10:16.329] <TB0> INFO: The DUT currently contains the following objects:
[10:10:16.329] <TB0> INFO: 4 TBM Cores tbm10c (4 ON)
[10:10:16.329] <TB0> INFO: TBM Core alpha (0): 7 registers set
[10:10:16.329] <TB0> INFO: TBM Core beta (1): 7 registers set
[10:10:16.329] <TB0> INFO: TBM Core alpha (2): 7 registers set
[10:10:16.329] <TB0> INFO: TBM Core beta (3): 7 registers set
[10:10:16.329] <TB0> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[10:10:16.329] <TB0> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.329] <TB0> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.329] <TB0> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.329] <TB0> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.329] <TB0> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.329] <TB0> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.329] <TB0> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.329] <TB0> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.330] <TB0> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.330] <TB0> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.330] <TB0> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.330] <TB0> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.330] <TB0> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.330] <TB0> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.330] <TB0> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.330] <TB0> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:10:16.730] <TB0> INFO: enter 'restricted' command line mode
[10:10:16.730] <TB0> INFO: enter test to run
[10:10:16.730] <TB0> INFO: test: pretest no parameter change
[10:10:16.730] <TB0> INFO: running: pretest
[10:10:16.735] <TB0> INFO: ######################################################################
[10:10:16.735] <TB0> INFO: PixTestPretest::doTest()
[10:10:16.735] <TB0> INFO: ######################################################################
[10:10:16.736] <TB0> INFO: ----------------------------------------------------------------------
[10:10:16.736] <TB0> INFO: PixTestPretest::programROC()
[10:10:16.736] <TB0> INFO: ----------------------------------------------------------------------
[10:10:34.749] <TB0> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[10:10:34.749] <TB0> INFO: IA differences per ROC: 20.9 20.9 20.9 16.9 18.5 17.7 19.3 16.9 17.7 20.1 16.1 19.3 16.9 18.5 19.3 18.5
[10:10:34.813] <TB0> INFO: ----------------------------------------------------------------------
[10:10:34.813] <TB0> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[10:10:34.813] <TB0> INFO: ----------------------------------------------------------------------
[10:10:56.089] <TB0> INFO: PixTestPretest::setVana() done, Module Ia 405.2 mA = 25.325 mA/ROC
[10:10:56.089] <TB0> INFO: i(loss) [mA/ROC]: 20.1 20.9 19.3 20.1 20.1 20.1 21.7 19.3 19.3 20.1 19.3 20.9 20.1 20.9 20.9 21.7
[10:10:56.124] <TB0> INFO: ----------------------------------------------------------------------
[10:10:56.124] <TB0> INFO: PixTestPretest::findTiming()
[10:10:56.124] <TB0> INFO: ----------------------------------------------------------------------
[10:10:56.124] <TB0> INFO: PixTestCmd::init()
[10:10:56.706] <TB0> WARNING: Not unmasking DUT, not setting Calibrate bits!

[10:11:28.465] <TB0> INFO: TBM phases: 160MHz: 7, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[10:11:28.465] <TB0> INFO: (success/tries = 100/100), width = 4
[10:11:29.972] <TB0> INFO: ----------------------------------------------------------------------
[10:11:29.972] <TB0> INFO: PixTestPretest::findWorkingPixel()
[10:11:29.972] <TB0> INFO: ----------------------------------------------------------------------
[10:11:30.067] <TB0> INFO: Expecting 231680 events.
[10:11:40.055] <TB0> INFO: 231680 events read in total (9396ms).
[10:11:40.064] <TB0> INFO: Test took 10088ms.
[10:11:40.312] <TB0> INFO: Found working pixel in all ROCs: col/row = 12/22
[10:11:40.351] <TB0> INFO: ----------------------------------------------------------------------
[10:11:40.351] <TB0> INFO: PixTestPretest::setVthrCompCalDel()
[10:11:40.351] <TB0> INFO: ----------------------------------------------------------------------
[10:11:40.446] <TB0> INFO: Expecting 231680 events.
[10:11:50.296] <TB0> INFO: 231680 events read in total (9259ms).
[10:11:50.307] <TB0> INFO: Test took 9952ms.
[10:11:50.576] <TB0> INFO: PixTestPretest::setVthrCompCalDel() done
[10:11:50.576] <TB0> INFO: CalDel: 87 78 92 92 102 98 71 95 91 93 82 96 83 90 113 107
[10:11:50.576] <TB0> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[10:11:50.579] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C0.dat
[10:11:50.580] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C1.dat
[10:11:50.580] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C2.dat
[10:11:50.580] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C3.dat
[10:11:50.580] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C4.dat
[10:11:50.581] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C5.dat
[10:11:50.581] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C6.dat
[10:11:50.581] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C7.dat
[10:11:50.581] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C8.dat
[10:11:50.582] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C9.dat
[10:11:50.582] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C10.dat
[10:11:50.582] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C11.dat
[10:11:50.582] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C12.dat
[10:11:50.582] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C13.dat
[10:11:50.583] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C14.dat
[10:11:50.583] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters_C15.dat
[10:11:50.583] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//tbmParameters_C0a.dat
[10:11:50.583] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//tbmParameters_C0b.dat
[10:11:50.583] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//tbmParameters_C1a.dat
[10:11:50.583] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//tbmParameters_C1b.dat
[10:11:50.584] <TB0> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[10:11:50.647] <TB0> INFO: enter test to run
[10:11:50.647] <TB0> INFO: test: FullTest no parameter change
[10:11:50.647] <TB0> INFO: running: fulltest
[10:11:50.647] <TB0> INFO: ######################################################################
[10:11:50.647] <TB0> INFO: PixTestFullTest::doTest()
[10:11:50.647] <TB0> INFO: ######################################################################
[10:11:50.648] <TB0> INFO: ######################################################################
[10:11:50.648] <TB0> INFO: PixTestAlive::doTest()
[10:11:50.648] <TB0> INFO: ######################################################################
[10:11:50.651] <TB0> INFO: ----------------------------------------------------------------------
[10:11:50.651] <TB0> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:11:50.651] <TB0> INFO: ----------------------------------------------------------------------
[10:11:50.892] <TB0> INFO: Expecting 41600 events.
[10:11:54.521] <TB0> INFO: 41600 events read in total (3037ms).
[10:11:54.521] <TB0> INFO: Test took 3868ms.
[10:11:54.754] <TB0> INFO: PixTestAlive::aliveTest() done
[10:11:54.754] <TB0> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[10:11:54.755] <TB0> INFO: ----------------------------------------------------------------------
[10:11:54.755] <TB0> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:11:54.755] <TB0> INFO: ----------------------------------------------------------------------
[10:11:54.999] <TB0> INFO: Expecting 41600 events.
[10:11:57.984] <TB0> INFO: 41600 events read in total (2393ms).
[10:11:57.985] <TB0> INFO: Test took 3228ms.
[10:11:57.985] <TB0> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:11:58.226] <TB0> INFO: PixTestAlive::maskTest() done
[10:11:58.226] <TB0> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:11:58.227] <TB0> INFO: ----------------------------------------------------------------------
[10:11:58.227] <TB0> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:11:58.227] <TB0> INFO: ----------------------------------------------------------------------
[10:11:58.469] <TB0> INFO: Expecting 41600 events.
[10:12:02.015] <TB0> INFO: 41600 events read in total (2954ms).
[10:12:02.016] <TB0> INFO: Test took 3787ms.
[10:12:02.250] <TB0> INFO: PixTestAlive::addressDecodingTest() done
[10:12:02.250] <TB0> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:12:02.250] <TB0> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[10:12:02.250] <TB0> INFO: Decoding statistics:
[10:12:02.250] <TB0> INFO: General information:
[10:12:02.250] <TB0> INFO: 16bit words read: 0
[10:12:02.250] <TB0> INFO: valid events total: 0
[10:12:02.250] <TB0> INFO: empty events: 0
[10:12:02.250] <TB0> INFO: valid events with pixels: 0
[10:12:02.250] <TB0> INFO: valid pixel hits: 0
[10:12:02.250] <TB0> INFO: Event errors: 0
[10:12:02.250] <TB0> INFO: start marker: 0
[10:12:02.250] <TB0> INFO: stop marker: 0
[10:12:02.250] <TB0> INFO: overflow: 0
[10:12:02.250] <TB0> INFO: invalid 5bit words: 0
[10:12:02.250] <TB0> INFO: invalid XOR eye diagram: 0
[10:12:02.250] <TB0> INFO: frame (failed synchr.): 0
[10:12:02.250] <TB0> INFO: idle data (no TBM trl): 0
[10:12:02.251] <TB0> INFO: no data (only TBM hdr): 0
[10:12:02.251] <TB0> INFO: TBM errors: 0
[10:12:02.251] <TB0> INFO: flawed TBM headers: 0
[10:12:02.251] <TB0> INFO: flawed TBM trailers: 0
[10:12:02.251] <TB0> INFO: event ID mismatches: 0
[10:12:02.251] <TB0> INFO: ROC errors: 0
[10:12:02.251] <TB0> INFO: missing ROC header(s): 0
[10:12:02.251] <TB0> INFO: misplaced readback start: 0
[10:12:02.251] <TB0> INFO: Pixel decoding errors: 0
[10:12:02.251] <TB0> INFO: pixel data incomplete: 0
[10:12:02.251] <TB0> INFO: pixel address: 0
[10:12:02.251] <TB0> INFO: pulse height fill bit: 0
[10:12:02.251] <TB0> INFO: buffer corruption: 0
[10:12:02.258] <TB0> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C15.dat
[10:12:02.258] <TB0> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr_C15.dat
[10:12:02.258] <TB0> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[10:12:02.258] <TB0> INFO: ######################################################################
[10:12:02.258] <TB0> INFO: PixTestReadback::doTest()
[10:12:02.258] <TB0> INFO: ######################################################################
[10:12:02.259] <TB0> INFO: ----------------------------------------------------------------------
[10:12:02.259] <TB0> INFO: PixTestReadback::CalibrateVd()
[10:12:02.259] <TB0> INFO: ----------------------------------------------------------------------
[10:12:12.256] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C0.dat
[10:12:12.257] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C1.dat
[10:12:12.257] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C2.dat
[10:12:12.257] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C3.dat
[10:12:12.257] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C4.dat
[10:12:12.257] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C5.dat
[10:12:12.257] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C6.dat
[10:12:12.257] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C7.dat
[10:12:12.257] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C8.dat
[10:12:12.257] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C9.dat
[10:12:12.258] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C10.dat
[10:12:12.258] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C11.dat
[10:12:12.258] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C12.dat
[10:12:12.258] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C13.dat
[10:12:12.258] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C14.dat
[10:12:12.258] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C15.dat
[10:12:12.286] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[10:12:12.286] <TB0> INFO: ----------------------------------------------------------------------
[10:12:12.286] <TB0> INFO: PixTestReadback::CalibrateVa()
[10:12:12.286] <TB0> INFO: ----------------------------------------------------------------------
[10:12:22.212] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C0.dat
[10:12:22.212] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C1.dat
[10:12:22.212] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C2.dat
[10:12:22.212] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C3.dat
[10:12:22.212] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C4.dat
[10:12:22.212] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C5.dat
[10:12:22.212] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C6.dat
[10:12:22.212] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C7.dat
[10:12:22.213] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C8.dat
[10:12:22.213] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C9.dat
[10:12:22.213] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C10.dat
[10:12:22.213] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C11.dat
[10:12:22.213] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C12.dat
[10:12:22.213] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C13.dat
[10:12:22.213] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C14.dat
[10:12:22.213] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C15.dat
[10:12:22.243] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[10:12:22.243] <TB0> INFO: ----------------------------------------------------------------------
[10:12:22.243] <TB0> INFO: PixTestReadback::readbackVbg()
[10:12:22.243] <TB0> INFO: ----------------------------------------------------------------------
[10:12:29.906] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[10:12:29.906] <TB0> INFO: ----------------------------------------------------------------------
[10:12:29.906] <TB0> INFO: PixTestReadback::getCalibratedVbg()
[10:12:29.906] <TB0> INFO: ----------------------------------------------------------------------
[10:12:29.906] <TB0> INFO: Vbg will be calibrated using Vd calibration
[10:12:29.906] <TB0> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 155.2calibrated Vbg = 1.16897 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 146.1calibrated Vbg = 1.16405 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 169.1calibrated Vbg = 1.17182 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 149.4calibrated Vbg = 1.15433 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 152.7calibrated Vbg = 1.16852 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 154.7calibrated Vbg = 1.17183 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 164.2calibrated Vbg = 1.16563 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 161.9calibrated Vbg = 1.17597 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 154.5calibrated Vbg = 1.1682 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 152.5calibrated Vbg = 1.15432 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 149.4calibrated Vbg = 1.15859 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 150calibrated Vbg = 1.15543 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 154.7calibrated Vbg = 1.16499 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 148.8calibrated Vbg = 1.17174 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 162calibrated Vbg = 1.17216 :::*/*/*/*/
[10:12:29.907] <TB0> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 160.8calibrated Vbg = 1.16863 :::*/*/*/*/
[10:12:29.910] <TB0> INFO: ----------------------------------------------------------------------
[10:12:29.910] <TB0> INFO: PixTestReadback::CalibrateIa()
[10:12:29.910] <TB0> INFO: ----------------------------------------------------------------------
[10:15:10.752] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C0.dat
[10:15:10.752] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C1.dat
[10:15:10.752] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C2.dat
[10:15:10.752] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C3.dat
[10:15:10.752] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C4.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C5.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C6.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C7.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C8.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C9.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C10.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C11.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C12.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C13.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C14.dat
[10:15:10.753] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//readbackCal_C15.dat
[10:15:10.783] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[10:15:10.785] <TB0> INFO: PixTestReadback::doTest() done
[10:15:10.785] <TB0> INFO: Decoding statistics:
[10:15:10.785] <TB0> INFO: General information:
[10:15:10.785] <TB0> INFO: 16bit words read: 1536
[10:15:10.785] <TB0> INFO: valid events total: 256
[10:15:10.785] <TB0> INFO: empty events: 256
[10:15:10.785] <TB0> INFO: valid events with pixels: 0
[10:15:10.785] <TB0> INFO: valid pixel hits: 0
[10:15:10.785] <TB0> INFO: Event errors: 0
[10:15:10.785] <TB0> INFO: start marker: 0
[10:15:10.785] <TB0> INFO: stop marker: 0
[10:15:10.785] <TB0> INFO: overflow: 0
[10:15:10.785] <TB0> INFO: invalid 5bit words: 0
[10:15:10.785] <TB0> INFO: invalid XOR eye diagram: 0
[10:15:10.785] <TB0> INFO: frame (failed synchr.): 0
[10:15:10.785] <TB0> INFO: idle data (no TBM trl): 0
[10:15:10.785] <TB0> INFO: no data (only TBM hdr): 0
[10:15:10.785] <TB0> INFO: TBM errors: 0
[10:15:10.786] <TB0> INFO: flawed TBM headers: 0
[10:15:10.786] <TB0> INFO: flawed TBM trailers: 0
[10:15:10.786] <TB0> INFO: event ID mismatches: 0
[10:15:10.786] <TB0> INFO: ROC errors: 0
[10:15:10.786] <TB0> INFO: missing ROC header(s): 0
[10:15:10.786] <TB0> INFO: misplaced readback start: 0
[10:15:10.786] <TB0> INFO: Pixel decoding errors: 0
[10:15:10.786] <TB0> INFO: pixel data incomplete: 0
[10:15:10.786] <TB0> INFO: pixel address: 0
[10:15:10.786] <TB0> INFO: pulse height fill bit: 0
[10:15:10.786] <TB0> INFO: buffer corruption: 0
[10:15:10.839] <TB0> INFO: ######################################################################
[10:15:10.839] <TB0> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[10:15:10.839] <TB0> INFO: ######################################################################
[10:15:10.841] <TB0> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[10:15:10.875] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[10:15:10.875] <TB0> INFO: run 1 of 1
[10:15:11.113] <TB0> INFO: Expecting 3120000 events.
[10:15:42.582] <TB0> INFO: 662390 events read in total (30877ms).
[10:15:54.649] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (247) != TBM ID (129)

[10:15:54.791] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 247 247 129 247 247 247 247 247

[10:15:54.791] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (248)

[10:15:54.791] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:15:54.791] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fb 8040 4601 4601 e022 c000

[10:15:54.791] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f5 80c0 4600 4600 e022 c000

[10:15:54.791] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f6 8000 4600 4600 e022 c000

[10:15:54.791] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4601 e022 c000

[10:15:54.791] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f8 80b1 4600 4600 e022 c000

[10:15:54.791] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f9 80c0 4600 4600 e022 c000

[10:15:54.791] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fa 8000 4600 4600 e022 c000

[10:16:12.727] <TB0> INFO: 1317890 events read in total (61022ms).
[10:16:24.727] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (131) != TBM ID (129)

[10:16:24.863] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 131 131 129 131 131 131 131 131

[10:16:24.864] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (132)

[10:16:24.864] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:16:24.864] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a087 8040 4600 4600 e022 c000

[10:16:24.864] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4601 e022 c000

[10:16:24.864] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a082 8000 4400 4400 e022 c000

[10:16:24.864] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4601 e022 c000

[10:16:24.864] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a084 80b1 4600 4600 e022 c000

[10:16:24.864] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a085 80c0 4600 4600 e022 c000

[10:16:24.864] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a086 8000 4600 4600 e022 c000

[10:16:42.581] <TB0> INFO: 1970540 events read in total (90876ms).
[10:16:54.531] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (237) != TBM ID (129)

[10:16:54.674] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 237 237 129 237 237 237 237 237

[10:16:54.674] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (238)

[10:16:54.675] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:16:54.675] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f1 80c0 4601 4601 e022 c000

[10:16:54.675] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0eb 8040 4601 4601 e022 c000

[10:16:54.675] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ec 80b1 4601 4601 e022 c000

[10:16:54.675] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4601 e022 c000

[10:16:54.675] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ee 8000 4600 4600 e022 c000

[10:16:54.675] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ef 8040 4402 4402 e022 c000

[10:16:54.675] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f0 80b1 4600 4600 e022 c000

[10:17:12.395] <TB0> INFO: 2619905 events read in total (120690ms).
[10:17:21.662] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (129)

[10:17:21.799] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 130 130 129 130 130 130 130 130

[10:17:21.799] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (131)

[10:17:21.799] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:17:21.799] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a086 8000 4600 4600 e022 c000

[10:17:21.799] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a080 80b1 4600 4600 e022 c000

[10:17:21.799] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4601 e022 c000

[10:17:21.799] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4601 e022 c000

[10:17:21.799] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a083 8040 4600 4601 e022 c000

[10:17:21.799] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a084 80b1 4600 4600 e022 c000

[10:17:21.799] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a085 80c0 4600 4600 e022 c000

[10:17:35.354] <TB0> INFO: 3120000 events read in total (143649ms).
[10:17:35.431] <TB0> INFO: Test took 144556ms.
[10:18:02.448] <TB0> INFO: PixTestBBMap::doTest() done, duration: 171 seconds
[10:18:02.448] <TB0> INFO: number of dead bumps (per ROC): 1 0 0 4 0 0 0 0 0 2 0 3 22 1 0 1
[10:18:02.448] <TB0> INFO: separation cut (per ROC): 109 107 114 109 106 109 111 105 100 107 106 116 107 105 113 113
[10:18:02.448] <TB0> INFO: Decoding statistics:
[10:18:02.448] <TB0> INFO: General information:
[10:18:02.448] <TB0> INFO: 16bit words read: 0
[10:18:02.448] <TB0> INFO: valid events total: 0
[10:18:02.448] <TB0> INFO: empty events: 0
[10:18:02.448] <TB0> INFO: valid events with pixels: 0
[10:18:02.448] <TB0> INFO: valid pixel hits: 0
[10:18:02.448] <TB0> INFO: Event errors: 0
[10:18:02.448] <TB0> INFO: start marker: 0
[10:18:02.448] <TB0> INFO: stop marker: 0
[10:18:02.448] <TB0> INFO: overflow: 0
[10:18:02.448] <TB0> INFO: invalid 5bit words: 0
[10:18:02.448] <TB0> INFO: invalid XOR eye diagram: 0
[10:18:02.448] <TB0> INFO: frame (failed synchr.): 0
[10:18:02.448] <TB0> INFO: idle data (no TBM trl): 0
[10:18:02.449] <TB0> INFO: no data (only TBM hdr): 0
[10:18:02.449] <TB0> INFO: TBM errors: 0
[10:18:02.449] <TB0> INFO: flawed TBM headers: 0
[10:18:02.449] <TB0> INFO: flawed TBM trailers: 0
[10:18:02.449] <TB0> INFO: event ID mismatches: 0
[10:18:02.449] <TB0> INFO: ROC errors: 0
[10:18:02.449] <TB0> INFO: missing ROC header(s): 0
[10:18:02.449] <TB0> INFO: misplaced readback start: 0
[10:18:02.449] <TB0> INFO: Pixel decoding errors: 0
[10:18:02.449] <TB0> INFO: pixel data incomplete: 0
[10:18:02.449] <TB0> INFO: pixel address: 0
[10:18:02.449] <TB0> INFO: pulse height fill bit: 0
[10:18:02.449] <TB0> INFO: buffer corruption: 0
[10:18:02.490] <TB0> INFO: ######################################################################
[10:18:02.490] <TB0> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[10:18:02.490] <TB0> INFO: ######################################################################
[10:18:02.490] <TB0> INFO: ----------------------------------------------------------------------
[10:18:02.490] <TB0> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[10:18:02.490] <TB0> INFO: ----------------------------------------------------------------------
[10:18:02.490] <TB0> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[10:18:02.505] <TB0> INFO: dacScan split into 1 runs with ntrig = 50
[10:18:02.505] <TB0> INFO: run 1 of 1
[10:18:02.788] <TB0> INFO: Expecting 36608000 events.
[10:18:27.188] <TB0> INFO: 682400 events read in total (23809ms).
[10:18:49.919] <TB0> INFO: 1349900 events read in total (46540ms).
[10:19:12.909] <TB0> INFO: 2017050 events read in total (69530ms).
[10:19:35.703] <TB0> INFO: 2684050 events read in total (92324ms).
[10:19:58.958] <TB0> INFO: 3351100 events read in total (115579ms).
[10:20:22.028] <TB0> INFO: 4017600 events read in total (138649ms).
[10:20:45.180] <TB0> INFO: 4681300 events read in total (161801ms).
[10:21:08.270] <TB0> INFO: 5345700 events read in total (184891ms).
[10:21:31.282] <TB0> INFO: 6010200 events read in total (207903ms).
[10:21:54.470] <TB0> INFO: 6676900 events read in total (231091ms).
[10:22:18.039] <TB0> INFO: 7341950 events read in total (254660ms).
[10:22:41.167] <TB0> INFO: 8006750 events read in total (277788ms).
[10:23:04.308] <TB0> INFO: 8672700 events read in total (300929ms).
[10:23:27.381] <TB0> INFO: 9336100 events read in total (324002ms).
[10:23:50.410] <TB0> INFO: 10000750 events read in total (347031ms).
[10:24:13.083] <TB0> INFO: 10663450 events read in total (369704ms).
[10:24:35.900] <TB0> INFO: 11326150 events read in total (392521ms).
[10:24:58.691] <TB0> INFO: 11989900 events read in total (415312ms).
[10:25:21.824] <TB0> INFO: 12650750 events read in total (438445ms).
[10:25:44.961] <TB0> INFO: 13311400 events read in total (461582ms).
[10:26:08.048] <TB0> INFO: 13972000 events read in total (484669ms).
[10:26:30.777] <TB0> INFO: 14633050 events read in total (507398ms).
[10:26:53.508] <TB0> INFO: 15294250 events read in total (530129ms).
[10:27:16.301] <TB0> INFO: 15954400 events read in total (552922ms).
[10:27:39.164] <TB0> INFO: 16614600 events read in total (575785ms).
[10:28:02.176] <TB0> INFO: 17274050 events read in total (598797ms).
[10:28:25.078] <TB0> INFO: 17932900 events read in total (621699ms).
[10:28:48.004] <TB0> INFO: 18592300 events read in total (644625ms).
[10:29:10.821] <TB0> INFO: 19250850 events read in total (667442ms).
[10:29:33.693] <TB0> INFO: 19908350 events read in total (690314ms).
[10:29:56.528] <TB0> INFO: 20564500 events read in total (713149ms).
[10:30:19.408] <TB0> INFO: 21222250 events read in total (736029ms).
[10:30:42.047] <TB0> INFO: 21877850 events read in total (758668ms).
[10:31:04.726] <TB0> INFO: 22534200 events read in total (781347ms).
[10:31:27.422] <TB0> INFO: 23188050 events read in total (804043ms).
[10:31:49.883] <TB0> INFO: 23842300 events read in total (826504ms).
[10:32:12.564] <TB0> INFO: 24496400 events read in total (849185ms).
[10:32:35.050] <TB0> INFO: 25151050 events read in total (871671ms).
[10:32:58.031] <TB0> INFO: 25805950 events read in total (894652ms).
[10:33:20.605] <TB0> INFO: 26458900 events read in total (917226ms).
[10:33:43.262] <TB0> INFO: 27112350 events read in total (939883ms).
[10:34:06.113] <TB0> INFO: 27768250 events read in total (962734ms).
[10:34:28.968] <TB0> INFO: 28422100 events read in total (985589ms).
[10:34:51.373] <TB0> INFO: 29076050 events read in total (1007994ms).
[10:35:13.780] <TB0> INFO: 29730200 events read in total (1030401ms).
[10:35:36.533] <TB0> INFO: 30383100 events read in total (1053154ms).
[10:35:59.198] <TB0> INFO: 31036950 events read in total (1075819ms).
[10:36:21.718] <TB0> INFO: 31689650 events read in total (1098339ms).
[10:36:44.232] <TB0> INFO: 32343900 events read in total (1120853ms).
[10:37:06.793] <TB0> INFO: 32996450 events read in total (1143414ms).
[10:37:29.674] <TB0> INFO: 33649350 events read in total (1166295ms).
[10:37:52.416] <TB0> INFO: 34303500 events read in total (1189037ms).
[10:38:14.980] <TB0> INFO: 34958950 events read in total (1211601ms).
[10:38:37.442] <TB0> INFO: 35613300 events read in total (1234063ms).
[10:39:00.094] <TB0> INFO: 36273650 events read in total (1256715ms).
[10:39:11.685] <TB0> INFO: 36608000 events read in total (1268306ms).
[10:39:11.766] <TB0> INFO: Test took 1269261ms.
[10:39:12.143] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:13.758] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:15.387] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:17.356] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:19.266] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:21.273] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:23.315] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:25.485] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:27.578] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:29.324] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:31.039] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:33.092] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:35.147] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:37.105] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:38.750] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:40.531] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[10:39:42.276] <TB0> INFO: PixTestScurves::scurves() done
[10:39:42.276] <TB0> INFO: Vcal mean: 116.64 119.50 113.59 118.53 114.46 121.97 116.78 125.26 109.29 120.54 109.46 109.75 115.98 116.19 112.36 121.82
[10:39:42.276] <TB0> INFO: Vcal RMS: 5.51 5.66 5.84 5.70 4.86 6.00 5.33 6.56 4.92 6.18 5.42 5.00 5.79 5.75 4.51 7.31
[10:39:42.276] <TB0> INFO: PixTestScurves::fullTest() done, duration: 1299 seconds
[10:39:42.276] <TB0> INFO: Decoding statistics:
[10:39:42.276] <TB0> INFO: General information:
[10:39:42.276] <TB0> INFO: 16bit words read: 0
[10:39:42.276] <TB0> INFO: valid events total: 0
[10:39:42.276] <TB0> INFO: empty events: 0
[10:39:42.276] <TB0> INFO: valid events with pixels: 0
[10:39:42.276] <TB0> INFO: valid pixel hits: 0
[10:39:42.276] <TB0> INFO: Event errors: 0
[10:39:42.276] <TB0> INFO: start marker: 0
[10:39:42.276] <TB0> INFO: stop marker: 0
[10:39:42.276] <TB0> INFO: overflow: 0
[10:39:42.276] <TB0> INFO: invalid 5bit words: 0
[10:39:42.276] <TB0> INFO: invalid XOR eye diagram: 0
[10:39:42.276] <TB0> INFO: frame (failed synchr.): 0
[10:39:42.276] <TB0> INFO: idle data (no TBM trl): 0
[10:39:42.276] <TB0> INFO: no data (only TBM hdr): 0
[10:39:42.276] <TB0> INFO: TBM errors: 0
[10:39:42.276] <TB0> INFO: flawed TBM headers: 0
[10:39:42.276] <TB0> INFO: flawed TBM trailers: 0
[10:39:42.276] <TB0> INFO: event ID mismatches: 0
[10:39:42.276] <TB0> INFO: ROC errors: 0
[10:39:42.276] <TB0> INFO: missing ROC header(s): 0
[10:39:42.276] <TB0> INFO: misplaced readback start: 0
[10:39:42.276] <TB0> INFO: Pixel decoding errors: 0
[10:39:42.276] <TB0> INFO: pixel data incomplete: 0
[10:39:42.276] <TB0> INFO: pixel address: 0
[10:39:42.276] <TB0> INFO: pulse height fill bit: 0
[10:39:42.276] <TB0> INFO: buffer corruption: 0
[10:39:42.369] <TB0> INFO: ######################################################################
[10:39:42.369] <TB0> INFO: PixTestTrim::doTest()
[10:39:42.369] <TB0> INFO: ######################################################################
[10:39:42.371] <TB0> INFO: ----------------------------------------------------------------------
[10:39:42.371] <TB0> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[10:39:42.371] <TB0> INFO: ----------------------------------------------------------------------
[10:39:42.412] <TB0> INFO: ---> VthrComp thr map (minimal VthrComp)
[10:39:42.412] <TB0> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[10:39:42.425] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[10:39:42.425] <TB0> INFO: run 1 of 1
[10:39:42.664] <TB0> INFO: Expecting 5025280 events.
[10:40:13.946] <TB0> INFO: 829016 events read in total (30679ms).
[10:40:44.078] <TB0> INFO: 1654624 events read in total (60811ms).
[10:41:13.835] <TB0> INFO: 2475120 events read in total (90569ms).
[10:41:43.962] <TB0> INFO: 3289048 events read in total (120695ms).
[10:42:14.090] <TB0> INFO: 4098544 events read in total (150824ms).
[10:42:44.159] <TB0> INFO: 4907248 events read in total (180892ms).
[10:42:48.737] <TB0> INFO: 5025280 events read in total (185470ms).
[10:42:48.785] <TB0> INFO: Test took 186359ms.
[10:43:05.735] <TB0> INFO: ROC 0 VthrComp = 132
[10:43:05.735] <TB0> INFO: ROC 1 VthrComp = 131
[10:43:05.735] <TB0> INFO: ROC 2 VthrComp = 131
[10:43:05.735] <TB0> INFO: ROC 3 VthrComp = 127
[10:43:05.735] <TB0> INFO: ROC 4 VthrComp = 124
[10:43:05.735] <TB0> INFO: ROC 5 VthrComp = 127
[10:43:05.735] <TB0> INFO: ROC 6 VthrComp = 134
[10:43:05.736] <TB0> INFO: ROC 7 VthrComp = 128
[10:43:05.736] <TB0> INFO: ROC 8 VthrComp = 113
[10:43:05.736] <TB0> INFO: ROC 9 VthrComp = 125
[10:43:05.736] <TB0> INFO: ROC 10 VthrComp = 122
[10:43:05.736] <TB0> INFO: ROC 11 VthrComp = 127
[10:43:05.736] <TB0> INFO: ROC 12 VthrComp = 122
[10:43:05.736] <TB0> INFO: ROC 13 VthrComp = 125
[10:43:05.736] <TB0> INFO: ROC 14 VthrComp = 129
[10:43:05.736] <TB0> INFO: ROC 15 VthrComp = 125
[10:43:05.997] <TB0> INFO: Expecting 41600 events.
[10:43:09.563] <TB0> INFO: 41600 events read in total (2974ms).
[10:43:09.564] <TB0> INFO: Test took 3826ms.
[10:43:09.576] <TB0> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[10:43:09.576] <TB0> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[10:43:09.589] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[10:43:09.589] <TB0> INFO: run 1 of 1
[10:43:09.868] <TB0> INFO: Expecting 5025280 events.
[10:43:36.825] <TB0> INFO: 588848 events read in total (26366ms).
[10:44:03.294] <TB0> INFO: 1177352 events read in total (52835ms).
[10:44:30.432] <TB0> INFO: 1765200 events read in total (79973ms).
[10:44:56.873] <TB0> INFO: 2351704 events read in total (106414ms).
[10:45:23.132] <TB0> INFO: 2936264 events read in total (132673ms).
[10:45:49.539] <TB0> INFO: 3518880 events read in total (159080ms).
[10:46:15.757] <TB0> INFO: 4101064 events read in total (185298ms).
[10:46:41.728] <TB0> INFO: 4683256 events read in total (211269ms).
[10:46:57.128] <TB0> INFO: 5025280 events read in total (226669ms).
[10:46:57.206] <TB0> INFO: Test took 227616ms.
[10:47:23.192] <TB0> INFO: roc 0 with ID = 0 has maximal Vcal 57.3145 for pixel 14/76 mean/min/max = 44.5919/31.7791/57.4047
[10:47:23.193] <TB0> INFO: roc 1 with ID = 1 has maximal Vcal 58.3024 for pixel 9/20 mean/min/max = 45.4053/32.4133/58.3974
[10:47:23.193] <TB0> INFO: roc 2 with ID = 2 has maximal Vcal 57.968 for pixel 0/62 mean/min/max = 44.9204/31.4586/58.3822
[10:47:23.194] <TB0> INFO: roc 3 with ID = 3 has maximal Vcal 59.3325 for pixel 7/71 mean/min/max = 45.2095/30.9994/59.4195
[10:47:23.194] <TB0> INFO: roc 4 with ID = 4 has maximal Vcal 56.7627 for pixel 37/7 mean/min/max = 44.5596/31.9535/57.1656
[10:47:23.195] <TB0> INFO: roc 5 with ID = 5 has maximal Vcal 60.059 for pixel 11/9 mean/min/max = 45.7358/31.0787/60.3929
[10:47:23.195] <TB0> INFO: roc 6 with ID = 6 has maximal Vcal 58.6911 for pixel 6/74 mean/min/max = 46.2526/33.7786/58.7265
[10:47:23.196] <TB0> INFO: roc 7 with ID = 7 has maximal Vcal 62.334 for pixel 1/23 mean/min/max = 47.3631/32.1161/62.6101
[10:47:23.196] <TB0> INFO: roc 8 with ID = 8 has maximal Vcal 61.5317 for pixel 11/0 mean/min/max = 46.9549/32.1634/61.7464
[10:47:23.196] <TB0> INFO: roc 9 with ID = 9 has maximal Vcal 61.3834 for pixel 29/75 mean/min/max = 46.3294/31.254/61.4047
[10:47:23.197] <TB0> INFO: roc 10 with ID = 10 has maximal Vcal 58.0016 for pixel 13/4 mean/min/max = 44.7272/31.4458/58.0086
[10:47:23.197] <TB0> INFO: roc 11 with ID = 11 has maximal Vcal 56.0246 for pixel 3/60 mean/min/max = 43.6088/30.9599/56.2577
[10:47:23.198] <TB0> INFO: roc 12 with ID = 12 has maximal Vcal 59.8325 for pixel 20/4 mean/min/max = 46.038/31.9808/60.0951
[10:47:23.198] <TB0> INFO: roc 13 with ID = 13 has maximal Vcal 59.9143 for pixel 1/0 mean/min/max = 45.3448/30.7155/59.9742
[10:47:23.198] <TB0> INFO: roc 14 with ID = 14 has maximal Vcal 57.2037 for pixel 42/11 mean/min/max = 44.7905/32.323/57.258
[10:47:23.199] <TB0> INFO: roc 15 with ID = 15 has maximal Vcal 66.1819 for pixel 0/12 mean/min/max = 48.214/30.2429/66.1852
[10:47:23.199] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:47:23.289] <TB0> INFO: Expecting 411648 events.
[10:47:32.734] <TB0> INFO: 411648 events read in total (8854ms).
[10:47:32.744] <TB0> INFO: Expecting 411648 events.
[10:47:41.941] <TB0> INFO: 411648 events read in total (8794ms).
[10:47:41.952] <TB0> INFO: Expecting 411648 events.
[10:47:51.264] <TB0> INFO: 411648 events read in total (8909ms).
[10:47:51.281] <TB0> INFO: Expecting 411648 events.
[10:48:00.811] <TB0> INFO: 411648 events read in total (9127ms).
[10:48:00.832] <TB0> INFO: Expecting 411648 events.
[10:48:10.454] <TB0> INFO: 411648 events read in total (9219ms).
[10:48:10.479] <TB0> INFO: Expecting 411648 events.
[10:48:20.026] <TB0> INFO: 411648 events read in total (9144ms).
[10:48:20.049] <TB0> INFO: Expecting 411648 events.
[10:48:29.720] <TB0> INFO: 411648 events read in total (9268ms).
[10:48:29.748] <TB0> INFO: Expecting 411648 events.
[10:48:39.374] <TB0> INFO: 411648 events read in total (9223ms).
[10:48:39.404] <TB0> INFO: Expecting 411648 events.
[10:48:48.934] <TB0> INFO: 411648 events read in total (9126ms).
[10:48:48.965] <TB0> INFO: Expecting 411648 events.
[10:48:58.554] <TB0> INFO: 411648 events read in total (9186ms).
[10:48:58.591] <TB0> INFO: Expecting 411648 events.
[10:49:08.199] <TB0> INFO: 411648 events read in total (9205ms).
[10:49:08.238] <TB0> INFO: Expecting 411648 events.
[10:49:17.864] <TB0> INFO: 411648 events read in total (9223ms).
[10:49:17.905] <TB0> INFO: Expecting 411648 events.
[10:49:27.450] <TB0> INFO: 411648 events read in total (9142ms).
[10:49:27.505] <TB0> INFO: Expecting 411648 events.
[10:49:36.999] <TB0> INFO: 411648 events read in total (9091ms).
[10:49:37.045] <TB0> INFO: Expecting 411648 events.
[10:49:46.588] <TB0> INFO: 411648 events read in total (9140ms).
[10:49:46.642] <TB0> INFO: Expecting 411648 events.
[10:49:56.186] <TB0> INFO: 411648 events read in total (9141ms).
[10:49:56.238] <TB0> INFO: Test took 153039ms.
[10:49:57.054] <TB0> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[10:49:57.068] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[10:49:57.068] <TB0> INFO: run 1 of 1
[10:49:57.343] <TB0> INFO: Expecting 5025280 events.
[10:50:23.999] <TB0> INFO: 584448 events read in total (26064ms).
[10:50:49.727] <TB0> INFO: 1167368 events read in total (51793ms).
[10:51:15.583] <TB0> INFO: 1750120 events read in total (77648ms).
[10:51:41.628] <TB0> INFO: 2333088 events read in total (103693ms).
[10:52:07.899] <TB0> INFO: 2915520 events read in total (129964ms).
[10:52:34.341] <TB0> INFO: 3498080 events read in total (156406ms).
[10:53:00.513] <TB0> INFO: 4078624 events read in total (182578ms).
[10:53:26.482] <TB0> INFO: 4658648 events read in total (208547ms).
[10:53:43.289] <TB0> INFO: 5025280 events read in total (225354ms).
[10:53:43.461] <TB0> INFO: Test took 226394ms.
[10:54:09.152] <TB0> INFO: ---> TrimStepCorr4 extremal thresholds: 2.353704 .. 142.906266
[10:54:09.416] <TB0> INFO: Expecting 208000 events.
[10:54:19.068] <TB0> INFO: 208000 events read in total (9060ms).
[10:54:19.070] <TB0> INFO: Test took 9917ms.
[10:54:19.130] <TB0> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 2 .. 152 (-1/-1) hits flags = 528 (plus default)
[10:54:19.145] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[10:54:19.145] <TB0> INFO: run 1 of 1
[10:54:19.469] <TB0> INFO: Expecting 5025280 events.
[10:54:46.034] <TB0> INFO: 583032 events read in total (25973ms).
[10:55:11.387] <TB0> INFO: 1166768 events read in total (51327ms).
[10:55:37.241] <TB0> INFO: 1750784 events read in total (77180ms).
[10:56:03.023] <TB0> INFO: 2334760 events read in total (102963ms).
[10:56:29.128] <TB0> INFO: 2918008 events read in total (129067ms).
[10:56:54.681] <TB0> INFO: 3500400 events read in total (154620ms).
[10:57:20.738] <TB0> INFO: 4082456 events read in total (180677ms).
[10:57:46.104] <TB0> INFO: 4664688 events read in total (206043ms).
[10:58:02.113] <TB0> INFO: 5025280 events read in total (222052ms).
[10:58:02.257] <TB0> INFO: Test took 223112ms.
[10:58:25.076] <TB0> INFO: ---> TrimStepCorr2 extremal thresholds: 26.963219 .. 45.793120
[10:58:25.314] <TB0> INFO: Expecting 208000 events.
[10:58:35.477] <TB0> INFO: 208000 events read in total (9572ms).
[10:58:35.478] <TB0> INFO: Test took 10400ms.
[10:58:35.546] <TB0> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 55 (-1/-1) hits flags = 528 (plus default)
[10:58:35.561] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[10:58:35.561] <TB0> INFO: run 1 of 1
[10:58:35.839] <TB0> INFO: Expecting 1331200 events.
[10:59:04.699] <TB0> INFO: 661824 events read in total (28268ms).
[10:59:32.808] <TB0> INFO: 1321952 events read in total (56377ms).
[10:59:33.646] <TB0> INFO: 1331200 events read in total (57216ms).
[10:59:33.679] <TB0> INFO: Test took 58119ms.
[10:59:46.402] <TB0> INFO: ---> TrimStepCorr1a extremal thresholds: 25.854932 .. 46.158742
[10:59:46.640] <TB0> INFO: Expecting 208000 events.
[10:59:56.535] <TB0> INFO: 208000 events read in total (9303ms).
[10:59:56.537] <TB0> INFO: Test took 10134ms.
[10:59:56.600] <TB0> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 15 .. 56 (-1/-1) hits flags = 528 (plus default)
[10:59:56.614] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[10:59:56.614] <TB0> INFO: run 1 of 1
[10:59:56.921] <TB0> INFO: Expecting 1397760 events.
[11:00:26.551] <TB0> INFO: 662856 events read in total (29038ms).
[11:00:54.263] <TB0> INFO: 1324376 events read in total (56750ms).
[11:00:57.837] <TB0> INFO: 1397760 events read in total (60325ms).
[11:00:57.869] <TB0> INFO: Test took 61254ms.
[11:01:10.627] <TB0> INFO: ---> TrimStepCorr1b extremal thresholds: 22.500354 .. 45.026206
[11:01:10.880] <TB0> INFO: Expecting 208000 events.
[11:01:20.734] <TB0> INFO: 208000 events read in total (9263ms).
[11:01:20.735] <TB0> INFO: Test took 10106ms.
[11:01:20.818] <TB0> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 12 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:01:20.832] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:01:20.832] <TB0> INFO: run 1 of 1
[11:01:21.111] <TB0> INFO: Expecting 1464320 events.
[11:01:50.392] <TB0> INFO: 678456 events read in total (28689ms).
[11:02:18.163] <TB0> INFO: 1356832 events read in total (56460ms).
[11:02:23.115] <TB0> INFO: 1464320 events read in total (61412ms).
[11:02:23.148] <TB0> INFO: Test took 62317ms.
[11:02:35.643] <TB0> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[11:02:35.643] <TB0> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:02:35.656] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:02:35.657] <TB0> INFO: run 1 of 1
[11:02:35.981] <TB0> INFO: Expecting 1364480 events.
[11:03:04.653] <TB0> INFO: 666968 events read in total (28080ms).
[11:03:32.477] <TB0> INFO: 1333280 events read in total (55905ms).
[11:03:34.290] <TB0> INFO: 1364480 events read in total (57717ms).
[11:03:34.320] <TB0> INFO: Test took 58663ms.
[11:03:48.454] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C0.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C1.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C2.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C3.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C4.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C5.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C6.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C7.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C8.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C9.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C10.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C11.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C12.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C13.dat
[11:03:48.455] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C14.dat
[11:03:48.456] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C15.dat
[11:03:48.456] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C0.dat
[11:03:48.461] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C1.dat
[11:03:48.466] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C2.dat
[11:03:48.471] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C3.dat
[11:03:48.475] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C4.dat
[11:03:48.481] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C5.dat
[11:03:48.487] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C6.dat
[11:03:48.491] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C7.dat
[11:03:48.496] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C8.dat
[11:03:48.501] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C9.dat
[11:03:48.505] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C10.dat
[11:03:48.511] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C11.dat
[11:03:48.515] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C12.dat
[11:03:48.520] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C13.dat
[11:03:48.526] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C14.dat
[11:03:48.530] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//trimParameters35_C15.dat
[11:03:48.535] <TB0> INFO: PixTestTrim::trimTest() done
[11:03:48.535] <TB0> INFO: vtrim: 127 121 141 128 131 124 140 137 119 141 113 136 126 116 137 154
[11:03:48.535] <TB0> INFO: vthrcomp: 132 131 131 127 124 127 134 128 113 125 122 127 122 125 129 125
[11:03:48.535] <TB0> INFO: vcal mean: 34.92 34.96 34.97 34.93 34.96 34.95 34.99 35.01 34.96 35.03 34.94 34.93 34.97 34.95 34.97 35.02
[11:03:48.535] <TB0> INFO: vcal RMS: 0.98 1.01 1.01 1.11 1.00 1.08 0.97 1.18 0.99 1.20 1.17 1.00 1.09 1.15 0.96 1.08
[11:03:48.535] <TB0> INFO: bits mean: 9.71 9.46 9.86 9.84 9.46 9.86 9.24 9.21 9.12 9.90 9.59 10.18 9.78 9.61 9.83 9.24
[11:03:48.535] <TB0> INFO: bits RMS: 2.71 2.70 2.60 2.68 2.77 2.67 2.49 2.74 2.79 2.57 2.76 2.63 2.50 2.83 2.53 2.82
[11:03:48.542] <TB0> INFO: ----------------------------------------------------------------------
[11:03:48.543] <TB0> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[11:03:48.543] <TB0> INFO: ----------------------------------------------------------------------
[11:03:48.546] <TB0> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[11:03:48.559] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[11:03:48.559] <TB0> INFO: run 1 of 1
[11:03:48.797] <TB0> INFO: Expecting 4160000 events.
[11:04:21.375] <TB0> INFO: 746505 events read in total (31987ms).
[11:04:52.695] <TB0> INFO: 1487320 events read in total (63307ms).
[11:05:24.337] <TB0> INFO: 2222760 events read in total (94949ms).
[11:05:55.774] <TB0> INFO: 2951690 events read in total (126386ms).
[11:06:26.977] <TB0> INFO: 3677930 events read in total (157589ms).
[11:06:47.832] <TB0> INFO: 4160000 events read in total (178444ms).
[11:06:47.909] <TB0> INFO: Test took 179349ms.
[11:07:15.842] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 200 (-1/-1) hits flags = 528 (plus default)
[11:07:15.855] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[11:07:15.855] <TB0> INFO: run 1 of 1
[11:07:16.133] <TB0> INFO: Expecting 4180800 events.
[11:07:48.314] <TB0> INFO: 721665 events read in total (31590ms).
[11:08:19.628] <TB0> INFO: 1437995 events read in total (62904ms).
[11:08:50.705] <TB0> INFO: 2149055 events read in total (93981ms).
[11:09:21.765] <TB0> INFO: 2854220 events read in total (125041ms).
[11:09:52.727] <TB0> INFO: 3556965 events read in total (156003ms).
[11:10:20.404] <TB0> INFO: 4180800 events read in total (183680ms).
[11:10:20.518] <TB0> INFO: Test took 184664ms.
[11:10:48.670] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 188 (-1/-1) hits flags = 528 (plus default)
[11:10:48.684] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[11:10:48.684] <TB0> INFO: run 1 of 1
[11:10:48.935] <TB0> INFO: Expecting 3931200 events.
[11:11:20.930] <TB0> INFO: 738335 events read in total (31404ms).
[11:11:52.473] <TB0> INFO: 1470240 events read in total (62947ms).
[11:12:24.108] <TB0> INFO: 2195985 events read in total (94582ms).
[11:12:55.212] <TB0> INFO: 2914700 events read in total (125686ms).
[11:13:26.541] <TB0> INFO: 3631705 events read in total (157015ms).
[11:13:39.789] <TB0> INFO: 3931200 events read in total (170263ms).
[11:13:39.889] <TB0> INFO: Test took 171205ms.
[11:14:04.997] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 187 (-1/-1) hits flags = 528 (plus default)
[11:14:05.012] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[11:14:05.012] <TB0> INFO: run 1 of 1
[11:14:05.251] <TB0> INFO: Expecting 3910400 events.
[11:14:37.363] <TB0> INFO: 739825 events read in total (31521ms).
[11:15:08.726] <TB0> INFO: 1473105 events read in total (62884ms).
[11:15:39.879] <TB0> INFO: 2200055 events read in total (94037ms).
[11:16:11.031] <TB0> INFO: 2920020 events read in total (125189ms).
[11:16:42.363] <TB0> INFO: 3638315 events read in total (156521ms).
[11:16:54.429] <TB0> INFO: 3910400 events read in total (168587ms).
[11:16:54.511] <TB0> INFO: Test took 169498ms.
[11:17:17.349] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 188 (-1/-1) hits flags = 528 (plus default)
[11:17:17.363] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[11:17:17.363] <TB0> INFO: run 1 of 1
[11:17:17.625] <TB0> INFO: Expecting 3931200 events.
[11:17:50.783] <TB0> INFO: 738170 events read in total (32567ms).
[11:18:22.124] <TB0> INFO: 1470030 events read in total (63908ms).
[11:18:54.299] <TB0> INFO: 2195580 events read in total (96084ms).
[11:19:25.388] <TB0> INFO: 2914130 events read in total (127172ms).
[11:19:56.465] <TB0> INFO: 3631065 events read in total (158249ms).
[11:20:09.719] <TB0> INFO: 3931200 events read in total (171503ms).
[11:20:09.843] <TB0> INFO: Test took 172480ms.
[11:20:38.441] <TB0> INFO: PixTestTrim::trimBitTest() done
[11:20:38.443] <TB0> INFO: PixTestTrim::doTest() done, duration: 2456 seconds
[11:20:38.443] <TB0> INFO: Decoding statistics:
[11:20:38.443] <TB0> INFO: General information:
[11:20:38.443] <TB0> INFO: 16bit words read: 0
[11:20:38.443] <TB0> INFO: valid events total: 0
[11:20:38.443] <TB0> INFO: empty events: 0
[11:20:38.443] <TB0> INFO: valid events with pixels: 0
[11:20:38.443] <TB0> INFO: valid pixel hits: 0
[11:20:38.443] <TB0> INFO: Event errors: 0
[11:20:38.443] <TB0> INFO: start marker: 0
[11:20:38.443] <TB0> INFO: stop marker: 0
[11:20:38.443] <TB0> INFO: overflow: 0
[11:20:38.443] <TB0> INFO: invalid 5bit words: 0
[11:20:38.443] <TB0> INFO: invalid XOR eye diagram: 0
[11:20:38.443] <TB0> INFO: frame (failed synchr.): 0
[11:20:38.443] <TB0> INFO: idle data (no TBM trl): 0
[11:20:38.443] <TB0> INFO: no data (only TBM hdr): 0
[11:20:38.443] <TB0> INFO: TBM errors: 0
[11:20:38.443] <TB0> INFO: flawed TBM headers: 0
[11:20:38.443] <TB0> INFO: flawed TBM trailers: 0
[11:20:38.443] <TB0> INFO: event ID mismatches: 0
[11:20:38.443] <TB0> INFO: ROC errors: 0
[11:20:38.443] <TB0> INFO: missing ROC header(s): 0
[11:20:38.443] <TB0> INFO: misplaced readback start: 0
[11:20:38.443] <TB0> INFO: Pixel decoding errors: 0
[11:20:38.443] <TB0> INFO: pixel data incomplete: 0
[11:20:38.443] <TB0> INFO: pixel address: 0
[11:20:38.443] <TB0> INFO: pulse height fill bit: 0
[11:20:38.443] <TB0> INFO: buffer corruption: 0
[11:20:39.080] <TB0> INFO: ######################################################################
[11:20:39.080] <TB0> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[11:20:39.080] <TB0> INFO: ######################################################################
[11:20:39.355] <TB0> INFO: Expecting 41600 events.
[11:20:42.908] <TB0> INFO: 41600 events read in total (2961ms).
[11:20:42.909] <TB0> INFO: Test took 3828ms.
[11:20:43.350] <TB0> INFO: Expecting 41600 events.
[11:20:46.904] <TB0> INFO: 41600 events read in total (2962ms).
[11:20:46.905] <TB0> INFO: Test took 3791ms.
[11:20:46.916] <TB0> INFO: Max pixel from chip 0 is [6 ,6] phvalue 40
[11:20:46.916] <TB0> INFO: Max pixel from chip 1 is [36 ,71] phvalue 66
[11:20:46.916] <TB0> INFO: Max pixel from chip 2 is [4 ,14] phvalue 124
[11:20:46.916] <TB0> INFO: Max pixel from chip 3 is [6 ,14] phvalue 64
[11:20:46.916] <TB0> INFO: Max pixel from chip 4 is [6 ,29] phvalue 150
[11:20:46.917] <TB0> INFO: Max pixel from chip 5 is [4 ,12] phvalue 26
[11:20:46.917] <TB0> INFO: Max pixel from chip 6 is [4 ,47] phvalue 112
[11:20:46.917] <TB0> INFO: Max pixel from chip 7 is [3 ,5] phvalue 96
[11:20:46.917] <TB0> INFO: Max pixel from chip 8 is [15 ,26] phvalue 123
[11:20:46.917] <TB0> INFO: Max pixel from chip 9 is [6 ,5] phvalue 127
[11:20:46.917] <TB0> INFO: Max pixel from chip 10 is [5 ,35] phvalue 48
[11:20:46.918] <TB0> INFO: Max pixel from chip 11 is [9 ,6] phvalue 158
[11:20:46.918] <TB0> INFO: Max pixel from chip 12 is [3 ,15] phvalue 79
[11:20:46.918] <TB0> INFO: Max pixel from chip 13 is [8 ,43] phvalue 164
[11:20:46.918] <TB0> INFO: Max pixel from chip 14 is [4 ,15] phvalue 118
[11:20:46.918] <TB0> INFO: Max pixel from chip 15 is [15 ,7] phvalue 125
[11:20:47.199] <TB0> INFO: Expecting 41600 events.
[11:20:50.713] <TB0> INFO: 41600 events read in total (2923ms).
[11:20:50.714] <TB0> INFO: Test took 3781ms.
[11:20:50.726] <TB0> INFO: Min pixel from chip 0 is [22 ,27] phvalue 232
[11:20:50.726] <TB0> INFO: Min pixel from chip 1 is [21 ,31] phvalue 234
[11:20:50.727] <TB0> INFO: Min pixel from chip 2 is [3 ,5] phvalue 255
[11:20:50.727] <TB0> INFO: Min pixel from chip 3 is [5 ,49] phvalue 241
[11:20:50.727] <TB0> INFO: Min pixel from chip 4 is [39 ,29] phvalue 253
[11:20:50.727] <TB0> INFO: Min pixel from chip 5 is [13 ,28] phvalue 227
[11:20:50.728] <TB0> INFO: Min pixel from chip 6 is [47 ,55] phvalue 251
[11:20:50.728] <TB0> INFO: Min pixel from chip 7 is [3 ,5] phvalue 255
[11:20:50.728] <TB0> INFO: Min pixel from chip 8 is [21 ,55] phvalue 240
[11:20:50.728] <TB0> INFO: Min pixel from chip 9 is [3 ,5] phvalue 255
[11:20:50.728] <TB0> INFO: Min pixel from chip 10 is [17 ,7] phvalue 228
[11:20:50.728] <TB0> INFO: Min pixel from chip 11 is [3 ,5] phvalue 255
[11:20:50.729] <TB0> INFO: Min pixel from chip 12 is [3 ,5] phvalue 255
[11:20:50.729] <TB0> INFO: Min pixel from chip 13 is [3 ,5] phvalue 255
[11:20:50.729] <TB0> INFO: Min pixel from chip 14 is [31 ,30] phvalue 252
[11:20:50.729] <TB0> INFO: Min pixel from chip 15 is [3 ,5] phvalue 255
[11:20:51.008] <TB0> INFO: Expecting 2560 events.
[11:20:51.892] <TB0> INFO: 2560 events read in total (292ms).
[11:20:51.893] <TB0> INFO: Test took 1162ms.
[11:20:52.201] <TB0> INFO: Expecting 2560 events.
[11:20:53.085] <TB0> INFO: 2560 events read in total (293ms).
[11:20:53.085] <TB0> INFO: Test took 1192ms.
[11:20:53.393] <TB0> INFO: Expecting 2560 events.
[11:20:54.280] <TB0> INFO: 2560 events read in total (295ms).
[11:20:54.281] <TB0> INFO: Test took 1195ms.
[11:20:54.588] <TB0> INFO: Expecting 2560 events.
[11:20:55.477] <TB0> INFO: 2560 events read in total (297ms).
[11:20:55.477] <TB0> INFO: Test took 1195ms.
[11:20:55.785] <TB0> INFO: Expecting 2560 events.
[11:20:56.668] <TB0> INFO: 2560 events read in total (292ms).
[11:20:56.668] <TB0> INFO: Test took 1190ms.
[11:20:56.975] <TB0> INFO: Expecting 2560 events.
[11:20:57.854] <TB0> INFO: 2560 events read in total (287ms).
[11:20:57.855] <TB0> INFO: Test took 1183ms.
[11:20:58.162] <TB0> INFO: Expecting 2560 events.
[11:20:59.044] <TB0> INFO: 2560 events read in total (290ms).
[11:20:59.044] <TB0> INFO: Test took 1187ms.
[11:20:59.352] <TB0> INFO: Expecting 2560 events.
[11:21:00.235] <TB0> INFO: 2560 events read in total (291ms).
[11:21:00.235] <TB0> INFO: Test took 1190ms.
[11:21:00.543] <TB0> INFO: Expecting 2560 events.
[11:21:01.421] <TB0> INFO: 2560 events read in total (286ms).
[11:21:01.421] <TB0> INFO: Test took 1183ms.
[11:21:01.729] <TB0> INFO: Expecting 2560 events.
[11:21:02.610] <TB0> INFO: 2560 events read in total (289ms).
[11:21:02.610] <TB0> INFO: Test took 1188ms.
[11:21:02.918] <TB0> INFO: Expecting 2560 events.
[11:21:03.800] <TB0> INFO: 2560 events read in total (291ms).
[11:21:03.800] <TB0> INFO: Test took 1190ms.
[11:21:04.108] <TB0> INFO: Expecting 2560 events.
[11:21:04.987] <TB0> INFO: 2560 events read in total (287ms).
[11:21:04.987] <TB0> INFO: Test took 1187ms.
[11:21:05.295] <TB0> INFO: Expecting 2560 events.
[11:21:06.184] <TB0> INFO: 2560 events read in total (297ms).
[11:21:06.184] <TB0> INFO: Test took 1196ms.
[11:21:06.492] <TB0> INFO: Expecting 2560 events.
[11:21:07.376] <TB0> INFO: 2560 events read in total (293ms).
[11:21:07.376] <TB0> INFO: Test took 1191ms.
[11:21:07.684] <TB0> INFO: Expecting 2560 events.
[11:21:08.568] <TB0> INFO: 2560 events read in total (292ms).
[11:21:08.569] <TB0> INFO: Test took 1192ms.
[11:21:08.876] <TB0> INFO: Expecting 2560 events.
[11:21:09.763] <TB0> INFO: 2560 events read in total (295ms).
[11:21:09.763] <TB0> INFO: Test took 1194ms.
[11:21:09.766] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:21:10.071] <TB0> INFO: Expecting 655360 events.
[11:21:24.625] <TB0> INFO: 655360 events read in total (13962ms).
[11:21:24.641] <TB0> INFO: Expecting 655360 events.
[11:21:39.059] <TB0> INFO: 655360 events read in total (14014ms).
[11:21:39.080] <TB0> INFO: Expecting 655360 events.
[11:21:54.123] <TB0> INFO: 655360 events read in total (14640ms).
[11:21:54.145] <TB0> INFO: Expecting 655360 events.
[11:22:08.561] <TB0> INFO: 655360 events read in total (14013ms).
[11:22:08.588] <TB0> INFO: Expecting 655360 events.
[11:22:22.802] <TB0> INFO: 655360 events read in total (13811ms).
[11:22:22.831] <TB0> INFO: Expecting 655360 events.
[11:22:37.048] <TB0> INFO: 655360 events read in total (13814ms).
[11:22:37.082] <TB0> INFO: Expecting 655360 events.
[11:22:51.773] <TB0> INFO: 655360 events read in total (14288ms).
[11:22:51.812] <TB0> INFO: Expecting 655360 events.
[11:23:06.608] <TB0> INFO: 655360 events read in total (14393ms).
[11:23:06.693] <TB0> INFO: Expecting 655360 events.
[11:23:21.309] <TB0> INFO: 655360 events read in total (14213ms).
[11:23:21.373] <TB0> INFO: Expecting 655360 events.
[11:23:36.088] <TB0> INFO: 655360 events read in total (14312ms).
[11:23:36.202] <TB0> INFO: Expecting 655360 events.
[11:23:50.846] <TB0> INFO: 655360 events read in total (14241ms).
[11:23:50.916] <TB0> INFO: Expecting 655360 events.
[11:24:05.499] <TB0> INFO: 655360 events read in total (14180ms).
[11:24:05.576] <TB0> INFO: Expecting 655360 events.
[11:24:20.210] <TB0> INFO: 655360 events read in total (14231ms).
[11:24:20.289] <TB0> INFO: Expecting 655360 events.
[11:24:34.926] <TB0> INFO: 655360 events read in total (14234ms).
[11:24:35.050] <TB0> INFO: Expecting 655360 events.
[11:24:49.717] <TB0> INFO: 655360 events read in total (14264ms).
[11:24:49.835] <TB0> INFO: Expecting 655360 events.
[11:25:04.490] <TB0> INFO: 655360 events read in total (14252ms).
[11:25:04.631] <TB0> INFO: Test took 234865ms.
[11:25:04.755] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:25:04.003] <TB0> INFO: Expecting 655360 events.
[11:25:19.805] <TB0> INFO: 655360 events read in total (14210ms).
[11:25:19.821] <TB0> INFO: Expecting 655360 events.
[11:25:34.220] <TB0> INFO: 655360 events read in total (13996ms).
[11:25:34.237] <TB0> INFO: Expecting 655360 events.
[11:25:48.776] <TB0> INFO: 655360 events read in total (14136ms).
[11:25:48.796] <TB0> INFO: Expecting 655360 events.
[11:26:03.262] <TB0> INFO: 655360 events read in total (14063ms).
[11:26:03.295] <TB0> INFO: Expecting 655360 events.
[11:26:17.644] <TB0> INFO: 655360 events read in total (13945ms).
[11:26:17.679] <TB0> INFO: Expecting 655360 events.
[11:26:32.192] <TB0> INFO: 655360 events read in total (14110ms).
[11:26:32.227] <TB0> INFO: Expecting 655360 events.
[11:26:46.592] <TB0> INFO: 655360 events read in total (13962ms).
[11:26:46.638] <TB0> INFO: Expecting 655360 events.
[11:27:01.244] <TB0> INFO: 655360 events read in total (14203ms).
[11:27:01.346] <TB0> INFO: Expecting 655360 events.
[11:27:15.945] <TB0> INFO: 655360 events read in total (14196ms).
[11:27:15.001] <TB0> INFO: Expecting 655360 events.
[11:27:30.648] <TB0> INFO: 655360 events read in total (14244ms).
[11:27:30.740] <TB0> INFO: Expecting 655360 events.
[11:27:45.409] <TB0> INFO: 655360 events read in total (14266ms).
[11:27:45.532] <TB0> INFO: Expecting 655360 events.
[11:28:00.121] <TB0> INFO: 655360 events read in total (14186ms).
[11:28:00.202] <TB0> INFO: Expecting 655360 events.
[11:28:14.667] <TB0> INFO: 655360 events read in total (14061ms).
[11:28:14.784] <TB0> INFO: Expecting 655360 events.
[11:28:29.302] <TB0> INFO: 655360 events read in total (14114ms).
[11:28:29.428] <TB0> INFO: Expecting 655360 events.
[11:28:44.163] <TB0> INFO: 655360 events read in total (14328ms).
[11:28:44.283] <TB0> INFO: Expecting 655360 events.
[11:28:59.197] <TB0> INFO: 655360 events read in total (14509ms).
[11:28:59.319] <TB0> INFO: Test took 234564ms.
[11:28:59.495] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.501] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.507] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.513] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[11:28:59.518] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.524] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.530] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.538] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.544] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.549] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.556] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.561] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[11:28:59.568] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.576] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.584] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[11:28:59.591] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.600] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.609] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[11:28:59.619] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[11:28:59.628] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[11:28:59.636] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[11:28:59.644] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.652] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[11:28:59.686] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C0.dat
[11:28:59.687] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C1.dat
[11:28:59.687] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C2.dat
[11:28:59.687] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C3.dat
[11:28:59.687] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C4.dat
[11:28:59.687] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C5.dat
[11:28:59.687] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C6.dat
[11:28:59.687] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C7.dat
[11:28:59.687] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C8.dat
[11:28:59.687] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C9.dat
[11:28:59.688] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C10.dat
[11:28:59.688] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C11.dat
[11:28:59.688] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C12.dat
[11:28:59.688] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C13.dat
[11:28:59.688] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C14.dat
[11:28:59.688] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//dacParameters35_C15.dat
[11:28:59.931] <TB0> INFO: Expecting 41600 events.
[11:29:03.088] <TB0> INFO: 41600 events read in total (2566ms).
[11:29:03.088] <TB0> INFO: Test took 3396ms.
[11:29:03.539] <TB0> INFO: Expecting 41600 events.
[11:29:06.592] <TB0> INFO: 41600 events read in total (2461ms).
[11:29:06.594] <TB0> INFO: Test took 3294ms.
[11:29:07.055] <TB0> INFO: Expecting 41600 events.
[11:29:10.267] <TB0> INFO: 41600 events read in total (2621ms).
[11:29:10.268] <TB0> INFO: Test took 3457ms.
[11:29:10.485] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:10.575] <TB0> INFO: Expecting 2560 events.
[11:29:11.467] <TB0> INFO: 2560 events read in total (300ms).
[11:29:11.467] <TB0> INFO: Test took 982ms.
[11:29:11.469] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:11.775] <TB0> INFO: Expecting 2560 events.
[11:29:12.668] <TB0> INFO: 2560 events read in total (301ms).
[11:29:12.669] <TB0> INFO: Test took 1200ms.
[11:29:12.671] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:12.977] <TB0> INFO: Expecting 2560 events.
[11:29:13.869] <TB0> INFO: 2560 events read in total (300ms).
[11:29:13.869] <TB0> INFO: Test took 1198ms.
[11:29:13.871] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:14.178] <TB0> INFO: Expecting 2560 events.
[11:29:15.067] <TB0> INFO: 2560 events read in total (298ms).
[11:29:15.067] <TB0> INFO: Test took 1196ms.
[11:29:15.070] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:15.376] <TB0> INFO: Expecting 2560 events.
[11:29:16.266] <TB0> INFO: 2560 events read in total (298ms).
[11:29:16.266] <TB0> INFO: Test took 1196ms.
[11:29:16.269] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:16.574] <TB0> INFO: Expecting 2560 events.
[11:29:17.458] <TB0> INFO: 2560 events read in total (292ms).
[11:29:17.459] <TB0> INFO: Test took 1191ms.
[11:29:17.461] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:17.767] <TB0> INFO: Expecting 2560 events.
[11:29:18.658] <TB0> INFO: 2560 events read in total (299ms).
[11:29:18.659] <TB0> INFO: Test took 1199ms.
[11:29:18.661] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:18.966] <TB0> INFO: Expecting 2560 events.
[11:29:19.860] <TB0> INFO: 2560 events read in total (299ms).
[11:29:19.860] <TB0> INFO: Test took 1199ms.
[11:29:19.862] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:20.185] <TB0> INFO: Expecting 2560 events.
[11:29:21.065] <TB0> INFO: 2560 events read in total (288ms).
[11:29:21.066] <TB0> INFO: Test took 1204ms.
[11:29:21.068] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:21.395] <TB0> INFO: Expecting 2560 events.
[11:29:22.283] <TB0> INFO: 2560 events read in total (296ms).
[11:29:22.283] <TB0> INFO: Test took 1215ms.
[11:29:22.285] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:22.593] <TB0> INFO: Expecting 2560 events.
[11:29:23.477] <TB0> INFO: 2560 events read in total (293ms).
[11:29:23.477] <TB0> INFO: Test took 1192ms.
[11:29:23.480] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:23.787] <TB0> INFO: Expecting 2560 events.
[11:29:24.680] <TB0> INFO: 2560 events read in total (301ms).
[11:29:24.680] <TB0> INFO: Test took 1201ms.
[11:29:24.684] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:24.988] <TB0> INFO: Expecting 2560 events.
[11:29:25.873] <TB0> INFO: 2560 events read in total (294ms).
[11:29:25.874] <TB0> INFO: Test took 1190ms.
[11:29:25.877] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:26.186] <TB0> INFO: Expecting 2560 events.
[11:29:27.068] <TB0> INFO: 2560 events read in total (290ms).
[11:29:27.068] <TB0> INFO: Test took 1191ms.
[11:29:27.071] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:27.376] <TB0> INFO: Expecting 2560 events.
[11:29:28.257] <TB0> INFO: 2560 events read in total (289ms).
[11:29:28.258] <TB0> INFO: Test took 1188ms.
[11:29:28.261] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:28.566] <TB0> INFO: Expecting 2560 events.
[11:29:29.450] <TB0> INFO: 2560 events read in total (292ms).
[11:29:29.451] <TB0> INFO: Test took 1191ms.
[11:29:29.454] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:29.759] <TB0> INFO: Expecting 2560 events.
[11:29:30.644] <TB0> INFO: 2560 events read in total (291ms).
[11:29:30.645] <TB0> INFO: Test took 1191ms.
[11:29:30.648] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:30.953] <TB0> INFO: Expecting 2560 events.
[11:29:31.837] <TB0> INFO: 2560 events read in total (292ms).
[11:29:31.837] <TB0> INFO: Test took 1189ms.
[11:29:31.840] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:32.145] <TB0> INFO: Expecting 2560 events.
[11:29:33.026] <TB0> INFO: 2560 events read in total (289ms).
[11:29:33.027] <TB0> INFO: Test took 1187ms.
[11:29:33.029] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:33.336] <TB0> INFO: Expecting 2560 events.
[11:29:34.223] <TB0> INFO: 2560 events read in total (295ms).
[11:29:34.224] <TB0> INFO: Test took 1195ms.
[11:29:34.226] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:34.530] <TB0> INFO: Expecting 2560 events.
[11:29:35.416] <TB0> INFO: 2560 events read in total (294ms).
[11:29:35.417] <TB0> INFO: Test took 1191ms.
[11:29:35.420] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:35.724] <TB0> INFO: Expecting 2560 events.
[11:29:36.615] <TB0> INFO: 2560 events read in total (300ms).
[11:29:36.615] <TB0> INFO: Test took 1195ms.
[11:29:36.618] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:36.935] <TB0> INFO: Expecting 2560 events.
[11:29:37.830] <TB0> INFO: 2560 events read in total (301ms).
[11:29:37.830] <TB0> INFO: Test took 1212ms.
[11:29:37.833] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:38.142] <TB0> INFO: Expecting 2560 events.
[11:29:39.026] <TB0> INFO: 2560 events read in total (292ms).
[11:29:39.027] <TB0> INFO: Test took 1194ms.
[11:29:39.033] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:39.335] <TB0> INFO: Expecting 2560 events.
[11:29:40.226] <TB0> INFO: 2560 events read in total (299ms).
[11:29:40.227] <TB0> INFO: Test took 1194ms.
[11:29:40.231] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:40.534] <TB0> INFO: Expecting 2560 events.
[11:29:41.428] <TB0> INFO: 2560 events read in total (302ms).
[11:29:41.428] <TB0> INFO: Test took 1198ms.
[11:29:41.431] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:41.736] <TB0> INFO: Expecting 2560 events.
[11:29:42.626] <TB0> INFO: 2560 events read in total (298ms).
[11:29:42.627] <TB0> INFO: Test took 1196ms.
[11:29:42.630] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:42.935] <TB0> INFO: Expecting 2560 events.
[11:29:43.820] <TB0> INFO: 2560 events read in total (293ms).
[11:29:43.821] <TB0> INFO: Test took 1191ms.
[11:29:43.824] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:44.129] <TB0> INFO: Expecting 2560 events.
[11:29:45.015] <TB0> INFO: 2560 events read in total (295ms).
[11:29:45.015] <TB0> INFO: Test took 1192ms.
[11:29:45.018] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:45.324] <TB0> INFO: Expecting 2560 events.
[11:29:46.209] <TB0> INFO: 2560 events read in total (293ms).
[11:29:46.209] <TB0> INFO: Test took 1192ms.
[11:29:46.212] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:46.518] <TB0> INFO: Expecting 2560 events.
[11:29:47.410] <TB0> INFO: 2560 events read in total (299ms).
[11:29:47.410] <TB0> INFO: Test took 1198ms.
[11:29:47.412] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:29:47.719] <TB0> INFO: Expecting 2560 events.
[11:29:48.612] <TB0> INFO: 2560 events read in total (302ms).
[11:29:48.613] <TB0> INFO: Test took 1201ms.
[11:29:49.080] <TB0> INFO: PixTestPhOptimization::doTest() done, duration: 550 seconds
[11:29:49.080] <TB0> INFO: PH scale (per ROC): 58 59 51 62 70 68 74 41 68 53 61 47 44 59 64 61
[11:29:49.080] <TB0> INFO: PH offset (per ROC): 131 125 99 127 111 136 117 100 116 98 128 89 106 96 115 107
[11:29:49.089] <TB0> INFO: Decoding statistics:
[11:29:49.089] <TB0> INFO: General information:
[11:29:49.089] <TB0> INFO: 16bit words read: 127888
[11:29:49.089] <TB0> INFO: valid events total: 20480
[11:29:49.089] <TB0> INFO: empty events: 17976
[11:29:49.089] <TB0> INFO: valid events with pixels: 2504
[11:29:49.089] <TB0> INFO: valid pixel hits: 2504
[11:29:49.089] <TB0> INFO: Event errors: 0
[11:29:49.089] <TB0> INFO: start marker: 0
[11:29:49.089] <TB0> INFO: stop marker: 0
[11:29:49.089] <TB0> INFO: overflow: 0
[11:29:49.089] <TB0> INFO: invalid 5bit words: 0
[11:29:49.089] <TB0> INFO: invalid XOR eye diagram: 0
[11:29:49.089] <TB0> INFO: frame (failed synchr.): 0
[11:29:49.089] <TB0> INFO: idle data (no TBM trl): 0
[11:29:49.089] <TB0> INFO: no data (only TBM hdr): 0
[11:29:49.089] <TB0> INFO: TBM errors: 0
[11:29:49.089] <TB0> INFO: flawed TBM headers: 0
[11:29:49.089] <TB0> INFO: flawed TBM trailers: 0
[11:29:49.089] <TB0> INFO: event ID mismatches: 0
[11:29:49.089] <TB0> INFO: ROC errors: 0
[11:29:49.089] <TB0> INFO: missing ROC header(s): 0
[11:29:49.089] <TB0> INFO: misplaced readback start: 0
[11:29:49.089] <TB0> INFO: Pixel decoding errors: 0
[11:29:49.089] <TB0> INFO: pixel data incomplete: 0
[11:29:49.089] <TB0> INFO: pixel address: 0
[11:29:49.089] <TB0> INFO: pulse height fill bit: 0
[11:29:49.089] <TB0> INFO: buffer corruption: 0
[11:29:49.246] <TB0> INFO: ######################################################################
[11:29:49.246] <TB0> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[11:29:49.246] <TB0> INFO: ######################################################################
[11:29:49.262] <TB0> INFO: scanning low vcal = 10
[11:29:49.500] <TB0> INFO: Expecting 41600 events.
[11:29:53.144] <TB0> INFO: 41600 events read in total (3045ms).
[11:29:53.144] <TB0> INFO: Test took 3882ms.
[11:29:53.146] <TB0> INFO: scanning low vcal = 20
[11:29:53.438] <TB0> INFO: Expecting 41600 events.
[11:29:57.023] <TB0> INFO: 41600 events read in total (2993ms).
[11:29:57.024] <TB0> INFO: Test took 3878ms.
[11:29:57.026] <TB0> INFO: scanning low vcal = 30
[11:29:57.319] <TB0> INFO: Expecting 41600 events.
[11:30:00.994] <TB0> INFO: 41600 events read in total (3083ms).
[11:30:00.995] <TB0> INFO: Test took 3969ms.
[11:30:00.997] <TB0> INFO: scanning low vcal = 40
[11:30:01.275] <TB0> INFO: Expecting 41600 events.
[11:30:05.269] <TB0> INFO: 41600 events read in total (3402ms).
[11:30:05.270] <TB0> INFO: Test took 4273ms.
[11:30:05.273] <TB0> INFO: scanning low vcal = 50
[11:30:05.550] <TB0> INFO: Expecting 41600 events.
[11:30:09.560] <TB0> INFO: 41600 events read in total (3411ms).
[11:30:09.561] <TB0> INFO: Test took 4288ms.
[11:30:09.564] <TB0> INFO: scanning low vcal = 60
[11:30:09.841] <TB0> INFO: Expecting 41600 events.
[11:30:13.839] <TB0> INFO: 41600 events read in total (3406ms).
[11:30:13.840] <TB0> INFO: Test took 4276ms.
[11:30:13.843] <TB0> INFO: scanning low vcal = 70
[11:30:14.120] <TB0> INFO: Expecting 41600 events.
[11:30:18.121] <TB0> INFO: 41600 events read in total (3409ms).
[11:30:18.122] <TB0> INFO: Test took 4279ms.
[11:30:18.124] <TB0> INFO: scanning low vcal = 80
[11:30:18.403] <TB0> INFO: Expecting 41600 events.
[11:30:22.488] <TB0> INFO: 41600 events read in total (3493ms).
[11:30:22.489] <TB0> INFO: Test took 4364ms.
[11:30:22.492] <TB0> INFO: scanning low vcal = 90
[11:30:22.769] <TB0> INFO: Expecting 41600 events.
[11:30:26.796] <TB0> INFO: 41600 events read in total (3434ms).
[11:30:26.797] <TB0> INFO: Test took 4305ms.
[11:30:26.801] <TB0> INFO: scanning low vcal = 100
[11:30:27.077] <TB0> INFO: Expecting 41600 events.
[11:30:31.088] <TB0> INFO: 41600 events read in total (3419ms).
[11:30:31.088] <TB0> INFO: Test took 4287ms.
[11:30:31.091] <TB0> INFO: scanning low vcal = 110
[11:30:31.369] <TB0> INFO: Expecting 41600 events.
[11:30:35.407] <TB0> INFO: 41600 events read in total (3447ms).
[11:30:35.407] <TB0> INFO: Test took 4315ms.
[11:30:35.410] <TB0> INFO: scanning low vcal = 120
[11:30:35.688] <TB0> INFO: Expecting 41600 events.
[11:30:39.699] <TB0> INFO: 41600 events read in total (3419ms).
[11:30:39.700] <TB0> INFO: Test took 4290ms.
[11:30:39.711] <TB0> INFO: scanning low vcal = 130
[11:30:39.981] <TB0> INFO: Expecting 41600 events.
[11:30:43.973] <TB0> INFO: 41600 events read in total (3401ms).
[11:30:43.973] <TB0> INFO: Test took 4262ms.
[11:30:43.976] <TB0> INFO: scanning low vcal = 140
[11:30:44.253] <TB0> INFO: Expecting 41600 events.
[11:30:48.242] <TB0> INFO: 41600 events read in total (3397ms).
[11:30:48.243] <TB0> INFO: Test took 4267ms.
[11:30:48.249] <TB0> INFO: scanning low vcal = 150
[11:30:48.524] <TB0> INFO: Expecting 41600 events.
[11:30:52.569] <TB0> INFO: 41600 events read in total (3453ms).
[11:30:52.570] <TB0> INFO: Test took 4321ms.
[11:30:52.573] <TB0> INFO: scanning low vcal = 160
[11:30:52.850] <TB0> INFO: Expecting 41600 events.
[11:30:56.858] <TB0> INFO: 41600 events read in total (3416ms).
[11:30:56.858] <TB0> INFO: Test took 4285ms.
[11:30:56.862] <TB0> INFO: scanning low vcal = 170
[11:30:57.152] <TB0> INFO: Expecting 41600 events.
[11:31:01.120] <TB0> INFO: 41600 events read in total (3377ms).
[11:31:01.121] <TB0> INFO: Test took 4259ms.
[11:31:01.126] <TB0> INFO: scanning low vcal = 180
[11:31:01.401] <TB0> INFO: Expecting 41600 events.
[11:31:05.443] <TB0> INFO: 41600 events read in total (3450ms).
[11:31:05.443] <TB0> INFO: Test took 4317ms.
[11:31:05.447] <TB0> INFO: scanning low vcal = 190
[11:31:05.724] <TB0> INFO: Expecting 41600 events.
[11:31:09.738] <TB0> INFO: 41600 events read in total (3422ms).
[11:31:09.739] <TB0> INFO: Test took 4292ms.
[11:31:09.742] <TB0> INFO: scanning low vcal = 200
[11:31:10.020] <TB0> INFO: Expecting 41600 events.
[11:31:14.029] <TB0> INFO: 41600 events read in total (3417ms).
[11:31:14.030] <TB0> INFO: Test took 4288ms.
[11:31:14.033] <TB0> INFO: scanning low vcal = 210
[11:31:14.311] <TB0> INFO: Expecting 41600 events.
[11:31:18.342] <TB0> INFO: 41600 events read in total (3439ms).
[11:31:18.342] <TB0> INFO: Test took 4308ms.
[11:31:18.345] <TB0> INFO: scanning low vcal = 220
[11:31:18.623] <TB0> INFO: Expecting 41600 events.
[11:31:22.647] <TB0> INFO: 41600 events read in total (3432ms).
[11:31:22.648] <TB0> INFO: Test took 4302ms.
[11:31:22.652] <TB0> INFO: scanning low vcal = 230
[11:31:22.929] <TB0> INFO: Expecting 41600 events.
[11:31:26.964] <TB0> INFO: 41600 events read in total (3444ms).
[11:31:26.965] <TB0> INFO: Test took 4313ms.
[11:31:26.967] <TB0> INFO: scanning low vcal = 240
[11:31:27.244] <TB0> INFO: Expecting 41600 events.
[11:31:31.297] <TB0> INFO: 41600 events read in total (3461ms).
[11:31:31.298] <TB0> INFO: Test took 4330ms.
[11:31:31.301] <TB0> INFO: scanning low vcal = 250
[11:31:31.578] <TB0> INFO: Expecting 41600 events.
[11:31:35.591] <TB0> INFO: 41600 events read in total (3421ms).
[11:31:35.592] <TB0> INFO: Test took 4291ms.
[11:31:35.596] <TB0> INFO: scanning high vcal = 30 (= 210 in low range)
[11:31:35.872] <TB0> INFO: Expecting 41600 events.
[11:31:39.964] <TB0> INFO: 41600 events read in total (3500ms).
[11:31:39.965] <TB0> INFO: Test took 4369ms.
[11:31:39.968] <TB0> INFO: scanning high vcal = 50 (= 350 in low range)
[11:31:40.246] <TB0> INFO: Expecting 41600 events.
[11:31:44.264] <TB0> INFO: 41600 events read in total (3426ms).
[11:31:44.265] <TB0> INFO: Test took 4297ms.
[11:31:44.268] <TB0> INFO: scanning high vcal = 70 (= 490 in low range)
[11:31:44.546] <TB0> INFO: Expecting 41600 events.
[11:31:48.549] <TB0> INFO: 41600 events read in total (3412ms).
[11:31:48.549] <TB0> INFO: Test took 4280ms.
[11:31:48.553] <TB0> INFO: scanning high vcal = 90 (= 630 in low range)
[11:31:48.830] <TB0> INFO: Expecting 41600 events.
[11:31:52.868] <TB0> INFO: 41600 events read in total (3446ms).
[11:31:52.869] <TB0> INFO: Test took 4316ms.
[11:31:52.881] <TB0> INFO: scanning high vcal = 200 (= 1400 in low range)
[11:31:53.167] <TB0> INFO: Expecting 41600 events.
[11:31:57.180] <TB0> INFO: 41600 events read in total (3421ms).
[11:31:57.182] <TB0> INFO: Test took 4301ms.
[11:31:57.610] <TB0> INFO: PixTestGainPedestal::measure() done
[11:32:34.953] <TB0> INFO: PixTestGainPedestal::fit() done
[11:32:34.953] <TB0> INFO: non-linearity mean: 0.979 0.981 0.942 0.984 0.986 0.985 0.986 1.005 0.984 0.934 0.978 0.922 0.989 0.962 0.980 0.968
[11:32:34.953] <TB0> INFO: non-linearity RMS: 0.007 0.005 0.164 0.004 0.004 0.003 0.003 0.158 0.003 0.100 0.006 0.157 0.221 0.025 0.004 0.013
[11:32:34.953] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C0.dat
[11:32:34.972] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C1.dat
[11:32:34.991] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C2.dat
[11:32:35.010] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C3.dat
[11:32:35.028] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C4.dat
[11:32:35.047] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C5.dat
[11:32:35.066] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C6.dat
[11:32:35.084] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C7.dat
[11:32:35.103] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C8.dat
[11:32:35.122] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C9.dat
[11:32:35.135] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C10.dat
[11:32:35.148] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C11.dat
[11:32:35.161] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C12.dat
[11:32:35.173] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C13.dat
[11:32:35.186] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C14.dat
[11:32:35.199] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1003_FullQualification_2016-11-14_09h59m_1479113999//000_Fulltest_m20//phCalibrationFitErr35_C15.dat
[11:32:35.212] <TB0> INFO: PixTestGainPedestal::fullTest() done, duration: 165 seconds
[11:32:35.212] <TB0> INFO: Decoding statistics:
[11:32:35.212] <TB0> INFO: General information:
[11:32:35.212] <TB0> INFO: 16bit words read: 3327994
[11:32:35.212] <TB0> INFO: valid events total: 332800
[11:32:35.212] <TB0> INFO: empty events: 0
[11:32:35.212] <TB0> INFO: valid events with pixels: 332800
[11:32:35.212] <TB0> INFO: valid pixel hits: 665597
[11:32:35.212] <TB0> INFO: Event errors: 0
[11:32:35.212] <TB0> INFO: start marker: 0
[11:32:35.212] <TB0> INFO: stop marker: 0
[11:32:35.212] <TB0> INFO: overflow: 0
[11:32:35.212] <TB0> INFO: invalid 5bit words: 0
[11:32:35.212] <TB0> INFO: invalid XOR eye diagram: 0
[11:32:35.212] <TB0> INFO: frame (failed synchr.): 0
[11:32:35.212] <TB0> INFO: idle data (no TBM trl): 0
[11:32:35.212] <TB0> INFO: no data (only TBM hdr): 0
[11:32:35.212] <TB0> INFO: TBM errors: 0
[11:32:35.212] <TB0> INFO: flawed TBM headers: 0
[11:32:35.212] <TB0> INFO: flawed TBM trailers: 0
[11:32:35.212] <TB0> INFO: event ID mismatches: 0
[11:32:35.212] <TB0> INFO: ROC errors: 0
[11:32:35.212] <TB0> INFO: missing ROC header(s): 0
[11:32:35.212] <TB0> INFO: misplaced readback start: 0
[11:32:35.212] <TB0> INFO: Pixel decoding errors: 0
[11:32:35.212] <TB0> INFO: pixel data incomplete: 0
[11:32:35.212] <TB0> INFO: pixel address: 0
[11:32:35.212] <TB0> INFO: pulse height fill bit: 0
[11:32:35.212] <TB0> INFO: buffer corruption: 0
[11:32:35.226] <TB0> INFO: Decoding statistics:
[11:32:35.226] <TB0> INFO: General information:
[11:32:35.226] <TB0> INFO: 16bit words read: 3457418
[11:32:35.226] <TB0> INFO: valid events total: 353536
[11:32:35.226] <TB0> INFO: empty events: 18232
[11:32:35.226] <TB0> INFO: valid events with pixels: 335304
[11:32:35.226] <TB0> INFO: valid pixel hits: 668101
[11:32:35.226] <TB0> INFO: Event errors: 0
[11:32:35.226] <TB0> INFO: start marker: 0
[11:32:35.226] <TB0> INFO: stop marker: 0
[11:32:35.226] <TB0> INFO: overflow: 0
[11:32:35.226] <TB0> INFO: invalid 5bit words: 0
[11:32:35.226] <TB0> INFO: invalid XOR eye diagram: 0
[11:32:35.226] <TB0> INFO: frame (failed synchr.): 0
[11:32:35.226] <TB0> INFO: idle data (no TBM trl): 0
[11:32:35.226] <TB0> INFO: no data (only TBM hdr): 0
[11:32:35.226] <TB0> INFO: TBM errors: 0
[11:32:35.226] <TB0> INFO: flawed TBM headers: 0
[11:32:35.226] <TB0> INFO: flawed TBM trailers: 0
[11:32:35.226] <TB0> INFO: event ID mismatches: 0
[11:32:35.226] <TB0> INFO: ROC errors: 0
[11:32:35.226] <TB0> INFO: missing ROC header(s): 0
[11:32:35.226] <TB0> INFO: misplaced readback start: 0
[11:32:35.226] <TB0> INFO: Pixel decoding errors: 0
[11:32:35.226] <TB0> INFO: pixel data incomplete: 0
[11:32:35.226] <TB0> INFO: pixel address: 0
[11:32:35.226] <TB0> INFO: pulse height fill bit: 0
[11:32:35.226] <TB0> INFO: buffer corruption: 0
[11:32:35.227] <TB0> INFO: enter test to run
[11:32:35.227] <TB0> INFO: test: exit no parameter change
[11:32:35.349] <TB0> QUIET: Connection to board 71 closed.
[11:32:35.354] <TB0> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud