Test Date: 2016-11-02 15:29
Analysis date: 2016-11-04 19:34
Logfile
LogfileView
[16:27:09.953] <TB2> INFO: *** Welcome to pxar ***
[16:27:09.953] <TB2> INFO: *** Today: 2016/11/02
[16:27:09.960] <TB2> INFO: *** Version: c8ba-dirty
[16:27:09.960] <TB2> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C15.dat
[16:27:09.961] <TB2> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//tbmParameters_C1b.dat
[16:27:09.961] <TB2> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//defaultMaskFile.dat
[16:27:09.961] <TB2> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters_C15.dat
[16:27:10.015] <TB2> INFO: clk: 4
[16:27:10.015] <TB2> INFO: ctr: 4
[16:27:10.015] <TB2> INFO: sda: 19
[16:27:10.015] <TB2> INFO: tin: 9
[16:27:10.015] <TB2> INFO: level: 15
[16:27:10.015] <TB2> INFO: triggerdelay: 0
[16:27:10.015] <TB2> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[16:27:10.015] <TB2> INFO: Log level: INFO
[16:27:10.023] <TB2> INFO: Found DTB DTB_WXC55Z
[16:27:10.034] <TB2> QUIET: Connection to board DTB_WXC55Z opened.
[16:27:10.036] <TB2> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 156
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXC55Z
MAC address: 40D85511809C
Hostname: pixelDTB156
Comment:
------------------------------------------------------
[16:27:10.037] <TB2> INFO: RPC call hashes of host and DTB match: 486171790
[16:27:11.520] <TB2> INFO: DUT info:
[16:27:11.520] <TB2> INFO: The DUT currently contains the following objects:
[16:27:11.520] <TB2> INFO: 4 TBM Cores tbm10c (4 ON)
[16:27:11.520] <TB2> INFO: TBM Core alpha (0): 7 registers set
[16:27:11.520] <TB2> INFO: TBM Core beta (1): 7 registers set
[16:27:11.520] <TB2> INFO: TBM Core alpha (2): 7 registers set
[16:27:11.520] <TB2> INFO: TBM Core beta (3): 7 registers set
[16:27:11.520] <TB2> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[16:27:11.520] <TB2> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.520] <TB2> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:27:11.921] <TB2> INFO: enter 'restricted' command line mode
[16:27:11.921] <TB2> INFO: enter test to run
[16:27:11.921] <TB2> INFO: test: pretest no parameter change
[16:27:11.921] <TB2> INFO: running: pretest
[16:27:12.529] <TB2> INFO: ######################################################################
[16:27:12.529] <TB2> INFO: PixTestPretest::doTest()
[16:27:12.529] <TB2> INFO: ######################################################################
[16:27:12.530] <TB2> INFO: ----------------------------------------------------------------------
[16:27:12.530] <TB2> INFO: PixTestPretest::programROC()
[16:27:12.530] <TB2> INFO: ----------------------------------------------------------------------
[16:27:30.543] <TB2> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[16:27:30.543] <TB2> INFO: IA differences per ROC: 18.5 19.3 22.5 18.5 18.5 17.7 17.7 21.7 20.9 21.7 18.5 19.3 18.5 20.9 20.1 18.5
[16:27:30.580] <TB2> INFO: ----------------------------------------------------------------------
[16:27:30.580] <TB2> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[16:27:30.580] <TB2> INFO: ----------------------------------------------------------------------
[16:27:51.822] <TB2> INFO: PixTestPretest::setVana() done, Module Ia 395.5 mA = 24.7188 mA/ROC
[16:27:51.822] <TB2> INFO: i(loss) [mA/ROC]: 19.3 20.9 19.3 20.9 20.1 19.3 19.3 20.1 19.3 20.9 20.9 19.3 20.9 19.3 19.3 19.3
[16:27:51.851] <TB2> INFO: ----------------------------------------------------------------------
[16:27:51.851] <TB2> INFO: PixTestPretest::findTiming()
[16:27:51.851] <TB2> INFO: ----------------------------------------------------------------------
[16:27:51.851] <TB2> INFO: PixTestCmd::init()
[16:27:52.419] <TB2> WARNING: Not unmasking DUT, not setting Calibrate bits!

[16:28:22.084] <TB2> INFO: TBM phases: 160MHz: 4, 400MHz: 6, TBM delays: ROC(0/1):3, header/trailer: 1, token: 0
[16:28:22.084] <TB2> INFO: (success/tries = 100/100), width = 4
[16:28:23.590] <TB2> INFO: ----------------------------------------------------------------------
[16:28:23.590] <TB2> INFO: PixTestPretest::findWorkingPixel()
[16:28:23.590] <TB2> INFO: ----------------------------------------------------------------------
[16:28:23.682] <TB2> INFO: Expecting 231680 events.
[16:28:33.277] <TB2> INFO: 231680 events read in total (9003ms).
[16:28:33.283] <TB2> INFO: Test took 9690ms.
[16:28:33.529] <TB2> INFO: Found working pixel in all ROCs: col/row = 12/22
[16:28:33.559] <TB2> INFO: ----------------------------------------------------------------------
[16:28:33.559] <TB2> INFO: PixTestPretest::setVthrCompCalDel()
[16:28:33.559] <TB2> INFO: ----------------------------------------------------------------------
[16:28:33.651] <TB2> INFO: Expecting 231680 events.
[16:28:43.325] <TB2> INFO: 231680 events read in total (9083ms).
[16:28:43.334] <TB2> INFO: Test took 9772ms.
[16:28:43.598] <TB2> INFO: PixTestPretest::setVthrCompCalDel() done
[16:28:43.598] <TB2> INFO: CalDel: 98 101 105 89 71 82 108 83 84 103 93 86 101 106 100 92
[16:28:43.598] <TB2> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[16:28:43.600] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C0.dat
[16:28:43.600] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C1.dat
[16:28:43.600] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C2.dat
[16:28:43.600] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C3.dat
[16:28:43.600] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C4.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C5.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C6.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C7.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C8.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C9.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C10.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C11.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C12.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C13.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C14.dat
[16:28:43.601] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters_C15.dat
[16:28:43.601] <TB2> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//tbmParameters_C0a.dat
[16:28:43.601] <TB2> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//tbmParameters_C0b.dat
[16:28:43.601] <TB2> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//tbmParameters_C1a.dat
[16:28:43.602] <TB2> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//tbmParameters_C1b.dat
[16:28:43.602] <TB2> INFO: PixTestPretest::doTest() done, duration: 91 seconds
[16:28:43.697] <TB2> INFO: enter test to run
[16:28:43.697] <TB2> INFO: test: FullTest no parameter change
[16:28:43.697] <TB2> INFO: running: fulltest
[16:28:43.697] <TB2> INFO: ######################################################################
[16:28:43.697] <TB2> INFO: PixTestFullTest::doTest()
[16:28:43.697] <TB2> INFO: ######################################################################
[16:28:43.698] <TB2> INFO: ######################################################################
[16:28:43.698] <TB2> INFO: PixTestAlive::doTest()
[16:28:43.698] <TB2> INFO: ######################################################################
[16:28:43.699] <TB2> INFO: ----------------------------------------------------------------------
[16:28:43.699] <TB2> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:28:43.699] <TB2> INFO: ----------------------------------------------------------------------
[16:28:43.976] <TB2> INFO: Expecting 41600 events.
[16:28:47.611] <TB2> INFO: 41600 events read in total (3043ms).
[16:28:47.612] <TB2> INFO: Test took 3911ms.
[16:28:47.838] <TB2> INFO: PixTestAlive::aliveTest() done
[16:28:47.838] <TB2> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:28:47.839] <TB2> INFO: ----------------------------------------------------------------------
[16:28:47.839] <TB2> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:28:47.839] <TB2> INFO: ----------------------------------------------------------------------
[16:28:48.073] <TB2> INFO: Expecting 41600 events.
[16:28:51.098] <TB2> INFO: 41600 events read in total (2434ms).
[16:28:51.098] <TB2> INFO: Test took 3256ms.
[16:28:51.099] <TB2> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[16:28:51.341] <TB2> INFO: PixTestAlive::maskTest() done
[16:28:51.341] <TB2> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:28:51.342] <TB2> INFO: ----------------------------------------------------------------------
[16:28:51.342] <TB2> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:28:51.342] <TB2> INFO: ----------------------------------------------------------------------
[16:28:51.576] <TB2> INFO: Expecting 41600 events.
[16:28:55.014] <TB2> INFO: 41600 events read in total (2846ms).
[16:28:55.014] <TB2> INFO: Test took 3671ms.
[16:28:55.242] <TB2> INFO: PixTestAlive::addressDecodingTest() done
[16:28:55.242] <TB2> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:28:55.242] <TB2> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[16:28:55.242] <TB2> INFO: Decoding statistics:
[16:28:55.242] <TB2> INFO: General information:
[16:28:55.242] <TB2> INFO: 16bit words read: 0
[16:28:55.242] <TB2> INFO: valid events total: 0
[16:28:55.242] <TB2> INFO: empty events: 0
[16:28:55.242] <TB2> INFO: valid events with pixels: 0
[16:28:55.242] <TB2> INFO: valid pixel hits: 0
[16:28:55.242] <TB2> INFO: Event errors: 0
[16:28:55.242] <TB2> INFO: start marker: 0
[16:28:55.242] <TB2> INFO: stop marker: 0
[16:28:55.242] <TB2> INFO: overflow: 0
[16:28:55.242] <TB2> INFO: invalid 5bit words: 0
[16:28:55.242] <TB2> INFO: invalid XOR eye diagram: 0
[16:28:55.242] <TB2> INFO: frame (failed synchr.): 0
[16:28:55.242] <TB2> INFO: idle data (no TBM trl): 0
[16:28:55.242] <TB2> INFO: no data (only TBM hdr): 0
[16:28:55.242] <TB2> INFO: TBM errors: 0
[16:28:55.242] <TB2> INFO: flawed TBM headers: 0
[16:28:55.242] <TB2> INFO: flawed TBM trailers: 0
[16:28:55.242] <TB2> INFO: event ID mismatches: 0
[16:28:55.242] <TB2> INFO: ROC errors: 0
[16:28:55.242] <TB2> INFO: missing ROC header(s): 0
[16:28:55.242] <TB2> INFO: misplaced readback start: 0
[16:28:55.242] <TB2> INFO: Pixel decoding errors: 0
[16:28:55.242] <TB2> INFO: pixel data incomplete: 0
[16:28:55.242] <TB2> INFO: pixel address: 0
[16:28:55.242] <TB2> INFO: pulse height fill bit: 0
[16:28:55.242] <TB2> INFO: buffer corruption: 0
[16:28:55.250] <TB2> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C15.dat
[16:28:55.250] <TB2> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[16:28:55.250] <TB2> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[16:28:55.250] <TB2> INFO: ######################################################################
[16:28:55.250] <TB2> INFO: PixTestReadback::doTest()
[16:28:55.250] <TB2> INFO: ######################################################################
[16:28:55.250] <TB2> INFO: ----------------------------------------------------------------------
[16:28:55.250] <TB2> INFO: PixTestReadback::CalibrateVd()
[16:28:55.250] <TB2> INFO: ----------------------------------------------------------------------
[16:29:05.220] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C0.dat
[16:29:05.220] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C1.dat
[16:29:05.220] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C2.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C3.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C4.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C5.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C6.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C7.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C8.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C9.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C10.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C11.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C12.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C13.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C14.dat
[16:29:05.221] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C15.dat
[16:29:05.248] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[16:29:05.248] <TB2> INFO: ----------------------------------------------------------------------
[16:29:05.248] <TB2> INFO: PixTestReadback::CalibrateVa()
[16:29:05.248] <TB2> INFO: ----------------------------------------------------------------------
[16:29:15.135] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C0.dat
[16:29:15.135] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C1.dat
[16:29:15.135] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C2.dat
[16:29:15.135] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C3.dat
[16:29:15.135] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C4.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C5.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C6.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C7.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C8.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C9.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C10.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C11.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C12.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C13.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C14.dat
[16:29:15.136] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C15.dat
[16:29:15.164] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[16:29:15.164] <TB2> INFO: ----------------------------------------------------------------------
[16:29:15.164] <TB2> INFO: PixTestReadback::readbackVbg()
[16:29:15.164] <TB2> INFO: ----------------------------------------------------------------------
[16:29:22.805] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[16:29:22.805] <TB2> INFO: ----------------------------------------------------------------------
[16:29:22.805] <TB2> INFO: PixTestReadback::getCalibratedVbg()
[16:29:22.805] <TB2> INFO: ----------------------------------------------------------------------
[16:29:22.805] <TB2> INFO: Vbg will be calibrated using Vd calibration
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 150calibrated Vbg = 1.16488 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 147.3calibrated Vbg = 1.15672 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 165calibrated Vbg = 1.15773 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 148.7calibrated Vbg = 1.15132 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 159.2calibrated Vbg = 1.15225 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 166.9calibrated Vbg = 1.16335 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 152.1calibrated Vbg = 1.16213 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 155.3calibrated Vbg = 1.16772 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 150.1calibrated Vbg = 1.15121 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 155.4calibrated Vbg = 1.15533 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 160.9calibrated Vbg = 1.15353 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 148.1calibrated Vbg = 1.14626 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 150.6calibrated Vbg = 1.1612 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 151.2calibrated Vbg = 1.15703 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 155.5calibrated Vbg = 1.16151 :::*/*/*/*/
[16:29:22.805] <TB2> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 152calibrated Vbg = 1.15711 :::*/*/*/*/
[16:29:22.807] <TB2> INFO: ----------------------------------------------------------------------
[16:29:22.807] <TB2> INFO: PixTestReadback::CalibrateIa()
[16:29:22.807] <TB2> INFO: ----------------------------------------------------------------------
[16:32:03.074] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C0.dat
[16:32:03.075] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C1.dat
[16:32:03.075] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C2.dat
[16:32:03.075] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C3.dat
[16:32:03.075] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C4.dat
[16:32:03.075] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C5.dat
[16:32:03.075] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C6.dat
[16:32:03.075] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C7.dat
[16:32:03.075] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C8.dat
[16:32:03.076] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C9.dat
[16:32:03.076] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C10.dat
[16:32:03.076] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C11.dat
[16:32:03.076] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C12.dat
[16:32:03.076] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C13.dat
[16:32:03.076] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C14.dat
[16:32:03.076] <TB2> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//readbackCal_C15.dat
[16:32:03.103] <TB2> INFO: PixTestPattern:: pg_setup set to default.
[16:32:03.104] <TB2> INFO: PixTestReadback::doTest() done
[16:32:03.104] <TB2> INFO: Decoding statistics:
[16:32:03.104] <TB2> INFO: General information:
[16:32:03.104] <TB2> INFO: 16bit words read: 1536
[16:32:03.104] <TB2> INFO: valid events total: 256
[16:32:03.104] <TB2> INFO: empty events: 256
[16:32:03.104] <TB2> INFO: valid events with pixels: 0
[16:32:03.104] <TB2> INFO: valid pixel hits: 0
[16:32:03.104] <TB2> INFO: Event errors: 0
[16:32:03.104] <TB2> INFO: start marker: 0
[16:32:03.104] <TB2> INFO: stop marker: 0
[16:32:03.104] <TB2> INFO: overflow: 0
[16:32:03.104] <TB2> INFO: invalid 5bit words: 0
[16:32:03.104] <TB2> INFO: invalid XOR eye diagram: 0
[16:32:03.104] <TB2> INFO: frame (failed synchr.): 0
[16:32:03.104] <TB2> INFO: idle data (no TBM trl): 0
[16:32:03.104] <TB2> INFO: no data (only TBM hdr): 0
[16:32:03.104] <TB2> INFO: TBM errors: 0
[16:32:03.104] <TB2> INFO: flawed TBM headers: 0
[16:32:03.104] <TB2> INFO: flawed TBM trailers: 0
[16:32:03.104] <TB2> INFO: event ID mismatches: 0
[16:32:03.104] <TB2> INFO: ROC errors: 0
[16:32:03.104] <TB2> INFO: missing ROC header(s): 0
[16:32:03.104] <TB2> INFO: misplaced readback start: 0
[16:32:03.104] <TB2> INFO: Pixel decoding errors: 0
[16:32:03.104] <TB2> INFO: pixel data incomplete: 0
[16:32:03.104] <TB2> INFO: pixel address: 0
[16:32:03.104] <TB2> INFO: pulse height fill bit: 0
[16:32:03.104] <TB2> INFO: buffer corruption: 0
[16:32:03.138] <TB2> INFO: ######################################################################
[16:32:03.138] <TB2> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[16:32:03.138] <TB2> INFO: ######################################################################
[16:32:03.141] <TB2> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[16:32:03.152] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[16:32:03.152] <TB2> INFO: run 1 of 1
[16:32:03.384] <TB2> INFO: Expecting 3120000 events.
[16:32:33.907] <TB2> INFO: 668725 events read in total (29932ms).
[16:32:46.100] <TB2> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (182) != TBM ID (129)

[16:32:46.236] <TB2> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 182 182 129 182 182 182 182 182

[16:32:46.236] <TB2> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (183)

[16:32:46.236] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[16:32:46.236] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ba 8000 4070 262 27a0 4070 262 27ef e022 c000

[16:32:46.236] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b4 80b1 40e0 262 278f 4070 262 27ef e022 c000

[16:32:46.236] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b5 80c0 4070 262 27a0 4070 262 27ef e022 c000

[16:32:46.236] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4071 27a0 4070 262 27ef e022 c000

[16:32:46.236] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b7 8040 4070 262 27a0 4070 262 27ef e022 c000

[16:32:46.236] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b8 80b1 4060 262 27a0 4060 262 27ef e022 c000

[16:32:46.236] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b9 80c0 40e1 262 27a0 4071 262 27ef e022 c000

[16:33:03.477] <TB2> INFO: 1331760 events read in total (59502ms).
[16:33:15.595] <TB2> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (177) != TBM ID (129)

[16:33:15.729] <TB2> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 177 177 129 177 177 177 177 177

[16:33:15.729] <TB2> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (178)

[16:33:15.729] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[16:33:15.729] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b5 80c0 40e0 4c2 2f6d 4060 4c2 2fef e022 c000

[16:33:15.729] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0af 8040 4072 4c2 2f6d 4072 4c2 2fef e022 c000

[16:33:15.729] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b0 80b1 40e0 4c2 2f6d 40f0 4c2 2fef e022 c000

[16:33:15.729] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4071 2f6d 40e1 4c2 2fef e022 c000

[16:33:15.729] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b2 8000 40e0 4c2 2f6c 40e0 4c2 2fef e022 c000

[16:33:15.729] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b3 8040 40e0 4c2 2f6d 40e1 4c2 2fef e022 c000

[16:33:15.729] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b4 80b1 40e0 4c2 2f6c 40e0 4c2 2fef e022 c000

[16:33:33.010] <TB2> INFO: 1990870 events read in total (89035ms).
[16:33:45.158] <TB2> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (87) != TBM ID (129)

[16:33:45.294] <TB2> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 87 87 129 87 87 87 87 87

[16:33:45.295] <TB2> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (88)

[16:33:45.295] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[16:33:45.295] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05b 8040 4070 4070 e022 c000

[16:33:45.295] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a055 80c0 4070 4070 e022 c000

[16:33:45.295] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a056 8000 4070 4070 e022 c000

[16:33:45.295] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4071 2da5 40e0 e022 c000

[16:33:45.295] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a058 80b1 40e0 40e0 e022 c000

[16:33:45.295] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a059 80c0 4061 4061 e022 c000

[16:33:45.295] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05a 8000 4060 4060 e022 c000

[16:34:02.696] <TB2> INFO: 2650805 events read in total (118721ms).
[16:34:11.420] <TB2> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (54) != TBM ID (129)

[16:34:11.559] <TB2> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 54 54 129 54 54 54 54 54

[16:34:11.559] <TB2> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (55)

[16:34:11.559] <TB2> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[16:34:11.559] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03a 8000 4061 4061 e022 c000

[16:34:11.559] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a034 80b1 4070 4070 e022 c000

[16:34:11.559] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a035 80c0 4070 4070 e022 c000

[16:34:11.559] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4071 e022 c000

[16:34:11.559] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a037 8040 4070 4070 e022 c000

[16:34:11.559] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a038 80b1 40f0 40f0 e022 c000

[16:34:11.559] <TB2> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a039 80c0 4060 4060 e022 c000

[16:34:24.685] <TB2> INFO: 3120000 events read in total (140710ms).
[16:34:24.750] <TB2> INFO: Test took 141598ms.
[16:34:50.758] <TB2> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 167 seconds
[16:34:50.758] <TB2> INFO: number of dead bumps (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[16:34:50.758] <TB2> INFO: separation cut (per ROC): 103 109 105 96 108 122 105 116 109 126 116 109 106 106 102 107
[16:34:50.758] <TB2> INFO: Decoding statistics:
[16:34:50.758] <TB2> INFO: General information:
[16:34:50.758] <TB2> INFO: 16bit words read: 0
[16:34:50.758] <TB2> INFO: valid events total: 0
[16:34:50.758] <TB2> INFO: empty events: 0
[16:34:50.759] <TB2> INFO: valid events with pixels: 0
[16:34:50.759] <TB2> INFO: valid pixel hits: 0
[16:34:50.759] <TB2> INFO: Event errors: 0
[16:34:50.759] <TB2> INFO: start marker: 0
[16:34:50.759] <TB2> INFO: stop marker: 0
[16:34:50.759] <TB2> INFO: overflow: 0
[16:34:50.759] <TB2> INFO: invalid 5bit words: 0
[16:34:50.759] <TB2> INFO: invalid XOR eye diagram: 0
[16:34:50.759] <TB2> INFO: frame (failed synchr.): 0
[16:34:50.759] <TB2> INFO: idle data (no TBM trl): 0
[16:34:50.759] <TB2> INFO: no data (only TBM hdr): 0
[16:34:50.759] <TB2> INFO: TBM errors: 0
[16:34:50.759] <TB2> INFO: flawed TBM headers: 0
[16:34:50.759] <TB2> INFO: flawed TBM trailers: 0
[16:34:50.759] <TB2> INFO: event ID mismatches: 0
[16:34:50.759] <TB2> INFO: ROC errors: 0
[16:34:50.759] <TB2> INFO: missing ROC header(s): 0
[16:34:50.759] <TB2> INFO: misplaced readback start: 0
[16:34:50.759] <TB2> INFO: Pixel decoding errors: 0
[16:34:50.759] <TB2> INFO: pixel data incomplete: 0
[16:34:50.759] <TB2> INFO: pixel address: 0
[16:34:50.759] <TB2> INFO: pulse height fill bit: 0
[16:34:50.759] <TB2> INFO: buffer corruption: 0
[16:34:50.794] <TB2> INFO: ######################################################################
[16:34:50.794] <TB2> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[16:34:50.794] <TB2> INFO: ######################################################################
[16:34:50.795] <TB2> INFO: ----------------------------------------------------------------------
[16:34:50.795] <TB2> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[16:34:50.795] <TB2> INFO: ----------------------------------------------------------------------
[16:34:50.795] <TB2> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[16:34:50.806] <TB2> INFO: dacScan split into 1 runs with ntrig = 50
[16:34:50.806] <TB2> INFO: run 1 of 1
[16:34:51.067] <TB2> INFO: Expecting 36608000 events.
[16:35:13.738] <TB2> INFO: 661300 events read in total (22079ms).
[16:35:35.824] <TB2> INFO: 1310750 events read in total (44165ms).
[16:35:57.821] <TB2> INFO: 1960350 events read in total (66162ms).
[16:36:19.873] <TB2> INFO: 2608800 events read in total (88214ms).
[16:36:41.955] <TB2> INFO: 3255150 events read in total (110296ms).
[16:37:04.164] <TB2> INFO: 3902400 events read in total (132505ms).
[16:37:25.913] <TB2> INFO: 4548550 events read in total (154254ms).
[16:37:47.825] <TB2> INFO: 5196350 events read in total (176166ms).
[16:38:09.892] <TB2> INFO: 5841750 events read in total (198233ms).
[16:38:31.837] <TB2> INFO: 6487350 events read in total (220178ms).
[16:38:53.751] <TB2> INFO: 7132600 events read in total (242092ms).
[16:39:15.537] <TB2> INFO: 7778350 events read in total (263878ms).
[16:39:37.489] <TB2> INFO: 8423650 events read in total (285830ms).
[16:39:59.552] <TB2> INFO: 9069950 events read in total (307893ms).
[16:40:21.522] <TB2> INFO: 9715150 events read in total (329863ms).
[16:40:43.816] <TB2> INFO: 10359800 events read in total (352157ms).
[16:41:05.835] <TB2> INFO: 11003800 events read in total (374176ms).
[16:41:27.743] <TB2> INFO: 11648300 events read in total (396084ms).
[16:41:49.764] <TB2> INFO: 12292350 events read in total (418105ms).
[16:42:11.773] <TB2> INFO: 12936500 events read in total (440114ms).
[16:42:33.879] <TB2> INFO: 13581650 events read in total (462220ms).
[16:42:56.130] <TB2> INFO: 14225300 events read in total (484471ms).
[16:43:18.356] <TB2> INFO: 14871450 events read in total (506697ms).
[16:43:40.447] <TB2> INFO: 15516500 events read in total (528788ms).
[16:44:02.640] <TB2> INFO: 16161400 events read in total (550981ms).
[16:44:24.622] <TB2> INFO: 16804750 events read in total (572963ms).
[16:44:46.670] <TB2> INFO: 17447200 events read in total (595011ms).
[16:45:08.874] <TB2> INFO: 18089950 events read in total (617215ms).
[16:45:30.844] <TB2> INFO: 18732550 events read in total (639185ms).
[16:45:52.885] <TB2> INFO: 19373750 events read in total (661226ms).
[16:46:14.973] <TB2> INFO: 20014800 events read in total (683314ms).
[16:46:37.005] <TB2> INFO: 20653900 events read in total (705346ms).
[16:46:58.997] <TB2> INFO: 21293750 events read in total (727338ms).
[16:47:20.766] <TB2> INFO: 21935000 events read in total (749107ms).
[16:47:42.477] <TB2> INFO: 22576650 events read in total (770818ms).
[16:48:04.600] <TB2> INFO: 23216250 events read in total (792941ms).
[16:48:26.581] <TB2> INFO: 23855050 events read in total (814922ms).
[16:48:48.448] <TB2> INFO: 24495700 events read in total (836789ms).
[16:49:10.442] <TB2> INFO: 25136550 events read in total (858783ms).
[16:49:32.517] <TB2> INFO: 25776550 events read in total (880858ms).
[16:49:54.789] <TB2> INFO: 26416700 events read in total (903130ms).
[16:50:16.819] <TB2> INFO: 27056550 events read in total (925160ms).
[16:50:38.769] <TB2> INFO: 27697250 events read in total (947110ms).
[16:51:00.810] <TB2> INFO: 28335750 events read in total (969151ms).
[16:51:22.930] <TB2> INFO: 28975600 events read in total (991271ms).
[16:51:45.006] <TB2> INFO: 29615700 events read in total (1013347ms).
[16:52:06.933] <TB2> INFO: 30252950 events read in total (1035274ms).
[16:52:28.720] <TB2> INFO: 30891150 events read in total (1057061ms).
[16:52:50.744] <TB2> INFO: 31530050 events read in total (1079085ms).
[16:53:12.465] <TB2> INFO: 32169750 events read in total (1100806ms).
[16:53:34.455] <TB2> INFO: 32808800 events read in total (1122796ms).
[16:53:56.429] <TB2> INFO: 33447550 events read in total (1144770ms).
[16:54:18.441] <TB2> INFO: 34088300 events read in total (1166782ms).
[16:54:40.213] <TB2> INFO: 34729250 events read in total (1188554ms).
[16:55:02.201] <TB2> INFO: 35369150 events read in total (1210542ms).
[16:55:24.388] <TB2> INFO: 36013750 events read in total (1232729ms).
[16:55:44.588] <TB2> INFO: 36608000 events read in total (1252929ms).
[16:55:44.647] <TB2> INFO: Test took 1253840ms.
[16:55:45.105] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:55:47.181] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:55:49.260] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:55:51.245] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:55:53.162] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:55:55.008] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:55:57.072] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:55:59.266] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:56:01.392] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:56:03.458] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:56:05.531] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:56:07.579] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:56:09.119] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:56:10.680] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:56:12.135] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:56:13.646] <TB2> INFO: dumping ASCII scurve output file: SCurveData
[16:56:15.161] <TB2> INFO: PixTestScurves::scurves() done
[16:56:15.161] <TB2> INFO: Vcal mean: 107.19 114.47 106.95 94.22 110.17 119.12 105.25 118.13 116.47 125.24 122.66 103.52 110.98 105.20 111.96 114.84
[16:56:15.161] <TB2> INFO: Vcal RMS: 5.21 5.18 4.99 4.67 4.67 5.56 5.08 5.48 6.07 6.32 6.34 5.23 5.11 5.41 5.32 5.38
[16:56:15.162] <TB2> INFO: PixTestScurves::fullTest() done, duration: 1284 seconds
[16:56:15.162] <TB2> INFO: Decoding statistics:
[16:56:15.162] <TB2> INFO: General information:
[16:56:15.162] <TB2> INFO: 16bit words read: 0
[16:56:15.162] <TB2> INFO: valid events total: 0
[16:56:15.162] <TB2> INFO: empty events: 0
[16:56:15.162] <TB2> INFO: valid events with pixels: 0
[16:56:15.162] <TB2> INFO: valid pixel hits: 0
[16:56:15.162] <TB2> INFO: Event errors: 0
[16:56:15.162] <TB2> INFO: start marker: 0
[16:56:15.162] <TB2> INFO: stop marker: 0
[16:56:15.162] <TB2> INFO: overflow: 0
[16:56:15.162] <TB2> INFO: invalid 5bit words: 0
[16:56:15.162] <TB2> INFO: invalid XOR eye diagram: 0
[16:56:15.162] <TB2> INFO: frame (failed synchr.): 0
[16:56:15.162] <TB2> INFO: idle data (no TBM trl): 0
[16:56:15.162] <TB2> INFO: no data (only TBM hdr): 0
[16:56:15.162] <TB2> INFO: TBM errors: 0
[16:56:15.162] <TB2> INFO: flawed TBM headers: 0
[16:56:15.162] <TB2> INFO: flawed TBM trailers: 0
[16:56:15.162] <TB2> INFO: event ID mismatches: 0
[16:56:15.162] <TB2> INFO: ROC errors: 0
[16:56:15.162] <TB2> INFO: missing ROC header(s): 0
[16:56:15.162] <TB2> INFO: misplaced readback start: 0
[16:56:15.162] <TB2> INFO: Pixel decoding errors: 0
[16:56:15.162] <TB2> INFO: pixel data incomplete: 0
[16:56:15.162] <TB2> INFO: pixel address: 0
[16:56:15.162] <TB2> INFO: pulse height fill bit: 0
[16:56:15.162] <TB2> INFO: buffer corruption: 0
[16:56:15.226] <TB2> INFO: ######################################################################
[16:56:15.226] <TB2> INFO: PixTestTrim::doTest()
[16:56:15.226] <TB2> INFO: ######################################################################
[16:56:15.227] <TB2> INFO: ----------------------------------------------------------------------
[16:56:15.227] <TB2> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[16:56:15.227] <TB2> INFO: ----------------------------------------------------------------------
[16:56:15.268] <TB2> INFO: ---> VthrComp thr map (minimal VthrComp)
[16:56:15.268] <TB2> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[16:56:15.278] <TB2> INFO: dacScan split into 1 runs with ntrig = 8
[16:56:15.278] <TB2> INFO: run 1 of 1
[16:56:15.509] <TB2> INFO: Expecting 5025280 events.
[16:56:45.489] <TB2> INFO: 808992 events read in total (29384ms).
[16:57:14.908] <TB2> INFO: 1614616 events read in total (58803ms).
[16:57:44.372] <TB2> INFO: 2419384 events read in total (88268ms).
[16:58:13.701] <TB2> INFO: 3217976 events read in total (117596ms).
[16:58:42.902] <TB2> INFO: 4013128 events read in total (146797ms).
[16:59:12.163] <TB2> INFO: 4804576 events read in total (176058ms).
[16:59:20.724] <TB2> INFO: 5025280 events read in total (184619ms).
[16:59:20.773] <TB2> INFO: Test took 185496ms.
[16:59:38.831] <TB2> INFO: ROC 0 VthrComp = 118
[16:59:38.831] <TB2> INFO: ROC 1 VthrComp = 131
[16:59:38.831] <TB2> INFO: ROC 2 VthrComp = 123
[16:59:38.831] <TB2> INFO: ROC 3 VthrComp = 110
[16:59:38.831] <TB2> INFO: ROC 4 VthrComp = 128
[16:59:38.831] <TB2> INFO: ROC 5 VthrComp = 132
[16:59:38.831] <TB2> INFO: ROC 6 VthrComp = 115
[16:59:38.832] <TB2> INFO: ROC 7 VthrComp = 132
[16:59:38.832] <TB2> INFO: ROC 8 VthrComp = 123
[16:59:38.832] <TB2> INFO: ROC 9 VthrComp = 133
[16:59:38.833] <TB2> INFO: ROC 10 VthrComp = 134
[16:59:38.833] <TB2> INFO: ROC 11 VthrComp = 116
[16:59:38.833] <TB2> INFO: ROC 12 VthrComp = 122
[16:59:38.833] <TB2> INFO: ROC 13 VthrComp = 115
[16:59:38.833] <TB2> INFO: ROC 14 VthrComp = 118
[16:59:38.833] <TB2> INFO: ROC 15 VthrComp = 124
[16:59:39.072] <TB2> INFO: Expecting 41600 events.
[16:59:42.492] <TB2> INFO: 41600 events read in total (2828ms).
[16:59:42.493] <TB2> INFO: Test took 3659ms.
[16:59:42.501] <TB2> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[16:59:42.501] <TB2> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[16:59:42.511] <TB2> INFO: dacScan split into 1 runs with ntrig = 8
[16:59:42.511] <TB2> INFO: run 1 of 1
[16:59:42.788] <TB2> INFO: Expecting 5025280 events.
[17:00:08.622] <TB2> INFO: 588440 events read in total (25242ms).
[17:00:33.868] <TB2> INFO: 1175600 events read in total (50488ms).
[17:00:58.917] <TB2> INFO: 1762704 events read in total (75537ms).
[17:01:23.945] <TB2> INFO: 2349984 events read in total (100565ms).
[17:01:48.948] <TB2> INFO: 2935144 events read in total (125568ms).
[17:02:14.036] <TB2> INFO: 3519608 events read in total (150656ms).
[17:02:39.697] <TB2> INFO: 4103152 events read in total (176317ms).
[17:03:05.010] <TB2> INFO: 4686256 events read in total (201630ms).
[17:03:20.055] <TB2> INFO: 5025280 events read in total (216675ms).
[17:03:20.115] <TB2> INFO: Test took 217605ms.
[17:03:47.948] <TB2> INFO: roc 0 with ID = 0 has maximal Vcal 56.6764 for pixel 19/42 mean/min/max = 44.6639/32.3881/56.9397
[17:03:47.948] <TB2> INFO: roc 1 with ID = 1 has maximal Vcal 56.3722 for pixel 36/12 mean/min/max = 44.5362/32.2525/56.8198
[17:03:47.949] <TB2> INFO: roc 2 with ID = 2 has maximal Vcal 55.7218 for pixel 0/75 mean/min/max = 43.7116/31.6882/55.7351
[17:03:47.949] <TB2> INFO: roc 3 with ID = 3 has maximal Vcal 55.2319 for pixel 14/10 mean/min/max = 44.6618/33.8931/55.4305
[17:03:47.949] <TB2> INFO: roc 4 with ID = 4 has maximal Vcal 55.0308 for pixel 0/15 mean/min/max = 43.297/31.4549/55.1391
[17:03:47.950] <TB2> INFO: roc 5 with ID = 5 has maximal Vcal 59.1005 for pixel 0/4 mean/min/max = 46.6607/34.1593/59.1622
[17:03:47.950] <TB2> INFO: roc 6 with ID = 6 has maximal Vcal 57.58 for pixel 20/5 mean/min/max = 45.1009/32.1026/58.0992
[17:03:47.950] <TB2> INFO: roc 7 with ID = 7 has maximal Vcal 58.7368 for pixel 0/57 mean/min/max = 47.1188/35.4642/58.7734
[17:03:47.951] <TB2> INFO: roc 8 with ID = 8 has maximal Vcal 60.7717 for pixel 2/18 mean/min/max = 46.51/32.226/60.7941
[17:03:47.951] <TB2> INFO: roc 9 with ID = 9 has maximal Vcal 63.8658 for pixel 23/72 mean/min/max = 48.7993/33.6258/63.9727
[17:03:47.952] <TB2> INFO: roc 10 with ID = 10 has maximal Vcal 59.8673 for pixel 10/79 mean/min/max = 46.3564/32.7622/59.9506
[17:03:47.952] <TB2> INFO: roc 11 with ID = 11 has maximal Vcal 56.5059 for pixel 0/79 mean/min/max = 44.5235/32.5281/56.5188
[17:03:47.952] <TB2> INFO: roc 12 with ID = 12 has maximal Vcal 58.1374 for pixel 23/74 mean/min/max = 44.9779/31.6073/58.3484
[17:03:47.953] <TB2> INFO: roc 13 with ID = 13 has maximal Vcal 57.0065 for pixel 44/1 mean/min/max = 44.4494/31.8298/57.0689
[17:03:47.953] <TB2> INFO: roc 14 with ID = 14 has maximal Vcal 59.8174 for pixel 22/76 mean/min/max = 45.7058/31.5446/59.8671
[17:03:47.953] <TB2> INFO: roc 15 with ID = 15 has maximal Vcal 58.4026 for pixel 0/73 mean/min/max = 44.9206/31.4043/58.4369
[17:03:47.954] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:03:48.042] <TB2> INFO: Expecting 411648 events.
[17:03:57.244] <TB2> INFO: 411648 events read in total (8608ms).
[17:03:57.253] <TB2> INFO: Expecting 411648 events.
[17:04:06.251] <TB2> INFO: 411648 events read in total (8595ms).
[17:04:06.260] <TB2> INFO: Expecting 411648 events.
[17:04:15.239] <TB2> INFO: 411648 events read in total (8576ms).
[17:04:15.255] <TB2> INFO: Expecting 411648 events.
[17:04:24.299] <TB2> INFO: 411648 events read in total (8639ms).
[17:04:24.319] <TB2> INFO: Expecting 411648 events.
[17:04:33.358] <TB2> INFO: 411648 events read in total (8636ms).
[17:04:33.376] <TB2> INFO: Expecting 411648 events.
[17:04:42.400] <TB2> INFO: 411648 events read in total (8622ms).
[17:04:42.420] <TB2> INFO: Expecting 411648 events.
[17:04:51.424] <TB2> INFO: 411648 events read in total (8601ms).
[17:04:51.454] <TB2> INFO: Expecting 411648 events.
[17:05:00.456] <TB2> INFO: 411648 events read in total (8599ms).
[17:05:00.482] <TB2> INFO: Expecting 411648 events.
[17:05:09.559] <TB2> INFO: 411648 events read in total (8674ms).
[17:05:09.587] <TB2> INFO: Expecting 411648 events.
[17:05:18.572] <TB2> INFO: 411648 events read in total (8582ms).
[17:05:18.603] <TB2> INFO: Expecting 411648 events.
[17:05:27.614] <TB2> INFO: 411648 events read in total (8608ms).
[17:05:27.647] <TB2> INFO: Expecting 411648 events.
[17:05:36.687] <TB2> INFO: 411648 events read in total (8637ms).
[17:05:36.725] <TB2> INFO: Expecting 411648 events.
[17:05:45.754] <TB2> INFO: 411648 events read in total (8626ms).
[17:05:45.792] <TB2> INFO: Expecting 411648 events.
[17:05:54.900] <TB2> INFO: 411648 events read in total (8705ms).
[17:05:54.958] <TB2> INFO: Expecting 411648 events.
[17:06:04.013] <TB2> INFO: 411648 events read in total (8652ms).
[17:06:04.072] <TB2> INFO: Expecting 411648 events.
[17:06:13.102] <TB2> INFO: 411648 events read in total (8627ms).
[17:06:13.166] <TB2> INFO: Test took 145212ms.
[17:06:14.007] <TB2> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[17:06:14.019] <TB2> INFO: dacScan split into 1 runs with ntrig = 8
[17:06:14.019] <TB2> INFO: run 1 of 1
[17:06:14.281] <TB2> INFO: Expecting 5025280 events.
[17:06:40.201] <TB2> INFO: 581472 events read in total (25328ms).
[17:07:05.150] <TB2> INFO: 1161744 events read in total (50277ms).
[17:07:30.649] <TB2> INFO: 1742640 events read in total (75776ms).
[17:07:55.863] <TB2> INFO: 2323512 events read in total (100990ms).
[17:08:21.420] <TB2> INFO: 2903080 events read in total (126547ms).
[17:08:46.785] <TB2> INFO: 3481064 events read in total (151912ms).
[17:09:12.099] <TB2> INFO: 4058504 events read in total (177226ms).
[17:09:37.383] <TB2> INFO: 4635280 events read in total (202510ms).
[17:09:54.738] <TB2> INFO: 5025280 events read in total (219865ms).
[17:09:54.849] <TB2> INFO: Test took 220830ms.
[17:10:19.589] <TB2> INFO: ---> TrimStepCorr4 extremal thresholds: 11.562198 .. 147.161190
[17:10:19.823] <TB2> INFO: Expecting 208000 events.
[17:10:29.355] <TB2> INFO: 208000 events read in total (8941ms).
[17:10:29.356] <TB2> INFO: Test took 9766ms.
[17:10:29.402] <TB2> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 1 .. 157 (-1/-1) hits flags = 528 (plus default)
[17:10:29.412] <TB2> INFO: dacScan split into 1 runs with ntrig = 8
[17:10:29.412] <TB2> INFO: run 1 of 1
[17:10:29.690] <TB2> INFO: Expecting 5224960 events.
[17:10:55.543] <TB2> INFO: 584264 events read in total (25262ms).
[17:11:20.670] <TB2> INFO: 1167904 events read in total (50389ms).
[17:11:45.916] <TB2> INFO: 1751816 events read in total (75635ms).
[17:12:11.496] <TB2> INFO: 2335656 events read in total (101215ms).
[17:12:36.339] <TB2> INFO: 2919096 events read in total (126058ms).
[17:13:01.668] <TB2> INFO: 3501272 events read in total (151387ms).
[17:13:26.910] <TB2> INFO: 4082880 events read in total (176629ms).
[17:13:52.292] <TB2> INFO: 4664120 events read in total (202011ms).
[17:14:17.028] <TB2> INFO: 5224960 events read in total (226747ms).
[17:14:17.118] <TB2> INFO: Test took 227707ms.
[17:14:45.119] <TB2> INFO: ---> TrimStepCorr2 extremal thresholds: 25.049696 .. 42.930778
[17:14:45.369] <TB2> INFO: Expecting 208000 events.
[17:14:55.145] <TB2> INFO: 208000 events read in total (9186ms).
[17:14:55.146] <TB2> INFO: Test took 10027ms.
[17:14:55.198] <TB2> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 15 .. 52 (-1/-1) hits flags = 528 (plus default)
[17:14:55.209] <TB2> INFO: dacScan split into 1 runs with ntrig = 8
[17:14:55.209] <TB2> INFO: run 1 of 1
[17:14:55.487] <TB2> INFO: Expecting 1264640 events.
[17:15:24.200] <TB2> INFO: 680952 events read in total (28122ms).
[17:15:48.787] <TB2> INFO: 1264640 events read in total (52709ms).
[17:15:48.813] <TB2> INFO: Test took 53605ms.
[17:16:01.916] <TB2> INFO: ---> TrimStepCorr1a extremal thresholds: 21.188467 .. 46.231782
[17:16:02.151] <TB2> INFO: Expecting 208000 events.
[17:16:11.687] <TB2> INFO: 208000 events read in total (8945ms).
[17:16:11.688] <TB2> INFO: Test took 9770ms.
[17:16:11.733] <TB2> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 11 .. 56 (-1/-1) hits flags = 528 (plus default)
[17:16:11.745] <TB2> INFO: dacScan split into 1 runs with ntrig = 8
[17:16:11.745] <TB2> INFO: run 1 of 1
[17:16:12.023] <TB2> INFO: Expecting 1530880 events.
[17:16:39.771] <TB2> INFO: 678360 events read in total (27157ms).
[17:17:07.426] <TB2> INFO: 1355624 events read in total (54812ms).
[17:17:14.807] <TB2> INFO: 1530880 events read in total (62193ms).
[17:17:14.838] <TB2> INFO: Test took 63094ms.
[17:17:29.699] <TB2> INFO: ---> TrimStepCorr1b extremal thresholds: 24.967037 .. 43.551858
[17:17:29.932] <TB2> INFO: Expecting 208000 events.
[17:17:39.544] <TB2> INFO: 208000 events read in total (9020ms).
[17:17:39.544] <TB2> INFO: Test took 9844ms.
[17:17:39.591] <TB2> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 14 .. 53 (-1/-1) hits flags = 528 (plus default)
[17:17:39.601] <TB2> INFO: dacScan split into 1 runs with ntrig = 8
[17:17:39.601] <TB2> INFO: run 1 of 1
[17:17:39.879] <TB2> INFO: Expecting 1331200 events.
[17:18:07.710] <TB2> INFO: 679800 events read in total (27240ms).
[17:18:34.743] <TB2> INFO: 1331200 events read in total (54273ms).
[17:18:34.775] <TB2> INFO: Test took 55175ms.
[17:18:46.665] <TB2> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[17:18:46.665] <TB2> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[17:18:46.676] <TB2> INFO: dacScan split into 1 runs with ntrig = 8
[17:18:46.676] <TB2> INFO: run 1 of 1
[17:18:46.912] <TB2> INFO: Expecting 1364480 events.
[17:19:14.991] <TB2> INFO: 667392 events read in total (27488ms).
[17:19:43.107] <TB2> INFO: 1334392 events read in total (55604ms).
[17:19:44.795] <TB2> INFO: 1364480 events read in total (57293ms).
[17:19:44.817] <TB2> INFO: Test took 58140ms.
[17:19:56.838] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C0.dat
[17:19:56.838] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C1.dat
[17:19:56.838] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C2.dat
[17:19:56.838] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C3.dat
[17:19:56.838] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C4.dat
[17:19:56.838] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C5.dat
[17:19:56.838] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C6.dat
[17:19:56.839] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C7.dat
[17:19:56.839] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C8.dat
[17:19:56.839] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C9.dat
[17:19:56.839] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C10.dat
[17:19:56.839] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C11.dat
[17:19:56.839] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C12.dat
[17:19:56.839] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C13.dat
[17:19:56.839] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C14.dat
[17:19:56.839] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C15.dat
[17:19:56.839] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C0.dat
[17:19:56.845] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C1.dat
[17:19:56.850] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C2.dat
[17:19:56.856] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C3.dat
[17:19:56.861] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C4.dat
[17:19:56.867] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C5.dat
[17:19:56.873] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C6.dat
[17:19:56.878] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C7.dat
[17:19:56.884] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C8.dat
[17:19:56.890] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C9.dat
[17:19:56.895] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C10.dat
[17:19:56.901] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C11.dat
[17:19:56.906] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C12.dat
[17:19:56.912] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C13.dat
[17:19:56.917] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C14.dat
[17:19:56.923] <TB2> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//trimParameters35_C15.dat
[17:19:56.928] <TB2> INFO: PixTestTrim::trimTest() done
[17:19:56.928] <TB2> INFO: vtrim: 131 144 144 123 127 144 120 135 146 180 141 131 150 144 144 133
[17:19:56.928] <TB2> INFO: vthrcomp: 118 131 123 110 128 132 115 132 123 133 134 116 122 115 118 124
[17:19:56.928] <TB2> INFO: vcal mean: 34.99 34.96 34.94 34.98 34.99 35.03 34.95 35.01 34.97 34.99 34.94 34.95 34.99 34.89 34.96 34.94
[17:19:56.928] <TB2> INFO: vcal RMS: 1.01 0.99 0.92 0.84 0.92 0.99 0.95 0.92 1.11 1.12 1.05 0.91 1.10 1.05 1.14 1.09
[17:19:56.928] <TB2> INFO: bits mean: 10.28 10.53 10.28 9.73 10.40 9.21 10.05 8.60 10.11 9.38 9.56 9.94 10.60 10.43 10.23 9.87
[17:19:56.928] <TB2> INFO: bits RMS: 2.35 2.25 2.50 2.35 2.46 2.44 2.52 2.49 2.33 2.32 2.49 2.50 2.26 2.31 2.40 2.63
[17:19:56.935] <TB2> INFO: ----------------------------------------------------------------------
[17:19:56.935] <TB2> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[17:19:56.935] <TB2> INFO: ----------------------------------------------------------------------
[17:19:56.937] <TB2> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[17:19:56.949] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[17:19:56.949] <TB2> INFO: run 1 of 1
[17:19:57.207] <TB2> INFO: Expecting 4160000 events.
[17:20:28.439] <TB2> INFO: 723275 events read in total (30640ms).
[17:20:58.726] <TB2> INFO: 1440300 events read in total (60927ms).
[17:21:29.136] <TB2> INFO: 2155065 events read in total (91337ms).
[17:21:59.315] <TB2> INFO: 2864780 events read in total (121516ms).
[17:22:29.538] <TB2> INFO: 3573040 events read in total (151739ms).
[17:22:55.380] <TB2> INFO: 4160000 events read in total (177581ms).
[17:22:55.457] <TB2> INFO: Test took 178508ms.
[17:23:22.141] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[17:23:22.151] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[17:23:22.151] <TB2> INFO: run 1 of 1
[17:23:22.383] <TB2> INFO: Expecting 4139200 events.
[17:23:53.074] <TB2> INFO: 703450 events read in total (30099ms).
[17:24:23.004] <TB2> INFO: 1401605 events read in total (60029ms).
[17:24:52.831] <TB2> INFO: 2098345 events read in total (89856ms).
[17:25:22.698] <TB2> INFO: 2790745 events read in total (119723ms).
[17:25:52.658] <TB2> INFO: 3481950 events read in total (149683ms).
[17:26:21.384] <TB2> INFO: 4139200 events read in total (178409ms).
[17:26:21.460] <TB2> INFO: Test took 179308ms.
[17:26:51.965] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 187 (-1/-1) hits flags = 528 (plus default)
[17:26:51.976] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[17:26:51.976] <TB2> INFO: run 1 of 1
[17:26:52.228] <TB2> INFO: Expecting 3910400 events.
[17:27:23.458] <TB2> INFO: 716975 events read in total (30638ms).
[17:27:53.773] <TB2> INFO: 1428310 events read in total (60953ms).
[17:28:24.026] <TB2> INFO: 2137235 events read in total (91206ms).
[17:28:54.221] <TB2> INFO: 2842095 events read in total (121401ms).
[17:29:24.434] <TB2> INFO: 3545645 events read in total (151614ms).
[17:29:40.549] <TB2> INFO: 3910400 events read in total (167729ms).
[17:29:40.604] <TB2> INFO: Test took 168627ms.
[17:30:09.139] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 188 (-1/-1) hits flags = 528 (plus default)
[17:30:09.149] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[17:30:09.149] <TB2> INFO: run 1 of 1
[17:30:09.384] <TB2> INFO: Expecting 3931200 events.
[17:30:40.491] <TB2> INFO: 715505 events read in total (30516ms).
[17:31:10.920] <TB2> INFO: 1425525 events read in total (60945ms).
[17:31:41.604] <TB2> INFO: 2133380 events read in total (91629ms).
[17:32:11.927] <TB2> INFO: 2836770 events read in total (121952ms).
[17:32:42.341] <TB2> INFO: 3538955 events read in total (152366ms).
[17:32:59.479] <TB2> INFO: 3931200 events read in total (169504ms).
[17:32:59.530] <TB2> INFO: Test took 170381ms.
[17:33:26.431] <TB2> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 187 (-1/-1) hits flags = 528 (plus default)
[17:33:26.442] <TB2> INFO: dacScan split into 1 runs with ntrig = 5
[17:33:26.442] <TB2> INFO: run 1 of 1
[17:33:26.674] <TB2> INFO: Expecting 3910400 events.
[17:33:57.936] <TB2> INFO: 716825 events read in total (30670ms).
[17:34:28.563] <TB2> INFO: 1427900 events read in total (61297ms).
[17:34:59.117] <TB2> INFO: 2136735 events read in total (91851ms).
[17:35:29.216] <TB2> INFO: 2841585 events read in total (121950ms).
[17:35:59.211] <TB2> INFO: 3545330 events read in total (151945ms).
[17:36:15.600] <TB2> INFO: 3910400 events read in total (168334ms).
[17:36:15.650] <TB2> INFO: Test took 169207ms.
[17:36:42.741] <TB2> INFO: PixTestTrim::trimBitTest() done
[17:36:42.742] <TB2> INFO: PixTestTrim::doTest() done, duration: 2427 seconds
[17:36:42.742] <TB2> INFO: Decoding statistics:
[17:36:42.742] <TB2> INFO: General information:
[17:36:42.742] <TB2> INFO: 16bit words read: 0
[17:36:42.742] <TB2> INFO: valid events total: 0
[17:36:42.742] <TB2> INFO: empty events: 0
[17:36:42.742] <TB2> INFO: valid events with pixels: 0
[17:36:42.742] <TB2> INFO: valid pixel hits: 0
[17:36:42.742] <TB2> INFO: Event errors: 0
[17:36:42.742] <TB2> INFO: start marker: 0
[17:36:42.742] <TB2> INFO: stop marker: 0
[17:36:42.742] <TB2> INFO: overflow: 0
[17:36:42.742] <TB2> INFO: invalid 5bit words: 0
[17:36:42.742] <TB2> INFO: invalid XOR eye diagram: 0
[17:36:42.742] <TB2> INFO: frame (failed synchr.): 0
[17:36:42.742] <TB2> INFO: idle data (no TBM trl): 0
[17:36:42.742] <TB2> INFO: no data (only TBM hdr): 0
[17:36:42.742] <TB2> INFO: TBM errors: 0
[17:36:42.742] <TB2> INFO: flawed TBM headers: 0
[17:36:42.742] <TB2> INFO: flawed TBM trailers: 0
[17:36:42.742] <TB2> INFO: event ID mismatches: 0
[17:36:42.742] <TB2> INFO: ROC errors: 0
[17:36:42.742] <TB2> INFO: missing ROC header(s): 0
[17:36:42.742] <TB2> INFO: misplaced readback start: 0
[17:36:42.742] <TB2> INFO: Pixel decoding errors: 0
[17:36:42.742] <TB2> INFO: pixel data incomplete: 0
[17:36:42.742] <TB2> INFO: pixel address: 0
[17:36:42.742] <TB2> INFO: pulse height fill bit: 0
[17:36:42.742] <TB2> INFO: buffer corruption: 0
[17:36:43.365] <TB2> INFO: ######################################################################
[17:36:43.365] <TB2> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[17:36:43.365] <TB2> INFO: ######################################################################
[17:36:43.635] <TB2> INFO: Expecting 41600 events.
[17:36:47.057] <TB2> INFO: 41600 events read in total (2830ms).
[17:36:47.058] <TB2> INFO: Test took 3692ms.
[17:36:47.497] <TB2> INFO: Expecting 41600 events.
[17:36:50.937] <TB2> INFO: 41600 events read in total (2848ms).
[17:36:50.938] <TB2> INFO: Test took 3678ms.
[17:36:51.284] <TB2> INFO: Expecting 41600 events.
[17:36:54.746] <TB2> INFO: 41600 events read in total (2870ms).
[17:36:54.747] <TB2> INFO: Test took 3786ms.
[17:36:55.037] <TB2> INFO: Expecting 41600 events.
[17:36:58.558] <TB2> INFO: 41600 events read in total (2929ms).
[17:36:58.559] <TB2> INFO: Test took 3788ms.
[17:36:58.850] <TB2> INFO: Expecting 41600 events.
[17:37:02.296] <TB2> INFO: 41600 events read in total (2855ms).
[17:37:02.297] <TB2> INFO: Test took 3712ms.
[17:37:02.585] <TB2> INFO: Expecting 41600 events.
[17:37:06.118] <TB2> INFO: 41600 events read in total (2938ms).
[17:37:06.119] <TB2> INFO: Test took 3798ms.
[17:37:06.407] <TB2> INFO: Expecting 41600 events.
[17:37:09.924] <TB2> INFO: 41600 events read in total (2925ms).
[17:37:09.925] <TB2> INFO: Test took 3783ms.
[17:37:10.213] <TB2> INFO: Expecting 41600 events.
[17:37:13.766] <TB2> INFO: 41600 events read in total (2961ms).
[17:37:13.767] <TB2> INFO: Test took 3818ms.
[17:37:14.070] <TB2> INFO: Expecting 41600 events.
[17:37:17.798] <TB2> INFO: 41600 events read in total (3136ms).
[17:37:17.800] <TB2> INFO: Test took 4009ms.
[17:37:18.089] <TB2> INFO: Expecting 41600 events.
[17:37:21.552] <TB2> INFO: 41600 events read in total (2872ms).
[17:37:21.553] <TB2> INFO: Test took 3729ms.
[17:37:21.846] <TB2> INFO: Expecting 41600 events.
[17:37:25.370] <TB2> INFO: 41600 events read in total (2932ms).
[17:37:25.371] <TB2> INFO: Test took 3795ms.
[17:37:25.659] <TB2> INFO: Expecting 41600 events.
[17:37:29.173] <TB2> INFO: 41600 events read in total (2922ms).
[17:37:29.174] <TB2> INFO: Test took 3779ms.
[17:37:29.463] <TB2> INFO: Expecting 41600 events.
[17:37:32.986] <TB2> INFO: 41600 events read in total (2932ms).
[17:37:32.986] <TB2> INFO: Test took 3788ms.
[17:37:33.277] <TB2> INFO: Expecting 41600 events.
[17:37:36.786] <TB2> INFO: 41600 events read in total (2918ms).
[17:37:36.786] <TB2> INFO: Test took 3774ms.
[17:37:37.077] <TB2> INFO: Expecting 41600 events.
[17:37:40.699] <TB2> INFO: 41600 events read in total (3030ms).
[17:37:40.700] <TB2> INFO: Test took 3890ms.
[17:37:40.993] <TB2> INFO: Expecting 41600 events.
[17:37:44.511] <TB2> INFO: 41600 events read in total (2927ms).
[17:37:44.512] <TB2> INFO: Test took 3784ms.
[17:37:44.800] <TB2> INFO: Expecting 41600 events.
[17:37:48.234] <TB2> INFO: 41600 events read in total (2842ms).
[17:37:48.235] <TB2> INFO: Test took 3700ms.
[17:37:48.526] <TB2> INFO: Expecting 41600 events.
[17:37:52.065] <TB2> INFO: 41600 events read in total (2947ms).
[17:37:52.066] <TB2> INFO: Test took 3805ms.
[17:37:52.357] <TB2> INFO: Expecting 41600 events.
[17:37:55.846] <TB2> INFO: 41600 events read in total (2898ms).
[17:37:55.847] <TB2> INFO: Test took 3755ms.
[17:37:56.138] <TB2> INFO: Expecting 41600 events.
[17:37:59.784] <TB2> INFO: 41600 events read in total (3054ms).
[17:37:59.784] <TB2> INFO: Test took 3911ms.
[17:38:00.077] <TB2> INFO: Expecting 41600 events.
[17:38:03.598] <TB2> INFO: 41600 events read in total (2929ms).
[17:38:03.599] <TB2> INFO: Test took 3786ms.
[17:38:03.887] <TB2> INFO: Expecting 41600 events.
[17:38:07.356] <TB2> INFO: 41600 events read in total (2877ms).
[17:38:07.357] <TB2> INFO: Test took 3735ms.
[17:38:07.649] <TB2> INFO: Expecting 41600 events.
[17:38:11.165] <TB2> INFO: 41600 events read in total (2924ms).
[17:38:11.165] <TB2> INFO: Test took 3781ms.
[17:38:11.456] <TB2> INFO: Expecting 41600 events.
[17:38:15.004] <TB2> INFO: 41600 events read in total (2956ms).
[17:38:15.005] <TB2> INFO: Test took 3813ms.
[17:38:15.294] <TB2> INFO: Expecting 41600 events.
[17:38:18.755] <TB2> INFO: 41600 events read in total (2870ms).
[17:38:18.756] <TB2> INFO: Test took 3727ms.
[17:38:19.046] <TB2> INFO: Expecting 41600 events.
[17:38:22.574] <TB2> INFO: 41600 events read in total (2937ms).
[17:38:22.574] <TB2> INFO: Test took 3793ms.
[17:38:22.865] <TB2> INFO: Expecting 41600 events.
[17:38:26.387] <TB2> INFO: 41600 events read in total (2930ms).
[17:38:26.388] <TB2> INFO: Test took 3787ms.
[17:38:26.679] <TB2> INFO: Expecting 41600 events.
[17:38:30.174] <TB2> INFO: 41600 events read in total (2904ms).
[17:38:30.174] <TB2> INFO: Test took 3760ms.
[17:38:30.464] <TB2> INFO: Expecting 41600 events.
[17:38:33.997] <TB2> INFO: 41600 events read in total (2942ms).
[17:38:33.998] <TB2> INFO: Test took 3799ms.
[17:38:34.287] <TB2> INFO: Expecting 2560 events.
[17:38:35.173] <TB2> INFO: 2560 events read in total (294ms).
[17:38:35.173] <TB2> INFO: Test took 1163ms.
[17:38:35.481] <TB2> INFO: Expecting 2560 events.
[17:38:36.365] <TB2> INFO: 2560 events read in total (292ms).
[17:38:36.365] <TB2> INFO: Test took 1191ms.
[17:38:36.673] <TB2> INFO: Expecting 2560 events.
[17:38:37.557] <TB2> INFO: 2560 events read in total (293ms).
[17:38:37.557] <TB2> INFO: Test took 1191ms.
[17:38:37.865] <TB2> INFO: Expecting 2560 events.
[17:38:38.750] <TB2> INFO: 2560 events read in total (294ms).
[17:38:38.750] <TB2> INFO: Test took 1193ms.
[17:38:39.058] <TB2> INFO: Expecting 2560 events.
[17:38:39.937] <TB2> INFO: 2560 events read in total (288ms).
[17:38:39.937] <TB2> INFO: Test took 1187ms.
[17:38:40.245] <TB2> INFO: Expecting 2560 events.
[17:38:41.126] <TB2> INFO: 2560 events read in total (289ms).
[17:38:41.126] <TB2> INFO: Test took 1188ms.
[17:38:41.434] <TB2> INFO: Expecting 2560 events.
[17:38:42.314] <TB2> INFO: 2560 events read in total (288ms).
[17:38:42.314] <TB2> INFO: Test took 1187ms.
[17:38:42.622] <TB2> INFO: Expecting 2560 events.
[17:38:43.502] <TB2> INFO: 2560 events read in total (288ms).
[17:38:43.502] <TB2> INFO: Test took 1187ms.
[17:38:43.810] <TB2> INFO: Expecting 2560 events.
[17:38:44.689] <TB2> INFO: 2560 events read in total (287ms).
[17:38:44.689] <TB2> INFO: Test took 1187ms.
[17:38:44.997] <TB2> INFO: Expecting 2560 events.
[17:38:45.874] <TB2> INFO: 2560 events read in total (285ms).
[17:38:45.874] <TB2> INFO: Test took 1185ms.
[17:38:46.182] <TB2> INFO: Expecting 2560 events.
[17:38:47.062] <TB2> INFO: 2560 events read in total (289ms).
[17:38:47.062] <TB2> INFO: Test took 1187ms.
[17:38:47.370] <TB2> INFO: Expecting 2560 events.
[17:38:48.251] <TB2> INFO: 2560 events read in total (289ms).
[17:38:48.251] <TB2> INFO: Test took 1189ms.
[17:38:48.559] <TB2> INFO: Expecting 2560 events.
[17:38:49.442] <TB2> INFO: 2560 events read in total (291ms).
[17:38:49.442] <TB2> INFO: Test took 1190ms.
[17:38:49.749] <TB2> INFO: Expecting 2560 events.
[17:38:50.631] <TB2> INFO: 2560 events read in total (290ms).
[17:38:50.631] <TB2> INFO: Test took 1189ms.
[17:38:50.939] <TB2> INFO: Expecting 2560 events.
[17:38:51.823] <TB2> INFO: 2560 events read in total (292ms).
[17:38:51.823] <TB2> INFO: Test took 1191ms.
[17:38:52.131] <TB2> INFO: Expecting 2560 events.
[17:38:53.014] <TB2> INFO: 2560 events read in total (291ms).
[17:38:53.014] <TB2> INFO: Test took 1191ms.
[17:38:53.017] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:38:53.323] <TB2> INFO: Expecting 655360 events.
[17:39:07.585] <TB2> INFO: 655360 events read in total (13670ms).
[17:39:07.595] <TB2> INFO: Expecting 655360 events.
[17:39:21.590] <TB2> INFO: 655360 events read in total (13592ms).
[17:39:21.604] <TB2> INFO: Expecting 655360 events.
[17:39:35.575] <TB2> INFO: 655360 events read in total (13568ms).
[17:39:35.594] <TB2> INFO: Expecting 655360 events.
[17:39:49.601] <TB2> INFO: 655360 events read in total (13604ms).
[17:39:49.624] <TB2> INFO: Expecting 655360 events.
[17:40:03.573] <TB2> INFO: 655360 events read in total (13546ms).
[17:40:03.600] <TB2> INFO: Expecting 655360 events.
[17:40:17.603] <TB2> INFO: 655360 events read in total (13600ms).
[17:40:17.633] <TB2> INFO: Expecting 655360 events.
[17:40:31.674] <TB2> INFO: 655360 events read in total (13638ms).
[17:40:31.711] <TB2> INFO: Expecting 655360 events.
[17:40:45.849] <TB2> INFO: 655360 events read in total (13735ms).
[17:40:45.902] <TB2> INFO: Expecting 655360 events.
[17:40:59.954] <TB2> INFO: 655360 events read in total (13649ms).
[17:41:00.015] <TB2> INFO: Expecting 655360 events.
[17:41:13.982] <TB2> INFO: 655360 events read in total (13564ms).
[17:41:14.030] <TB2> INFO: Expecting 655360 events.
[17:41:27.988] <TB2> INFO: 655360 events read in total (13555ms).
[17:41:28.041] <TB2> INFO: Expecting 655360 events.
[17:41:42.046] <TB2> INFO: 655360 events read in total (13602ms).
[17:41:42.103] <TB2> INFO: Expecting 655360 events.
[17:41:56.099] <TB2> INFO: 655360 events read in total (13593ms).
[17:41:56.160] <TB2> INFO: Expecting 655360 events.
[17:42:10.153] <TB2> INFO: 655360 events read in total (13590ms).
[17:42:10.217] <TB2> INFO: Expecting 655360 events.
[17:42:24.232] <TB2> INFO: 655360 events read in total (13612ms).
[17:42:24.327] <TB2> INFO: Expecting 655360 events.
[17:42:38.380] <TB2> INFO: 655360 events read in total (13650ms).
[17:42:38.458] <TB2> INFO: Test took 225441ms.
[17:42:38.556] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:42:38.821] <TB2> INFO: Expecting 655360 events.
[17:42:52.613] <TB2> INFO: 655360 events read in total (13200ms).
[17:42:52.621] <TB2> INFO: Expecting 655360 events.
[17:43:06.505] <TB2> INFO: 655360 events read in total (13481ms).
[17:43:06.519] <TB2> INFO: Expecting 655360 events.
[17:43:20.608] <TB2> INFO: 655360 events read in total (13686ms).
[17:43:20.626] <TB2> INFO: Expecting 655360 events.
[17:43:34.688] <TB2> INFO: 655360 events read in total (13659ms).
[17:43:34.709] <TB2> INFO: Expecting 655360 events.
[17:43:48.663] <TB2> INFO: 655360 events read in total (13551ms).
[17:43:48.698] <TB2> INFO: Expecting 655360 events.
[17:44:02.535] <TB2> INFO: 655360 events read in total (13434ms).
[17:44:02.565] <TB2> INFO: Expecting 655360 events.
[17:44:16.541] <TB2> INFO: 655360 events read in total (13573ms).
[17:44:16.575] <TB2> INFO: Expecting 655360 events.
[17:44:30.535] <TB2> INFO: 655360 events read in total (13557ms).
[17:44:30.572] <TB2> INFO: Expecting 655360 events.
[17:44:44.508] <TB2> INFO: 655360 events read in total (13533ms).
[17:44:44.552] <TB2> INFO: Expecting 655360 events.
[17:44:58.415] <TB2> INFO: 655360 events read in total (13460ms).
[17:44:58.464] <TB2> INFO: Expecting 655360 events.
[17:45:12.476] <TB2> INFO: 655360 events read in total (13609ms).
[17:45:12.527] <TB2> INFO: Expecting 655360 events.
[17:45:26.434] <TB2> INFO: 655360 events read in total (13504ms).
[17:45:26.491] <TB2> INFO: Expecting 655360 events.
[17:45:40.301] <TB2> INFO: 655360 events read in total (13407ms).
[17:45:40.361] <TB2> INFO: Expecting 655360 events.
[17:45:54.297] <TB2> INFO: 655360 events read in total (13533ms).
[17:45:54.362] <TB2> INFO: Expecting 655360 events.
[17:46:07.992] <TB2> INFO: 655360 events read in total (13227ms).
[17:46:08.060] <TB2> INFO: Expecting 655360 events.
[17:46:22.057] <TB2> INFO: 655360 events read in total (13594ms).
[17:46:22.129] <TB2> INFO: Test took 223573ms.
[17:46:22.363] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.369] <TB2> INFO: safety margin for low PH: adding 1, margin is now 21
[17:46:22.376] <TB2> INFO: safety margin for low PH: adding 2, margin is now 22
[17:46:22.382] <TB2> INFO: safety margin for low PH: adding 3, margin is now 23
[17:46:22.389] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.395] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.401] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.408] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.414] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.420] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.427] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.433] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.440] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.446] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.452] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.459] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.465] <TB2> INFO: safety margin for low PH: adding 1, margin is now 21
[17:46:22.472] <TB2> INFO: safety margin for low PH: adding 2, margin is now 22
[17:46:22.478] <TB2> INFO: safety margin for low PH: adding 3, margin is now 23
[17:46:22.484] <TB2> INFO: safety margin for low PH: adding 4, margin is now 24
[17:46:22.491] <TB2> INFO: safety margin for low PH: adding 5, margin is now 25
[17:46:22.497] <TB2> INFO: safety margin for low PH: adding 6, margin is now 26
[17:46:22.504] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.510] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.517] <TB2> INFO: safety margin for low PH: adding 0, margin is now 20
[17:46:22.551] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C0.dat
[17:46:22.551] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C1.dat
[17:46:22.551] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C2.dat
[17:46:22.551] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C3.dat
[17:46:22.552] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C4.dat
[17:46:22.552] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C5.dat
[17:46:22.552] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C6.dat
[17:46:22.552] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C7.dat
[17:46:22.552] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C8.dat
[17:46:22.552] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C9.dat
[17:46:22.552] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C10.dat
[17:46:22.552] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C11.dat
[17:46:22.552] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C12.dat
[17:46:22.553] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C13.dat
[17:46:22.553] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C14.dat
[17:46:22.553] <TB2> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//dacParameters35_C15.dat
[17:46:22.791] <TB2> INFO: Expecting 41600 events.
[17:46:25.888] <TB2> INFO: 41600 events read in total (2505ms).
[17:46:25.889] <TB2> INFO: Test took 3334ms.
[17:46:26.378] <TB2> INFO: Expecting 41600 events.
[17:46:29.398] <TB2> INFO: 41600 events read in total (2428ms).
[17:46:29.399] <TB2> INFO: Test took 3297ms.
[17:46:29.886] <TB2> INFO: Expecting 41600 events.
[17:46:32.977] <TB2> INFO: 41600 events read in total (2499ms).
[17:46:32.978] <TB2> INFO: Test took 3368ms.
[17:46:33.193] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:33.282] <TB2> INFO: Expecting 2560 events.
[17:46:34.165] <TB2> INFO: 2560 events read in total (292ms).
[17:46:34.165] <TB2> INFO: Test took 972ms.
[17:46:34.167] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:34.474] <TB2> INFO: Expecting 2560 events.
[17:46:35.358] <TB2> INFO: 2560 events read in total (293ms).
[17:46:35.359] <TB2> INFO: Test took 1192ms.
[17:46:35.360] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:35.667] <TB2> INFO: Expecting 2560 events.
[17:46:36.550] <TB2> INFO: 2560 events read in total (292ms).
[17:46:36.550] <TB2> INFO: Test took 1190ms.
[17:46:36.552] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:36.858] <TB2> INFO: Expecting 2560 events.
[17:46:37.742] <TB2> INFO: 2560 events read in total (292ms).
[17:46:37.742] <TB2> INFO: Test took 1190ms.
[17:46:37.744] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:38.050] <TB2> INFO: Expecting 2560 events.
[17:46:38.934] <TB2> INFO: 2560 events read in total (291ms).
[17:46:38.934] <TB2> INFO: Test took 1190ms.
[17:46:38.936] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:39.242] <TB2> INFO: Expecting 2560 events.
[17:46:40.129] <TB2> INFO: 2560 events read in total (295ms).
[17:46:40.129] <TB2> INFO: Test took 1193ms.
[17:46:40.131] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:40.437] <TB2> INFO: Expecting 2560 events.
[17:46:41.321] <TB2> INFO: 2560 events read in total (292ms).
[17:46:41.321] <TB2> INFO: Test took 1190ms.
[17:46:41.322] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:41.629] <TB2> INFO: Expecting 2560 events.
[17:46:42.513] <TB2> INFO: 2560 events read in total (292ms).
[17:46:42.513] <TB2> INFO: Test took 1191ms.
[17:46:42.515] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:42.822] <TB2> INFO: Expecting 2560 events.
[17:46:43.701] <TB2> INFO: 2560 events read in total (288ms).
[17:46:43.701] <TB2> INFO: Test took 1186ms.
[17:46:43.704] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:44.009] <TB2> INFO: Expecting 2560 events.
[17:46:44.887] <TB2> INFO: 2560 events read in total (286ms).
[17:46:44.888] <TB2> INFO: Test took 1184ms.
[17:46:44.889] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:45.196] <TB2> INFO: Expecting 2560 events.
[17:46:46.078] <TB2> INFO: 2560 events read in total (290ms).
[17:46:46.078] <TB2> INFO: Test took 1189ms.
[17:46:46.079] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:46.386] <TB2> INFO: Expecting 2560 events.
[17:46:47.267] <TB2> INFO: 2560 events read in total (289ms).
[17:46:47.267] <TB2> INFO: Test took 1188ms.
[17:46:47.269] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:47.576] <TB2> INFO: Expecting 2560 events.
[17:46:48.454] <TB2> INFO: 2560 events read in total (286ms).
[17:46:48.455] <TB2> INFO: Test took 1186ms.
[17:46:48.456] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:48.762] <TB2> INFO: Expecting 2560 events.
[17:46:49.645] <TB2> INFO: 2560 events read in total (291ms).
[17:46:49.645] <TB2> INFO: Test took 1189ms.
[17:46:49.647] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:49.953] <TB2> INFO: Expecting 2560 events.
[17:46:50.831] <TB2> INFO: 2560 events read in total (286ms).
[17:46:50.832] <TB2> INFO: Test took 1185ms.
[17:46:50.833] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:51.140] <TB2> INFO: Expecting 2560 events.
[17:46:52.018] <TB2> INFO: 2560 events read in total (287ms).
[17:46:52.018] <TB2> INFO: Test took 1185ms.
[17:46:52.020] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:52.327] <TB2> INFO: Expecting 2560 events.
[17:46:53.207] <TB2> INFO: 2560 events read in total (289ms).
[17:46:53.208] <TB2> INFO: Test took 1188ms.
[17:46:53.209] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:53.516] <TB2> INFO: Expecting 2560 events.
[17:46:54.396] <TB2> INFO: 2560 events read in total (289ms).
[17:46:54.397] <TB2> INFO: Test took 1188ms.
[17:46:54.398] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:54.705] <TB2> INFO: Expecting 2560 events.
[17:46:55.585] <TB2> INFO: 2560 events read in total (288ms).
[17:46:55.585] <TB2> INFO: Test took 1187ms.
[17:46:55.587] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:55.893] <TB2> INFO: Expecting 2560 events.
[17:46:56.771] <TB2> INFO: 2560 events read in total (286ms).
[17:46:56.771] <TB2> INFO: Test took 1184ms.
[17:46:56.773] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:57.079] <TB2> INFO: Expecting 2560 events.
[17:46:57.957] <TB2> INFO: 2560 events read in total (286ms).
[17:46:57.957] <TB2> INFO: Test took 1185ms.
[17:46:57.959] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:58.266] <TB2> INFO: Expecting 2560 events.
[17:46:59.145] <TB2> INFO: 2560 events read in total (288ms).
[17:46:59.145] <TB2> INFO: Test took 1186ms.
[17:46:59.147] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:46:59.453] <TB2> INFO: Expecting 2560 events.
[17:47:00.335] <TB2> INFO: 2560 events read in total (290ms).
[17:47:00.335] <TB2> INFO: Test took 1188ms.
[17:47:00.337] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:47:00.643] <TB2> INFO: Expecting 2560 events.
[17:47:01.520] <TB2> INFO: 2560 events read in total (285ms).
[17:47:01.521] <TB2> INFO: Test took 1184ms.
[17:47:01.522] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:47:01.829] <TB2> INFO: Expecting 2560 events.
[17:47:02.715] <TB2> INFO: 2560 events read in total (295ms).
[17:47:02.716] <TB2> INFO: Test took 1194ms.
[17:47:02.717] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:47:03.024] <TB2> INFO: Expecting 2560 events.
[17:47:03.907] <TB2> INFO: 2560 events read in total (292ms).
[17:47:03.907] <TB2> INFO: Test took 1190ms.
[17:47:03.909] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:47:04.215] <TB2> INFO: Expecting 2560 events.
[17:47:05.098] <TB2> INFO: 2560 events read in total (291ms).
[17:47:05.098] <TB2> INFO: Test took 1189ms.
[17:47:05.100] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:47:05.407] <TB2> INFO: Expecting 2560 events.
[17:47:06.290] <TB2> INFO: 2560 events read in total (292ms).
[17:47:06.290] <TB2> INFO: Test took 1190ms.
[17:47:06.292] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:47:06.599] <TB2> INFO: Expecting 2560 events.
[17:47:07.482] <TB2> INFO: 2560 events read in total (292ms).
[17:47:07.482] <TB2> INFO: Test took 1190ms.
[17:47:07.484] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:47:07.791] <TB2> INFO: Expecting 2560 events.
[17:47:08.673] <TB2> INFO: 2560 events read in total (291ms).
[17:47:08.673] <TB2> INFO: Test took 1189ms.
[17:47:08.675] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:47:08.982] <TB2> INFO: Expecting 2560 events.
[17:47:09.864] <TB2> INFO: 2560 events read in total (291ms).
[17:47:09.864] <TB2> INFO: Test took 1189ms.
[17:47:09.867] <TB2> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:47:10.173] <TB2> INFO: Expecting 2560 events.
[17:47:11.055] <TB2> INFO: 2560 events read in total (291ms).
[17:47:11.055] <TB2> INFO: Test took 1188ms.
[17:47:11.517] <TB2> INFO: PixTestPhOptimization::doTest() done, duration: 628 seconds
[17:47:11.517] <TB2> INFO: PH scale (per ROC): 61 54 67 39 58 58 64 65 51 51 38 49 48 51 52 58
[17:47:11.517] <TB2> INFO: PH offset (per ROC): 121 114 114 99 130 109 118 119 107 110 95 101 114 112 120 115
[17:47:11.522] <TB2> INFO: Decoding statistics:
[17:47:11.522] <TB2> INFO: General information:
[17:47:11.522] <TB2> INFO: 16bit words read: 127886
[17:47:11.522] <TB2> INFO: valid events total: 20480
[17:47:11.522] <TB2> INFO: empty events: 17977
[17:47:11.522] <TB2> INFO: valid events with pixels: 2503
[17:47:11.522] <TB2> INFO: valid pixel hits: 2503
[17:47:11.522] <TB2> INFO: Event errors: 0
[17:47:11.522] <TB2> INFO: start marker: 0
[17:47:11.522] <TB2> INFO: stop marker: 0
[17:47:11.522] <TB2> INFO: overflow: 0
[17:47:11.522] <TB2> INFO: invalid 5bit words: 0
[17:47:11.522] <TB2> INFO: invalid XOR eye diagram: 0
[17:47:11.522] <TB2> INFO: frame (failed synchr.): 0
[17:47:11.522] <TB2> INFO: idle data (no TBM trl): 0
[17:47:11.522] <TB2> INFO: no data (only TBM hdr): 0
[17:47:11.522] <TB2> INFO: TBM errors: 0
[17:47:11.522] <TB2> INFO: flawed TBM headers: 0
[17:47:11.522] <TB2> INFO: flawed TBM trailers: 0
[17:47:11.522] <TB2> INFO: event ID mismatches: 0
[17:47:11.522] <TB2> INFO: ROC errors: 0
[17:47:11.522] <TB2> INFO: missing ROC header(s): 0
[17:47:11.522] <TB2> INFO: misplaced readback start: 0
[17:47:11.522] <TB2> INFO: Pixel decoding errors: 0
[17:47:11.522] <TB2> INFO: pixel data incomplete: 0
[17:47:11.522] <TB2> INFO: pixel address: 0
[17:47:11.522] <TB2> INFO: pulse height fill bit: 0
[17:47:11.523] <TB2> INFO: buffer corruption: 0
[17:47:11.789] <TB2> INFO: ######################################################################
[17:47:11.789] <TB2> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[17:47:11.789] <TB2> INFO: ######################################################################
[17:47:11.802] <TB2> INFO: scanning low vcal = 10
[17:47:12.036] <TB2> INFO: Expecting 41600 events.
[17:47:15.626] <TB2> INFO: 41600 events read in total (2999ms).
[17:47:15.626] <TB2> INFO: Test took 3823ms.
[17:47:15.628] <TB2> INFO: scanning low vcal = 20
[17:47:15.924] <TB2> INFO: Expecting 41600 events.
[17:47:19.485] <TB2> INFO: 41600 events read in total (2969ms).
[17:47:19.486] <TB2> INFO: Test took 3858ms.
[17:47:19.487] <TB2> INFO: scanning low vcal = 30
[17:47:19.783] <TB2> INFO: Expecting 41600 events.
[17:47:23.392] <TB2> INFO: 41600 events read in total (3017ms).
[17:47:23.393] <TB2> INFO: Test took 3906ms.
[17:47:23.395] <TB2> INFO: scanning low vcal = 40
[17:47:23.674] <TB2> INFO: Expecting 41600 events.
[17:47:27.626] <TB2> INFO: 41600 events read in total (3360ms).
[17:47:27.627] <TB2> INFO: Test took 4232ms.
[17:47:27.630] <TB2> INFO: scanning low vcal = 50
[17:47:27.907] <TB2> INFO: Expecting 41600 events.
[17:47:31.881] <TB2> INFO: 41600 events read in total (3383ms).
[17:47:31.881] <TB2> INFO: Test took 4251ms.
[17:47:31.884] <TB2> INFO: scanning low vcal = 60
[17:47:32.160] <TB2> INFO: Expecting 41600 events.
[17:47:36.113] <TB2> INFO: 41600 events read in total (3361ms).
[17:47:36.113] <TB2> INFO: Test took 4229ms.
[17:47:36.116] <TB2> INFO: scanning low vcal = 70
[17:47:36.393] <TB2> INFO: Expecting 41600 events.
[17:47:40.351] <TB2> INFO: 41600 events read in total (3367ms).
[17:47:40.351] <TB2> INFO: Test took 4235ms.
[17:47:40.354] <TB2> INFO: scanning low vcal = 80
[17:47:40.631] <TB2> INFO: Expecting 41600 events.
[17:47:44.588] <TB2> INFO: 41600 events read in total (3366ms).
[17:47:44.589] <TB2> INFO: Test took 4235ms.
[17:47:44.592] <TB2> INFO: scanning low vcal = 90
[17:47:44.868] <TB2> INFO: Expecting 41600 events.
[17:47:48.848] <TB2> INFO: 41600 events read in total (3388ms).
[17:47:48.849] <TB2> INFO: Test took 4257ms.
[17:47:48.851] <TB2> INFO: scanning low vcal = 100
[17:47:49.128] <TB2> INFO: Expecting 41600 events.
[17:47:53.075] <TB2> INFO: 41600 events read in total (3355ms).
[17:47:53.076] <TB2> INFO: Test took 4225ms.
[17:47:53.079] <TB2> INFO: scanning low vcal = 110
[17:47:53.355] <TB2> INFO: Expecting 41600 events.
[17:47:57.361] <TB2> INFO: 41600 events read in total (3414ms).
[17:47:57.362] <TB2> INFO: Test took 4283ms.
[17:47:57.364] <TB2> INFO: scanning low vcal = 120
[17:47:57.641] <TB2> INFO: Expecting 41600 events.
[17:48:01.613] <TB2> INFO: 41600 events read in total (3381ms).
[17:48:01.614] <TB2> INFO: Test took 4250ms.
[17:48:01.616] <TB2> INFO: scanning low vcal = 130
[17:48:01.893] <TB2> INFO: Expecting 41600 events.
[17:48:05.891] <TB2> INFO: 41600 events read in total (3406ms).
[17:48:05.891] <TB2> INFO: Test took 4275ms.
[17:48:05.894] <TB2> INFO: scanning low vcal = 140
[17:48:06.171] <TB2> INFO: Expecting 41600 events.
[17:48:10.173] <TB2> INFO: 41600 events read in total (3411ms).
[17:48:10.174] <TB2> INFO: Test took 4280ms.
[17:48:10.176] <TB2> INFO: scanning low vcal = 150
[17:48:10.453] <TB2> INFO: Expecting 41600 events.
[17:48:14.500] <TB2> INFO: 41600 events read in total (3456ms).
[17:48:14.501] <TB2> INFO: Test took 4325ms.
[17:48:14.504] <TB2> INFO: scanning low vcal = 160
[17:48:14.795] <TB2> INFO: Expecting 41600 events.
[17:48:18.769] <TB2> INFO: 41600 events read in total (3382ms).
[17:48:18.769] <TB2> INFO: Test took 4265ms.
[17:48:18.772] <TB2> INFO: scanning low vcal = 170
[17:48:19.048] <TB2> INFO: Expecting 41600 events.
[17:48:23.023] <TB2> INFO: 41600 events read in total (3383ms).
[17:48:23.024] <TB2> INFO: Test took 4252ms.
[17:48:23.026] <TB2> INFO: scanning low vcal = 180
[17:48:23.322] <TB2> INFO: Expecting 41600 events.
[17:48:27.302] <TB2> INFO: 41600 events read in total (3388ms).
[17:48:27.303] <TB2> INFO: Test took 4276ms.
[17:48:27.305] <TB2> INFO: scanning low vcal = 190
[17:48:27.603] <TB2> INFO: Expecting 41600 events.
[17:48:31.607] <TB2> INFO: 41600 events read in total (3413ms).
[17:48:31.608] <TB2> INFO: Test took 4303ms.
[17:48:31.611] <TB2> INFO: scanning low vcal = 200
[17:48:31.905] <TB2> INFO: Expecting 41600 events.
[17:48:35.957] <TB2> INFO: 41600 events read in total (3461ms).
[17:48:35.957] <TB2> INFO: Test took 4346ms.
[17:48:35.960] <TB2> INFO: scanning low vcal = 210
[17:48:36.237] <TB2> INFO: Expecting 41600 events.
[17:48:40.260] <TB2> INFO: 41600 events read in total (3432ms).
[17:48:40.261] <TB2> INFO: Test took 4301ms.
[17:48:40.264] <TB2> INFO: scanning low vcal = 220
[17:48:40.541] <TB2> INFO: Expecting 41600 events.
[17:48:44.568] <TB2> INFO: 41600 events read in total (3436ms).
[17:48:44.569] <TB2> INFO: Test took 4305ms.
[17:48:44.572] <TB2> INFO: scanning low vcal = 230
[17:48:44.868] <TB2> INFO: Expecting 41600 events.
[17:48:48.900] <TB2> INFO: 41600 events read in total (3440ms).
[17:48:48.901] <TB2> INFO: Test took 4329ms.
[17:48:48.903] <TB2> INFO: scanning low vcal = 240
[17:48:49.180] <TB2> INFO: Expecting 41600 events.
[17:48:53.203] <TB2> INFO: 41600 events read in total (3431ms).
[17:48:53.204] <TB2> INFO: Test took 4300ms.
[17:48:53.207] <TB2> INFO: scanning low vcal = 250
[17:48:53.500] <TB2> INFO: Expecting 41600 events.
[17:48:57.552] <TB2> INFO: 41600 events read in total (3461ms).
[17:48:57.552] <TB2> INFO: Test took 4345ms.
[17:48:57.556] <TB2> INFO: scanning high vcal = 30 (= 210 in low range)
[17:48:57.839] <TB2> INFO: Expecting 41600 events.
[17:49:01.822] <TB2> INFO: 41600 events read in total (3391ms).
[17:49:01.823] <TB2> INFO: Test took 4267ms.
[17:49:01.825] <TB2> INFO: scanning high vcal = 50 (= 350 in low range)
[17:49:02.102] <TB2> INFO: Expecting 41600 events.
[17:49:06.081] <TB2> INFO: 41600 events read in total (3388ms).
[17:49:06.082] <TB2> INFO: Test took 4257ms.
[17:49:06.085] <TB2> INFO: scanning high vcal = 70 (= 490 in low range)
[17:49:06.378] <TB2> INFO: Expecting 41600 events.
[17:49:10.354] <TB2> INFO: 41600 events read in total (3384ms).
[17:49:10.355] <TB2> INFO: Test took 4270ms.
[17:49:10.358] <TB2> INFO: scanning high vcal = 90 (= 630 in low range)
[17:49:10.634] <TB2> INFO: Expecting 41600 events.
[17:49:14.608] <TB2> INFO: 41600 events read in total (3382ms).
[17:49:14.609] <TB2> INFO: Test took 4251ms.
[17:49:14.611] <TB2> INFO: scanning high vcal = 200 (= 1400 in low range)
[17:49:14.888] <TB2> INFO: Expecting 41600 events.
[17:49:18.891] <TB2> INFO: 41600 events read in total (3412ms).
[17:49:18.892] <TB2> INFO: Test took 4281ms.
[17:49:19.492] <TB2> INFO: PixTestGainPedestal::measure() done
[17:49:53.756] <TB2> INFO: PixTestGainPedestal::fit() done
[17:49:53.756] <TB2> INFO: non-linearity mean: 0.983 0.949 0.980 0.911 0.976 0.948 0.984 0.983 0.955 0.932 0.900 0.914 0.946 0.950 0.978 0.980
[17:49:53.756] <TB2> INFO: non-linearity RMS: 0.004 0.048 0.004 0.167 0.007 0.042 0.005 0.002 0.039 0.084 0.126 0.156 0.047 0.052 0.003 0.003
[17:49:53.756] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[17:49:53.770] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[17:49:53.784] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[17:49:53.797] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[17:49:53.811] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[17:49:53.824] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[17:49:53.838] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[17:49:53.851] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[17:49:53.865] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[17:49:53.878] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[17:49:53.892] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[17:49:53.906] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[17:49:53.920] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[17:49:53.934] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[17:49:53.947] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[17:49:53.961] <TB2> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1114_FullQualification_2016-11-02_15h29m_1478096993//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[17:49:53.975] <TB2> INFO: PixTestGainPedestal::fullTest() done, duration: 162 seconds
[17:49:53.975] <TB2> INFO: Decoding statistics:
[17:49:53.975] <TB2> INFO: General information:
[17:49:53.975] <TB2> INFO: 16bit words read: 3327956
[17:49:53.975] <TB2> INFO: valid events total: 332800
[17:49:53.975] <TB2> INFO: empty events: 0
[17:49:53.975] <TB2> INFO: valid events with pixels: 332800
[17:49:53.975] <TB2> INFO: valid pixel hits: 665578
[17:49:53.975] <TB2> INFO: Event errors: 0
[17:49:53.975] <TB2> INFO: start marker: 0
[17:49:53.975] <TB2> INFO: stop marker: 0
[17:49:53.975] <TB2> INFO: overflow: 0
[17:49:53.975] <TB2> INFO: invalid 5bit words: 0
[17:49:53.975] <TB2> INFO: invalid XOR eye diagram: 0
[17:49:53.975] <TB2> INFO: frame (failed synchr.): 0
[17:49:53.975] <TB2> INFO: idle data (no TBM trl): 0
[17:49:53.975] <TB2> INFO: no data (only TBM hdr): 0
[17:49:53.975] <TB2> INFO: TBM errors: 0
[17:49:53.975] <TB2> INFO: flawed TBM headers: 0
[17:49:53.975] <TB2> INFO: flawed TBM trailers: 0
[17:49:53.975] <TB2> INFO: event ID mismatches: 0
[17:49:53.975] <TB2> INFO: ROC errors: 0
[17:49:53.975] <TB2> INFO: missing ROC header(s): 0
[17:49:53.975] <TB2> INFO: misplaced readback start: 0
[17:49:53.975] <TB2> INFO: Pixel decoding errors: 0
[17:49:53.975] <TB2> INFO: pixel data incomplete: 0
[17:49:53.975] <TB2> INFO: pixel address: 0
[17:49:53.975] <TB2> INFO: pulse height fill bit: 0
[17:49:53.975] <TB2> INFO: buffer corruption: 0
[17:49:53.990] <TB2> INFO: Decoding statistics:
[17:49:53.990] <TB2> INFO: General information:
[17:49:53.990] <TB2> INFO: 16bit words read: 3457378
[17:49:53.990] <TB2> INFO: valid events total: 353536
[17:49:53.990] <TB2> INFO: empty events: 18233
[17:49:53.990] <TB2> INFO: valid events with pixels: 335303
[17:49:53.990] <TB2> INFO: valid pixel hits: 668081
[17:49:53.990] <TB2> INFO: Event errors: 0
[17:49:53.990] <TB2> INFO: start marker: 0
[17:49:53.990] <TB2> INFO: stop marker: 0
[17:49:53.990] <TB2> INFO: overflow: 0
[17:49:53.990] <TB2> INFO: invalid 5bit words: 0
[17:49:53.990] <TB2> INFO: invalid XOR eye diagram: 0
[17:49:53.990] <TB2> INFO: frame (failed synchr.): 0
[17:49:53.990] <TB2> INFO: idle data (no TBM trl): 0
[17:49:53.990] <TB2> INFO: no data (only TBM hdr): 0
[17:49:53.990] <TB2> INFO: TBM errors: 0
[17:49:53.990] <TB2> INFO: flawed TBM headers: 0
[17:49:53.990] <TB2> INFO: flawed TBM trailers: 0
[17:49:53.990] <TB2> INFO: event ID mismatches: 0
[17:49:53.990] <TB2> INFO: ROC errors: 0
[17:49:53.990] <TB2> INFO: missing ROC header(s): 0
[17:49:53.990] <TB2> INFO: misplaced readback start: 0
[17:49:53.990] <TB2> INFO: Pixel decoding errors: 0
[17:49:53.990] <TB2> INFO: pixel data incomplete: 0
[17:49:53.990] <TB2> INFO: pixel address: 0
[17:49:53.990] <TB2> INFO: pulse height fill bit: 0
[17:49:53.990] <TB2> INFO: buffer corruption: 0
[17:49:53.990] <TB2> INFO: enter test to run
[17:49:53.990] <TB2> INFO: test: exit no parameter change
[17:49:54.037] <TB2> QUIET: Connection to board 156 closed.
[17:49:54.038] <TB2> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud