Test Date: 2016-11-07 11:20
Analysis date: 2016-11-15 13:43
Logfile
LogfileView
[13:58:41.954] <TB1> INFO: *** Welcome to pxar ***
[13:58:41.954] <TB1> INFO: *** Today: 2016/11/07
[13:58:41.961] <TB1> INFO: *** Version: c8ba-dirty
[13:58:41.961] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C15.dat
[13:58:41.961] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[13:58:41.961] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//defaultMaskFile.dat
[13:58:41.961] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters_C15.dat
[13:58:42.015] <TB1> INFO: clk: 4
[13:58:42.015] <TB1> INFO: ctr: 4
[13:58:42.015] <TB1> INFO: sda: 19
[13:58:42.015] <TB1> INFO: tin: 9
[13:58:42.015] <TB1> INFO: level: 15
[13:58:42.015] <TB1> INFO: triggerdelay: 0
[13:58:42.015] <TB1> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[13:58:42.015] <TB1> INFO: Log level: INFO
[13:58:42.024] <TB1> INFO: Found DTB DTB_WXBYFL
[13:58:42.034] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[13:58:42.036] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[13:58:42.037] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[13:58:43.522] <TB1> INFO: DUT info:
[13:58:43.522] <TB1> INFO: The DUT currently contains the following objects:
[13:58:43.522] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[13:58:43.522] <TB1> INFO: TBM Core alpha (0): 7 registers set
[13:58:43.522] <TB1> INFO: TBM Core beta (1): 7 registers set
[13:58:43.522] <TB1> INFO: TBM Core alpha (2): 7 registers set
[13:58:43.522] <TB1> INFO: TBM Core beta (3): 7 registers set
[13:58:43.522] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[13:58:43.522] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.522] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:58:43.923] <TB1> INFO: enter 'restricted' command line mode
[13:58:43.923] <TB1> INFO: enter test to run
[13:58:43.923] <TB1> INFO: test: pretest no parameter change
[13:58:43.923] <TB1> INFO: running: pretest
[13:58:44.469] <TB1> INFO: ######################################################################
[13:58:44.469] <TB1> INFO: PixTestPretest::doTest()
[13:58:44.469] <TB1> INFO: ######################################################################
[13:58:44.470] <TB1> INFO: ----------------------------------------------------------------------
[13:58:44.470] <TB1> INFO: PixTestPretest::programROC()
[13:58:44.470] <TB1> INFO: ----------------------------------------------------------------------
[13:59:02.483] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[13:59:02.483] <TB1> INFO: IA differences per ROC: 19.3 18.5 19.3 21.7 19.3 20.1 18.5 17.7 19.3 17.7 18.5 19.3 20.9 18.5 18.5 20.9
[13:59:02.518] <TB1> INFO: ----------------------------------------------------------------------
[13:59:02.518] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[13:59:02.518] <TB1> INFO: ----------------------------------------------------------------------
[13:59:09.395] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 381.9 mA = 23.8688 mA/ROC
[13:59:09.395] <TB1> INFO: i(loss) [mA/ROC]: 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5 19.3 18.5 18.5 18.5 18.5 19.3 18.5
[13:59:09.423] <TB1> INFO: ----------------------------------------------------------------------
[13:59:09.423] <TB1> INFO: PixTestPretest::findTiming()
[13:59:09.423] <TB1> INFO: ----------------------------------------------------------------------
[13:59:09.423] <TB1> INFO: PixTestCmd::init()
[13:59:09.975] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[13:59:40.594] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[13:59:40.594] <TB1> INFO: (success/tries = 100/100), width = 3
[13:59:42.092] <TB1> INFO: ----------------------------------------------------------------------
[13:59:42.092] <TB1> INFO: PixTestPretest::findWorkingPixel()
[13:59:42.092] <TB1> INFO: ----------------------------------------------------------------------
[13:59:42.183] <TB1> INFO: Expecting 231680 events.
[13:59:51.782] <TB1> INFO: 231680 events read in total (9007ms).
[13:59:51.789] <TB1> INFO: Test took 9695ms.
[13:59:52.034] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[13:59:52.066] <TB1> INFO: ----------------------------------------------------------------------
[13:59:52.066] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[13:59:52.066] <TB1> INFO: ----------------------------------------------------------------------
[13:59:52.158] <TB1> INFO: Expecting 231680 events.
[14:00:01.809] <TB1> INFO: 231680 events read in total (9059ms).
[14:00:01.817] <TB1> INFO: Test took 9747ms.
[14:00:02.073] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[14:00:02.073] <TB1> INFO: CalDel: 97 119 94 120 91 118 129 113 102 93 90 85 83 83 96 94
[14:00:02.073] <TB1> INFO: VthrComp: 51 51 52 57 52 51 51 51 51 51 57 51 51 51 51 56
[14:00:02.076] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C0.dat
[14:00:02.076] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C1.dat
[14:00:02.076] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C2.dat
[14:00:02.076] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C3.dat
[14:00:02.076] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C4.dat
[14:00:02.076] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C5.dat
[14:00:02.076] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C6.dat
[14:00:02.077] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C7.dat
[14:00:02.077] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C8.dat
[14:00:02.077] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C9.dat
[14:00:02.077] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C10.dat
[14:00:02.077] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C11.dat
[14:00:02.077] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C12.dat
[14:00:02.077] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C13.dat
[14:00:02.077] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C14.dat
[14:00:02.077] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters_C15.dat
[14:00:02.078] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//tbmParameters_C0a.dat
[14:00:02.078] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//tbmParameters_C0b.dat
[14:00:02.078] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//tbmParameters_C1a.dat
[14:00:02.078] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[14:00:02.078] <TB1> INFO: PixTestPretest::doTest() done, duration: 78 seconds
[14:00:02.174] <TB1> INFO: enter test to run
[14:00:02.174] <TB1> INFO: test: fulltest no parameter change
[14:00:02.174] <TB1> INFO: running: fulltest
[14:00:02.174] <TB1> INFO: ######################################################################
[14:00:02.174] <TB1> INFO: PixTestFullTest::doTest()
[14:00:02.174] <TB1> INFO: ######################################################################
[14:00:02.175] <TB1> INFO: ######################################################################
[14:00:02.175] <TB1> INFO: PixTestAlive::doTest()
[14:00:02.175] <TB1> INFO: ######################################################################
[14:00:02.176] <TB1> INFO: ----------------------------------------------------------------------
[14:00:02.176] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:00:02.176] <TB1> INFO: ----------------------------------------------------------------------
[14:00:02.412] <TB1> INFO: Expecting 41600 events.
[14:00:05.917] <TB1> INFO: 41600 events read in total (2913ms).
[14:00:05.918] <TB1> INFO: Test took 3740ms.
[14:00:06.143] <TB1> INFO: PixTestAlive::aliveTest() done
[14:00:06.144] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 1 1 1 0 0 0 0 0
[14:00:06.145] <TB1> INFO: ----------------------------------------------------------------------
[14:00:06.145] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:00:06.145] <TB1> INFO: ----------------------------------------------------------------------
[14:00:06.395] <TB1> INFO: Expecting 41600 events.
[14:00:09.320] <TB1> INFO: 41600 events read in total (2334ms).
[14:00:09.320] <TB1> INFO: Test took 3174ms.
[14:00:09.321] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[14:00:09.558] <TB1> INFO: PixTestAlive::maskTest() done
[14:00:09.558] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:00:09.559] <TB1> INFO: ----------------------------------------------------------------------
[14:00:09.559] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:00:09.559] <TB1> INFO: ----------------------------------------------------------------------
[14:00:09.797] <TB1> INFO: Expecting 41600 events.
[14:00:13.301] <TB1> INFO: 41600 events read in total (2912ms).
[14:00:13.302] <TB1> INFO: Test took 3742ms.
[14:00:13.529] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[14:00:13.529] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:00:13.529] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[14:00:13.529] <TB1> INFO: Decoding statistics:
[14:00:13.529] <TB1> INFO: General information:
[14:00:13.529] <TB1> INFO: 16bit words read: 0
[14:00:13.529] <TB1> INFO: valid events total: 0
[14:00:13.529] <TB1> INFO: empty events: 0
[14:00:13.529] <TB1> INFO: valid events with pixels: 0
[14:00:13.529] <TB1> INFO: valid pixel hits: 0
[14:00:13.529] <TB1> INFO: Event errors: 0
[14:00:13.529] <TB1> INFO: start marker: 0
[14:00:13.529] <TB1> INFO: stop marker: 0
[14:00:13.529] <TB1> INFO: overflow: 0
[14:00:13.529] <TB1> INFO: invalid 5bit words: 0
[14:00:13.529] <TB1> INFO: invalid XOR eye diagram: 0
[14:00:13.529] <TB1> INFO: frame (failed synchr.): 0
[14:00:13.529] <TB1> INFO: idle data (no TBM trl): 0
[14:00:13.529] <TB1> INFO: no data (only TBM hdr): 0
[14:00:13.529] <TB1> INFO: TBM errors: 0
[14:00:13.529] <TB1> INFO: flawed TBM headers: 0
[14:00:13.529] <TB1> INFO: flawed TBM trailers: 0
[14:00:13.529] <TB1> INFO: event ID mismatches: 0
[14:00:13.529] <TB1> INFO: ROC errors: 0
[14:00:13.529] <TB1> INFO: missing ROC header(s): 0
[14:00:13.529] <TB1> INFO: misplaced readback start: 0
[14:00:13.529] <TB1> INFO: Pixel decoding errors: 0
[14:00:13.529] <TB1> INFO: pixel data incomplete: 0
[14:00:13.529] <TB1> INFO: pixel address: 0
[14:00:13.529] <TB1> INFO: pulse height fill bit: 0
[14:00:13.529] <TB1> INFO: buffer corruption: 0
[14:00:13.537] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:00:13.537] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr_C15.dat
[14:00:13.537] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[14:00:13.537] <TB1> INFO: ######################################################################
[14:00:13.537] <TB1> INFO: PixTestReadback::doTest()
[14:00:13.537] <TB1> INFO: ######################################################################
[14:00:13.537] <TB1> INFO: ----------------------------------------------------------------------
[14:00:13.537] <TB1> INFO: PixTestReadback::CalibrateVd()
[14:00:13.537] <TB1> INFO: ----------------------------------------------------------------------
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C0.dat
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C1.dat
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C2.dat
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C3.dat
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C4.dat
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C5.dat
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C6.dat
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C7.dat
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C8.dat
[14:00:23.498] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C9.dat
[14:00:23.499] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C10.dat
[14:00:23.499] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C11.dat
[14:00:23.499] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C12.dat
[14:00:23.499] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C13.dat
[14:00:23.499] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C14.dat
[14:00:23.499] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:00:23.527] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:00:23.527] <TB1> INFO: ----------------------------------------------------------------------
[14:00:23.527] <TB1> INFO: PixTestReadback::CalibrateVa()
[14:00:23.527] <TB1> INFO: ----------------------------------------------------------------------
[14:00:33.415] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C0.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C1.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C2.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C3.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C4.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C5.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C6.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C7.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C8.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C9.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C10.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C11.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C12.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C13.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C14.dat
[14:00:33.416] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:00:33.444] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:00:33.444] <TB1> INFO: ----------------------------------------------------------------------
[14:00:33.444] <TB1> INFO: PixTestReadback::readbackVbg()
[14:00:33.444] <TB1> INFO: ----------------------------------------------------------------------
[14:00:41.087] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:00:41.087] <TB1> INFO: ----------------------------------------------------------------------
[14:00:41.087] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[14:00:41.087] <TB1> INFO: ----------------------------------------------------------------------
[14:00:41.087] <TB1> INFO: Vbg will be calibrated using Vd calibration
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 155.6calibrated Vbg = 1.1655 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 153.7calibrated Vbg = 1.16402 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 156.9calibrated Vbg = 1.16003 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 159.2calibrated Vbg = 1.15739 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 155.3calibrated Vbg = 1.15964 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 153.1calibrated Vbg = 1.16416 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 153.4calibrated Vbg = 1.16678 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 158.9calibrated Vbg = 1.17526 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 163.3calibrated Vbg = 1.15845 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 161.5calibrated Vbg = 1.15853 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 167.8calibrated Vbg = 1.15396 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 159calibrated Vbg = 1.16207 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 147.2calibrated Vbg = 1.15416 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 160.7calibrated Vbg = 1.16372 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 154calibrated Vbg = 1.16125 :::*/*/*/*/
[14:00:41.087] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 154.7calibrated Vbg = 1.15956 :::*/*/*/*/
[14:00:41.089] <TB1> INFO: ----------------------------------------------------------------------
[14:00:41.089] <TB1> INFO: PixTestReadback::CalibrateIa()
[14:00:41.089] <TB1> INFO: ----------------------------------------------------------------------
[14:03:21.399] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C0.dat
[14:03:21.399] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C1.dat
[14:03:21.399] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C2.dat
[14:03:21.399] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C3.dat
[14:03:21.399] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C4.dat
[14:03:21.399] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C5.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C6.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C7.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C8.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C9.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C10.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C11.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C12.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C13.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C14.dat
[14:03:21.400] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:03:21.429] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:03:21.430] <TB1> INFO: PixTestReadback::doTest() done
[14:03:21.430] <TB1> INFO: Decoding statistics:
[14:03:21.430] <TB1> INFO: General information:
[14:03:21.430] <TB1> INFO: 16bit words read: 1536
[14:03:21.430] <TB1> INFO: valid events total: 256
[14:03:21.430] <TB1> INFO: empty events: 256
[14:03:21.430] <TB1> INFO: valid events with pixels: 0
[14:03:21.430] <TB1> INFO: valid pixel hits: 0
[14:03:21.430] <TB1> INFO: Event errors: 0
[14:03:21.430] <TB1> INFO: start marker: 0
[14:03:21.430] <TB1> INFO: stop marker: 0
[14:03:21.430] <TB1> INFO: overflow: 0
[14:03:21.430] <TB1> INFO: invalid 5bit words: 0
[14:03:21.430] <TB1> INFO: invalid XOR eye diagram: 0
[14:03:21.430] <TB1> INFO: frame (failed synchr.): 0
[14:03:21.430] <TB1> INFO: idle data (no TBM trl): 0
[14:03:21.430] <TB1> INFO: no data (only TBM hdr): 0
[14:03:21.430] <TB1> INFO: TBM errors: 0
[14:03:21.430] <TB1> INFO: flawed TBM headers: 0
[14:03:21.430] <TB1> INFO: flawed TBM trailers: 0
[14:03:21.430] <TB1> INFO: event ID mismatches: 0
[14:03:21.430] <TB1> INFO: ROC errors: 0
[14:03:21.430] <TB1> INFO: missing ROC header(s): 0
[14:03:21.430] <TB1> INFO: misplaced readback start: 0
[14:03:21.430] <TB1> INFO: Pixel decoding errors: 0
[14:03:21.430] <TB1> INFO: pixel data incomplete: 0
[14:03:21.430] <TB1> INFO: pixel address: 0
[14:03:21.430] <TB1> INFO: pulse height fill bit: 0
[14:03:21.430] <TB1> INFO: buffer corruption: 0
[14:03:21.465] <TB1> INFO: ######################################################################
[14:03:21.465] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[14:03:21.465] <TB1> INFO: ######################################################################
[14:03:21.467] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[14:03:21.478] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:03:21.478] <TB1> INFO: run 1 of 1
[14:03:21.708] <TB1> INFO: Expecting 3120000 events.
[14:03:52.301] <TB1> INFO: 667855 events read in total (30001ms).
[14:04:04.497] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (80) != TBM ID (129)

[14:04:04.631] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 80 80 129 80 80 80 80 80

[14:04:04.631] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (81)

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a054 8040 40c0 41c1 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04e 80c0 40c1 40c0 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04f 8000 40c0 40c0 e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 40c0 40c0 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a051 80b1 40c0 40c0 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a052 80c0 40c1 41c0 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a053 8000 40c0 40c0 e022 c000

[14:04:04.632] <TB1> WARNING: Channel 0 ROC 0: Readback start marker after 32 readouts!

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a063 8000 41c0 41c0 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05d 80b1 40c1 262 25ef 40c0 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05e 80c0 40c0 40c0 e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05f 8000 40c0 40c0 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a060 8040 40c2 40c1 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a061 80b1 40c0 40c0 262 25ef e022 c000

[14:04:04.632] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a062 80c0 40c1 41c0 262 25ef e022 c000

[14:04:22.070] <TB1> INFO: 1332125 events read in total (59770ms).
[14:04:34.220] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (30) != TBM ID (129)

[14:04:34.358] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 30 30 129 30 30 30 30 30

[14:04:34.358] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (31)

[14:04:34.358] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:04:34.358] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a022 80c0 40c1 40c1 e022 c000

[14:04:34.358] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01c 8040 40c1 40c0 e022 c000

[14:04:34.358] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01d 80b1 40c0 40c0 e022 c000

[14:04:34.358] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 40c0 40c0 e022 c000

[14:04:34.358] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01f 8000 40c1 41c0 e022 c000

[14:04:34.358] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a020 8040 4082 4080 e022 c000

[14:04:34.358] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a021 80b1 40c0 40c0 e022 c000

[14:04:51.648] <TB1> INFO: 1993895 events read in total (89348ms).
[14:05:03.830] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (40) != TBM ID (129)

[14:05:03.964] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 40 40 129 40 40 40 40 40

[14:05:03.964] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (41)

[14:05:03.967] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:05:03.967] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02c 8040 40c0 824 25ef 40c0 824 25ef e022 c000

[14:05:03.967] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a026 80c0 40c0 41c3 824 25ef e022 c000

[14:05:03.967] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a027 8000 41c0 41c0 824 25ef e022 c000

[14:05:03.968] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 40c0 40c0 25ef 40c1 824 25ef e022 c000

[14:05:03.968] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a029 80b1 41c0 824 25ef 41c0 824 25ef e022 c000

[14:05:03.968] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02a 80c0 4181 824 25ef 41c1 824 25ef e022 c000

[14:05:03.968] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02b 8000 4180 824 25ef 41c0 824 25ef e022 c000

[14:05:21.526] <TB1> INFO: 2657210 events read in total (119226ms).
[14:05:30.134] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (59) != TBM ID (129)

[14:05:30.270] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 59 59 129 59 59 59 59 59

[14:05:30.270] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (60)

[14:05:30.270] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:05:30.270] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03f 8000 40c0 a84 2def 4181 a84 2def e022 c000

[14:05:30.270] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a039 80b1 40c1 a84 2def 40c0 a84 2def e022 c000

[14:05:30.270] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03a 80c0 4180 a84 2def 41c1 a84 2def e022 c000

[14:05:30.270] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 40c0 40c0 2def 4080 a84 2def e022 c000

[14:05:30.270] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03c 8040 41c0 a84 2def 4080 a84 2def e022 c000

[14:05:30.270] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03d 80b1 40c1 a84 2def 4180 a84 2def e022 c000

[14:05:30.270] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03e 80c0 41c1 a84 2def 41c0 a84 2def e022 c000

[14:05:42.556] <TB1> INFO: 3120000 events read in total (140256ms).
[14:05:42.611] <TB1> INFO: Test took 141134ms.
[14:06:07.732] <TB1> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 166 seconds
[14:06:07.732] <TB1> INFO: number of dead bumps (per ROC): 0 1 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[14:06:07.732] <TB1> INFO: separation cut (per ROC): 102 101 108 107 107 104 93 96 108 103 122 107 104 107 102 108
[14:06:07.732] <TB1> INFO: Decoding statistics:
[14:06:07.732] <TB1> INFO: General information:
[14:06:07.732] <TB1> INFO: 16bit words read: 0
[14:06:07.732] <TB1> INFO: valid events total: 0
[14:06:07.732] <TB1> INFO: empty events: 0
[14:06:07.732] <TB1> INFO: valid events with pixels: 0
[14:06:07.732] <TB1> INFO: valid pixel hits: 0
[14:06:07.732] <TB1> INFO: Event errors: 0
[14:06:07.732] <TB1> INFO: start marker: 0
[14:06:07.732] <TB1> INFO: stop marker: 0
[14:06:07.732] <TB1> INFO: overflow: 0
[14:06:07.732] <TB1> INFO: invalid 5bit words: 0
[14:06:07.732] <TB1> INFO: invalid XOR eye diagram: 0
[14:06:07.732] <TB1> INFO: frame (failed synchr.): 0
[14:06:07.732] <TB1> INFO: idle data (no TBM trl): 0
[14:06:07.732] <TB1> INFO: no data (only TBM hdr): 0
[14:06:07.732] <TB1> INFO: TBM errors: 0
[14:06:07.732] <TB1> INFO: flawed TBM headers: 0
[14:06:07.732] <TB1> INFO: flawed TBM trailers: 0
[14:06:07.732] <TB1> INFO: event ID mismatches: 0
[14:06:07.732] <TB1> INFO: ROC errors: 0
[14:06:07.732] <TB1> INFO: missing ROC header(s): 0
[14:06:07.732] <TB1> INFO: misplaced readback start: 0
[14:06:07.732] <TB1> INFO: Pixel decoding errors: 0
[14:06:07.732] <TB1> INFO: pixel data incomplete: 0
[14:06:07.732] <TB1> INFO: pixel address: 0
[14:06:07.732] <TB1> INFO: pulse height fill bit: 0
[14:06:07.733] <TB1> INFO: buffer corruption: 0
[14:06:07.779] <TB1> INFO: ######################################################################
[14:06:07.779] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:06:07.779] <TB1> INFO: ######################################################################
[14:06:07.779] <TB1> INFO: ----------------------------------------------------------------------
[14:06:07.779] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:06:07.779] <TB1> INFO: ----------------------------------------------------------------------
[14:06:07.779] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[14:06:07.793] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[14:06:07.793] <TB1> INFO: run 1 of 1
[14:06:08.075] <TB1> INFO: Expecting 36608000 events.
[14:06:31.599] <TB1> INFO: 710350 events read in total (22932ms).
[14:06:54.649] <TB1> INFO: 1401250 events read in total (45982ms).
[14:07:17.435] <TB1> INFO: 2089450 events read in total (68768ms).
[14:07:40.092] <TB1> INFO: 2777350 events read in total (91425ms).
[14:08:02.681] <TB1> INFO: 3464150 events read in total (114014ms).
[14:08:25.459] <TB1> INFO: 4152650 events read in total (136792ms).
[14:08:48.373] <TB1> INFO: 4840150 events read in total (159706ms).
[14:09:11.006] <TB1> INFO: 5527450 events read in total (182339ms).
[14:09:33.000] <TB1> INFO: 6217700 events read in total (205333ms).
[14:09:56.794] <TB1> INFO: 6907650 events read in total (228127ms).
[14:10:19.316] <TB1> INFO: 7596000 events read in total (250649ms).
[14:10:42.239] <TB1> INFO: 8283950 events read in total (273572ms).
[14:11:04.898] <TB1> INFO: 8972100 events read in total (296231ms).
[14:11:27.626] <TB1> INFO: 9659900 events read in total (318959ms).
[14:11:50.532] <TB1> INFO: 10348000 events read in total (341865ms).
[14:12:13.210] <TB1> INFO: 11037000 events read in total (364543ms).
[14:12:36.113] <TB1> INFO: 11724700 events read in total (387446ms).
[14:12:58.460] <TB1> INFO: 12409550 events read in total (409793ms).
[14:13:21.303] <TB1> INFO: 13097550 events read in total (432636ms).
[14:13:43.914] <TB1> INFO: 13785050 events read in total (455247ms).
[14:14:06.577] <TB1> INFO: 14473150 events read in total (477910ms).
[14:14:29.456] <TB1> INFO: 15159450 events read in total (500789ms).
[14:14:52.208] <TB1> INFO: 15845500 events read in total (523541ms).
[14:15:14.948] <TB1> INFO: 16530200 events read in total (546281ms).
[14:15:37.451] <TB1> INFO: 17214250 events read in total (568784ms).
[14:16:00.195] <TB1> INFO: 17897900 events read in total (591528ms).
[14:16:22.824] <TB1> INFO: 18583050 events read in total (614157ms).
[14:16:45.477] <TB1> INFO: 19267050 events read in total (636810ms).
[14:17:08.065] <TB1> INFO: 19948200 events read in total (659398ms).
[14:17:30.507] <TB1> INFO: 20630850 events read in total (681840ms).
[14:17:53.413] <TB1> INFO: 21311200 events read in total (704746ms).
[14:18:15.798] <TB1> INFO: 21992200 events read in total (727131ms).
[14:18:38.591] <TB1> INFO: 22673900 events read in total (749924ms).
[14:19:01.295] <TB1> INFO: 23354050 events read in total (772628ms).
[14:19:23.913] <TB1> INFO: 24034900 events read in total (795246ms).
[14:19:46.560] <TB1> INFO: 24716900 events read in total (817893ms).
[14:20:09.166] <TB1> INFO: 25397600 events read in total (840499ms).
[14:20:31.963] <TB1> INFO: 26078700 events read in total (863296ms).
[14:20:54.432] <TB1> INFO: 26757800 events read in total (885765ms).
[14:21:16.813] <TB1> INFO: 27438050 events read in total (908146ms).
[14:21:39.258] <TB1> INFO: 28115550 events read in total (930591ms).
[14:22:01.728] <TB1> INFO: 28795150 events read in total (953061ms).
[14:22:24.254] <TB1> INFO: 29472750 events read in total (975587ms).
[14:22:47.334] <TB1> INFO: 30153000 events read in total (998667ms).
[14:23:10.093] <TB1> INFO: 30831100 events read in total (1021426ms).
[14:23:32.585] <TB1> INFO: 31508650 events read in total (1043918ms).
[14:23:55.010] <TB1> INFO: 32186500 events read in total (1066343ms).
[14:24:17.439] <TB1> INFO: 32865400 events read in total (1088772ms).
[14:24:40.255] <TB1> INFO: 33545600 events read in total (1111588ms).
[14:25:02.961] <TB1> INFO: 34226400 events read in total (1134294ms).
[14:25:25.565] <TB1> INFO: 34905950 events read in total (1156898ms).
[14:25:48.560] <TB1> INFO: 35586150 events read in total (1179893ms).
[14:26:11.222] <TB1> INFO: 36276150 events read in total (1202555ms).
[14:26:22.254] <TB1> INFO: 36608000 events read in total (1213587ms).
[14:26:22.304] <TB1> INFO: Test took 1214511ms.
[14:26:22.630] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:24.229] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:26.192] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:28.013] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:29.910] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:31.870] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:33.863] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:35.847] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:37.850] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:39.713] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:41.306] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:43.253] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:45.073] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:47.006] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:48.809] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:50.828] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[14:26:52.723] <TB1> INFO: PixTestScurves::scurves() done
[14:26:52.723] <TB1> INFO: Vcal mean: 129.72 125.47 132.60 141.25 126.14 120.24 124.11 125.89 142.56 131.02 135.72 123.22 115.63 131.06 121.89 136.19
[14:26:52.723] <TB1> INFO: Vcal RMS: 5.93 7.19 6.01 5.98 6.18 5.89 6.27 6.45 6.26 6.75 6.97 6.06 5.02 6.15 5.94 6.01
[14:26:52.723] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1244 seconds
[14:26:52.723] <TB1> INFO: Decoding statistics:
[14:26:52.723] <TB1> INFO: General information:
[14:26:52.723] <TB1> INFO: 16bit words read: 0
[14:26:52.723] <TB1> INFO: valid events total: 0
[14:26:52.723] <TB1> INFO: empty events: 0
[14:26:52.723] <TB1> INFO: valid events with pixels: 0
[14:26:52.723] <TB1> INFO: valid pixel hits: 0
[14:26:52.723] <TB1> INFO: Event errors: 0
[14:26:52.723] <TB1> INFO: start marker: 0
[14:26:52.723] <TB1> INFO: stop marker: 0
[14:26:52.723] <TB1> INFO: overflow: 0
[14:26:52.723] <TB1> INFO: invalid 5bit words: 0
[14:26:52.723] <TB1> INFO: invalid XOR eye diagram: 0
[14:26:52.723] <TB1> INFO: frame (failed synchr.): 0
[14:26:52.723] <TB1> INFO: idle data (no TBM trl): 0
[14:26:52.723] <TB1> INFO: no data (only TBM hdr): 0
[14:26:52.723] <TB1> INFO: TBM errors: 0
[14:26:52.723] <TB1> INFO: flawed TBM headers: 0
[14:26:52.723] <TB1> INFO: flawed TBM trailers: 0
[14:26:52.723] <TB1> INFO: event ID mismatches: 0
[14:26:52.723] <TB1> INFO: ROC errors: 0
[14:26:52.723] <TB1> INFO: missing ROC header(s): 0
[14:26:52.723] <TB1> INFO: misplaced readback start: 0
[14:26:52.723] <TB1> INFO: Pixel decoding errors: 0
[14:26:52.723] <TB1> INFO: pixel data incomplete: 0
[14:26:52.723] <TB1> INFO: pixel address: 0
[14:26:52.723] <TB1> INFO: pulse height fill bit: 0
[14:26:52.723] <TB1> INFO: buffer corruption: 0
[14:26:52.787] <TB1> INFO: ######################################################################
[14:26:52.787] <TB1> INFO: PixTestTrim::doTest()
[14:26:52.787] <TB1> INFO: ######################################################################
[14:26:52.788] <TB1> INFO: ----------------------------------------------------------------------
[14:26:52.788] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[14:26:52.788] <TB1> INFO: ----------------------------------------------------------------------
[14:26:52.831] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[14:26:52.831] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[14:26:52.841] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:26:52.841] <TB1> INFO: run 1 of 1
[14:26:53.075] <TB1> INFO: Expecting 5025280 events.
[14:27:23.714] <TB1> INFO: 830776 events read in total (30046ms).
[14:27:53.690] <TB1> INFO: 1660528 events read in total (60022ms).
[14:28:23.663] <TB1> INFO: 2488072 events read in total (89995ms).
[14:28:53.730] <TB1> INFO: 3312960 events read in total (120062ms).
[14:29:23.499] <TB1> INFO: 4134344 events read in total (149831ms).
[14:29:53.132] <TB1> INFO: 4953920 events read in total (179464ms).
[14:29:56.003] <TB1> INFO: 5025280 events read in total (182335ms).
[14:29:56.059] <TB1> INFO: Test took 183218ms.
[14:30:11.938] <TB1> INFO: ROC 0 VthrComp = 124
[14:30:11.938] <TB1> INFO: ROC 1 VthrComp = 112
[14:30:11.938] <TB1> INFO: ROC 2 VthrComp = 133
[14:30:11.938] <TB1> INFO: ROC 3 VthrComp = 132
[14:30:11.940] <TB1> INFO: ROC 4 VthrComp = 127
[14:30:11.941] <TB1> INFO: ROC 5 VthrComp = 115
[14:30:11.941] <TB1> INFO: ROC 6 VthrComp = 109
[14:30:11.941] <TB1> INFO: ROC 7 VthrComp = 113
[14:30:11.941] <TB1> INFO: ROC 8 VthrComp = 135
[14:30:11.941] <TB1> INFO: ROC 9 VthrComp = 126
[14:30:11.942] <TB1> INFO: ROC 10 VthrComp = 134
[14:30:11.942] <TB1> INFO: ROC 11 VthrComp = 122
[14:30:11.942] <TB1> INFO: ROC 12 VthrComp = 119
[14:30:11.942] <TB1> INFO: ROC 13 VthrComp = 126
[14:30:11.942] <TB1> INFO: ROC 14 VthrComp = 118
[14:30:11.942] <TB1> INFO: ROC 15 VthrComp = 133
[14:30:12.182] <TB1> INFO: Expecting 41600 events.
[14:30:15.641] <TB1> INFO: 41600 events read in total (2867ms).
[14:30:15.642] <TB1> INFO: Test took 3698ms.
[14:30:15.651] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[14:30:15.651] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[14:30:15.662] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:30:15.662] <TB1> INFO: run 1 of 1
[14:30:15.940] <TB1> INFO: Expecting 5025280 events.
[14:30:42.124] <TB1> INFO: 592088 events read in total (25593ms).
[14:31:07.414] <TB1> INFO: 1183080 events read in total (50883ms).
[14:31:32.455] <TB1> INFO: 1774456 events read in total (75924ms).
[14:31:58.186] <TB1> INFO: 2365872 events read in total (101655ms).
[14:32:23.684] <TB1> INFO: 2954976 events read in total (127153ms).
[14:32:48.784] <TB1> INFO: 3542752 events read in total (152253ms).
[14:33:14.175] <TB1> INFO: 4129784 events read in total (177644ms).
[14:33:39.535] <TB1> INFO: 4716576 events read in total (203004ms).
[14:33:52.000] <TB1> INFO: 5025280 events read in total (216469ms).
[14:33:53.059] <TB1> INFO: Test took 217397ms.
[14:34:19.719] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 62.2187 for pixel 26/19 mean/min/max = 46.8635/31.3193/62.4078
[14:34:19.720] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 68.5981 for pixel 18/5 mean/min/max = 50.8648/32.0675/69.6621
[14:34:19.720] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 61.4963 for pixel 14/10 mean/min/max = 47.339/33.1436/61.5343
[14:34:19.720] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 68.9241 for pixel 1/0 mean/min/max = 50.6251/31.8916/69.3586
[14:34:19.721] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 60.2151 for pixel 0/8 mean/min/max = 45.9512/31.5372/60.3651
[14:34:19.721] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 62.4989 for pixel 0/2 mean/min/max = 47.5141/32.1097/62.9186
[14:34:19.721] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 70.4669 for pixel 0/6 mean/min/max = 51.8562/32.9628/70.7497
[14:34:19.722] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 66.2632 for pixel 0/0 mean/min/max = 48.9855/31.5772/66.3937
[14:34:19.722] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 65.3588 for pixel 0/74 mean/min/max = 49.3248/33.1646/65.485
[14:34:19.722] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 61.9092 for pixel 36/9 mean/min/max = 46.7563/31.5196/61.993
[14:34:19.723] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 68.5825 for pixel 0/27 mean/min/max = 51.8655/35.0625/68.6685
[14:34:19.723] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 62.213 for pixel 5/38 mean/min/max = 47.635/33.0108/62.2591
[14:34:19.724] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 58.0765 for pixel 0/79 mean/min/max = 45.2468/32.3689/58.1247
[14:34:19.724] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 63.532 for pixel 13/77 mean/min/max = 47.7168/31.7669/63.6667
[14:34:19.724] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 62.5002 for pixel 51/1 mean/min/max = 47.0797/31.6075/62.5519
[14:34:19.725] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 66.3904 for pixel 0/16 mean/min/max = 50.4708/34.2532/66.6883
[14:34:19.725] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:34:19.814] <TB1> INFO: Expecting 411648 events.
[14:34:29.175] <TB1> INFO: 411648 events read in total (8770ms).
[14:34:29.183] <TB1> INFO: Expecting 411648 events.
[14:34:38.452] <TB1> INFO: 411648 events read in total (8866ms).
[14:34:38.461] <TB1> INFO: Expecting 411648 events.
[14:34:47.656] <TB1> INFO: 411648 events read in total (8792ms).
[14:34:47.672] <TB1> INFO: Expecting 411648 events.
[14:34:56.698] <TB1> INFO: 411648 events read in total (8623ms).
[14:34:56.711] <TB1> INFO: Expecting 411648 events.
[14:35:05.808] <TB1> INFO: 411648 events read in total (8694ms).
[14:35:05.824] <TB1> INFO: Expecting 411648 events.
[14:35:14.813] <TB1> INFO: 411648 events read in total (8586ms).
[14:35:14.832] <TB1> INFO: Expecting 411648 events.
[14:35:23.856] <TB1> INFO: 411648 events read in total (8621ms).
[14:35:23.879] <TB1> INFO: Expecting 411648 events.
[14:35:32.840] <TB1> INFO: 411648 events read in total (8558ms).
[14:35:32.863] <TB1> INFO: Expecting 411648 events.
[14:35:41.918] <TB1> INFO: 411648 events read in total (8652ms).
[14:35:41.944] <TB1> INFO: Expecting 411648 events.
[14:35:50.001] <TB1> INFO: 411648 events read in total (8655ms).
[14:35:51.029] <TB1> INFO: Expecting 411648 events.
[14:36:00.091] <TB1> INFO: 411648 events read in total (8659ms).
[14:36:00.133] <TB1> INFO: Expecting 411648 events.
[14:36:09.196] <TB1> INFO: 411648 events read in total (8660ms).
[14:36:09.230] <TB1> INFO: Expecting 411648 events.
[14:36:18.233] <TB1> INFO: 411648 events read in total (8600ms).
[14:36:18.278] <TB1> INFO: Expecting 411648 events.
[14:36:27.344] <TB1> INFO: 411648 events read in total (8663ms).
[14:36:27.382] <TB1> INFO: Expecting 411648 events.
[14:36:36.445] <TB1> INFO: 411648 events read in total (8660ms).
[14:36:36.500] <TB1> INFO: Expecting 411648 events.
[14:36:45.588] <TB1> INFO: 411648 events read in total (8685ms).
[14:36:45.646] <TB1> INFO: Test took 145921ms.
[14:36:46.263] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[14:36:46.274] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:36:46.274] <TB1> INFO: run 1 of 1
[14:36:46.512] <TB1> INFO: Expecting 5025280 events.
[14:37:12.235] <TB1> INFO: 593912 events read in total (25131ms).
[14:37:37.576] <TB1> INFO: 1184880 events read in total (50472ms).
[14:38:03.157] <TB1> INFO: 1775392 events read in total (76054ms).
[14:38:28.606] <TB1> INFO: 2365216 events read in total (101502ms).
[14:38:54.252] <TB1> INFO: 2957128 events read in total (127149ms).
[14:39:19.815] <TB1> INFO: 3547584 events read in total (152711ms).
[14:39:45.011] <TB1> INFO: 4137840 events read in total (177907ms).
[14:40:10.584] <TB1> INFO: 4728624 events read in total (203480ms).
[14:40:23.723] <TB1> INFO: 5025280 events read in total (216619ms).
[14:40:23.829] <TB1> INFO: Test took 217554ms.
[14:40:46.904] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 9.500000 .. 147.798249
[14:40:47.146] <TB1> INFO: Expecting 208000 events.
[14:40:56.763] <TB1> INFO: 208000 events read in total (9025ms).
[14:40:56.765] <TB1> INFO: Test took 9860ms.
[14:40:56.843] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 9 .. 157 (-1/-1) hits flags = 528 (plus default)
[14:40:56.856] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:40:56.856] <TB1> INFO: run 1 of 1
[14:40:57.150] <TB1> INFO: Expecting 4958720 events.
[14:41:23.091] <TB1> INFO: 574288 events read in total (25350ms).
[14:41:47.979] <TB1> INFO: 1148096 events read in total (50238ms).
[14:42:13.167] <TB1> INFO: 1722176 events read in total (75426ms).
[14:42:38.328] <TB1> INFO: 2295840 events read in total (100587ms).
[14:43:03.112] <TB1> INFO: 2869192 events read in total (125371ms).
[14:43:28.532] <TB1> INFO: 3442400 events read in total (150791ms).
[14:43:53.672] <TB1> INFO: 4015072 events read in total (175931ms).
[14:44:18.900] <TB1> INFO: 4587304 events read in total (201159ms).
[14:44:35.490] <TB1> INFO: 4958720 events read in total (217749ms).
[14:44:35.568] <TB1> INFO: Test took 218712ms.
[14:45:02.436] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 26.180972 .. 47.016619
[14:45:02.680] <TB1> INFO: Expecting 208000 events.
[14:45:12.592] <TB1> INFO: 208000 events read in total (9321ms).
[14:45:12.593] <TB1> INFO: Test took 10155ms.
[14:45:12.654] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 57 (-1/-1) hits flags = 528 (plus default)
[14:45:12.665] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:45:12.665] <TB1> INFO: run 1 of 1
[14:45:12.943] <TB1> INFO: Expecting 1397760 events.
[14:45:40.241] <TB1> INFO: 657360 events read in total (26706ms).
[14:46:07.681] <TB1> INFO: 1312760 events read in total (54146ms).
[14:46:11.532] <TB1> INFO: 1397760 events read in total (57998ms).
[14:46:11.561] <TB1> INFO: Test took 58897ms.
[14:46:25.817] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 27.357537 .. 50.498399
[14:46:26.087] <TB1> INFO: Expecting 208000 events.
[14:46:35.786] <TB1> INFO: 208000 events read in total (9106ms).
[14:46:35.787] <TB1> INFO: Test took 9969ms.
[14:46:35.851] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 17 .. 60 (-1/-1) hits flags = 528 (plus default)
[14:46:35.862] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:46:35.862] <TB1> INFO: run 1 of 1
[14:46:36.140] <TB1> INFO: Expecting 1464320 events.
[14:47:03.967] <TB1> INFO: 643104 events read in total (27236ms).
[14:47:30.724] <TB1> INFO: 1285456 events read in total (53993ms).
[14:47:38.690] <TB1> INFO: 1464320 events read in total (61959ms).
[14:47:38.717] <TB1> INFO: Test took 62856ms.
[14:47:53.034] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 27.296132 .. 53.163221
[14:47:53.271] <TB1> INFO: Expecting 208000 events.
[14:48:02.974] <TB1> INFO: 208000 events read in total (9111ms).
[14:48:02.976] <TB1> INFO: Test took 9940ms.
[14:48:03.040] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 17 .. 63 (-1/-1) hits flags = 528 (plus default)
[14:48:03.051] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:48:03.052] <TB1> INFO: run 1 of 1
[14:48:03.329] <TB1> INFO: Expecting 1564160 events.
[14:48:31.027] <TB1> INFO: 634160 events read in total (27106ms).
[14:48:57.495] <TB1> INFO: 1268048 events read in total (53574ms).
[14:49:10.218] <TB1> INFO: 1564160 events read in total (66297ms).
[14:49:10.258] <TB1> INFO: Test took 67207ms.
[14:49:24.116] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[14:49:24.116] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[14:49:24.126] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:49:24.126] <TB1> INFO: run 1 of 1
[14:49:24.389] <TB1> INFO: Expecting 1364480 events.
[14:49:52.574] <TB1> INFO: 668648 events read in total (27594ms).
[14:50:19.563] <TB1> INFO: 1336856 events read in total (54583ms).
[14:50:21.164] <TB1> INFO: 1364480 events read in total (56184ms).
[14:50:21.189] <TB1> INFO: Test took 57063ms.
[14:50:34.921] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C0.dat
[14:50:34.921] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C1.dat
[14:50:34.921] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C2.dat
[14:50:34.921] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C3.dat
[14:50:34.921] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C4.dat
[14:50:34.921] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C5.dat
[14:50:34.921] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C6.dat
[14:50:34.922] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C7.dat
[14:50:34.922] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C8.dat
[14:50:34.922] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C9.dat
[14:50:34.922] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C10.dat
[14:50:34.922] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C11.dat
[14:50:34.922] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C12.dat
[14:50:34.922] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C13.dat
[14:50:34.922] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C14.dat
[14:50:34.922] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C15.dat
[14:50:34.922] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C0.dat
[14:50:34.928] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C1.dat
[14:50:34.934] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C2.dat
[14:50:34.940] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C3.dat
[14:50:34.947] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C4.dat
[14:50:34.953] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C5.dat
[14:50:34.959] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C6.dat
[14:50:34.965] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C7.dat
[14:50:34.971] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C8.dat
[14:50:34.976] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C9.dat
[14:50:34.982] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C10.dat
[14:50:34.988] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C11.dat
[14:50:34.994] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C12.dat
[14:50:34.001] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C13.dat
[14:50:35.008] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C14.dat
[14:50:35.014] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters35_C15.dat
[14:50:35.020] <TB1> INFO: PixTestTrim::trimTest() done
[14:50:35.020] <TB1> INFO: vtrim: 143 137 165 134 127 130 133 138 144 147 143 145 123 135 133 152
[14:50:35.020] <TB1> INFO: vthrcomp: 124 112 133 132 127 115 109 113 135 126 134 122 119 126 118 133
[14:50:35.020] <TB1> INFO: vcal mean: 35.19 35.99 35.10 35.62 35.00 35.00 35.47 35.59 35.45 35.11 35.43 35.15 34.94 35.66 35.09 35.53
[14:50:35.020] <TB1> INFO: vcal RMS: 1.43 2.36 1.25 1.93 1.04 1.10 1.71 1.87 1.71 1.43 1.73 1.37 0.96 1.79 1.18 1.65
[14:50:35.020] <TB1> INFO: bits mean: 10.28 9.62 10.16 9.15 9.42 9.54 8.89 9.64 9.14 10.17 8.01 9.71 9.68 10.18 9.66 8.69
[14:50:35.020] <TB1> INFO: bits RMS: 2.39 2.55 2.17 2.76 2.74 2.61 2.71 2.67 2.63 2.46 2.65 2.47 2.63 2.44 2.67 2.64
[14:50:35.026] <TB1> INFO: ----------------------------------------------------------------------
[14:50:35.026] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[14:50:35.026] <TB1> INFO: ----------------------------------------------------------------------
[14:50:35.029] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[14:50:35.038] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:50:35.038] <TB1> INFO: run 1 of 1
[14:50:35.272] <TB1> INFO: Expecting 4160000 events.
[14:51:08.225] <TB1> INFO: 782705 events read in total (32362ms).
[14:51:39.865] <TB1> INFO: 1559395 events read in total (64002ms).
[14:52:11.706] <TB1> INFO: 2331425 events read in total (95843ms).
[14:52:43.275] <TB1> INFO: 3100785 events read in total (127412ms).
[14:53:15.055] <TB1> INFO: 3867490 events read in total (159192ms).
[14:53:27.470] <TB1> INFO: 4160000 events read in total (171607ms).
[14:53:27.514] <TB1> INFO: Test took 172476ms.
[14:53:52.270] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 221 (-1/-1) hits flags = 528 (plus default)
[14:53:52.281] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:53:52.282] <TB1> INFO: run 1 of 1
[14:53:52.565] <TB1> INFO: Expecting 4617600 events.
[14:54:24.292] <TB1> INFO: 724055 events read in total (31135ms).
[14:54:54.663] <TB1> INFO: 1444870 events read in total (61506ms).
[14:55:25.269] <TB1> INFO: 2162475 events read in total (92113ms).
[14:55:55.772] <TB1> INFO: 2877895 events read in total (122615ms).
[14:56:26.371] <TB1> INFO: 3591960 events read in total (153214ms).
[14:56:57.059] <TB1> INFO: 4305385 events read in total (183902ms).
[14:57:10.874] <TB1> INFO: 4617600 events read in total (197717ms).
[14:57:10.977] <TB1> INFO: Test took 198695ms.
[14:57:41.028] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 216 (-1/-1) hits flags = 528 (plus default)
[14:57:41.040] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:57:41.040] <TB1> INFO: run 1 of 1
[14:57:41.356] <TB1> INFO: Expecting 4513600 events.
[14:58:12.732] <TB1> INFO: 730465 events read in total (30784ms).
[14:58:43.557] <TB1> INFO: 1457160 events read in total (61609ms).
[14:59:14.062] <TB1> INFO: 2181190 events read in total (92114ms).
[14:59:44.655] <TB1> INFO: 2902130 events read in total (122707ms).
[15:00:15.534] <TB1> INFO: 3622545 events read in total (153587ms).
[15:00:46.501] <TB1> INFO: 4342120 events read in total (184553ms).
[15:00:54.222] <TB1> INFO: 4513600 events read in total (192274ms).
[15:00:54.329] <TB1> INFO: Test took 193289ms.
[15:01:23.699] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 214 (-1/-1) hits flags = 528 (plus default)
[15:01:23.710] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:01:23.710] <TB1> INFO: run 1 of 1
[15:01:23.963] <TB1> INFO: Expecting 4472000 events.
[15:01:55.551] <TB1> INFO: 732970 events read in total (30996ms).
[15:02:26.417] <TB1> INFO: 1462390 events read in total (61862ms).
[15:02:57.269] <TB1> INFO: 2188550 events read in total (92714ms).
[15:03:28.083] <TB1> INFO: 2912065 events read in total (123528ms).
[15:03:59.078] <TB1> INFO: 3635240 events read in total (154523ms).
[15:04:30.030] <TB1> INFO: 4357625 events read in total (185475ms).
[15:04:35.216] <TB1> INFO: 4472000 events read in total (190661ms).
[15:04:35.304] <TB1> INFO: Test took 191594ms.
[15:05:03.781] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 216 (-1/-1) hits flags = 528 (plus default)
[15:05:03.791] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:05:03.791] <TB1> INFO: run 1 of 1
[15:05:04.026] <TB1> INFO: Expecting 4513600 events.
[15:05:35.865] <TB1> INFO: 730550 events read in total (31247ms).
[15:06:06.560] <TB1> INFO: 1457345 events read in total (61942ms).
[15:06:37.232] <TB1> INFO: 2181570 events read in total (92614ms).
[15:07:07.795] <TB1> INFO: 2902695 events read in total (123177ms).
[15:07:38.584] <TB1> INFO: 3623500 events read in total (153966ms).
[15:08:09.469] <TB1> INFO: 4343325 events read in total (184851ms).
[15:08:16.962] <TB1> INFO: 4513600 events read in total (192344ms).
[15:08:17.054] <TB1> INFO: Test took 193263ms.
[15:08:45.974] <TB1> INFO: PixTestTrim::trimBitTest() done
[15:08:45.976] <TB1> INFO: PixTestTrim::doTest() done, duration: 2513 seconds
[15:08:45.976] <TB1> INFO: Decoding statistics:
[15:08:45.976] <TB1> INFO: General information:
[15:08:45.976] <TB1> INFO: 16bit words read: 0
[15:08:45.976] <TB1> INFO: valid events total: 0
[15:08:45.976] <TB1> INFO: empty events: 0
[15:08:45.976] <TB1> INFO: valid events with pixels: 0
[15:08:45.976] <TB1> INFO: valid pixel hits: 0
[15:08:45.976] <TB1> INFO: Event errors: 0
[15:08:45.976] <TB1> INFO: start marker: 0
[15:08:45.976] <TB1> INFO: stop marker: 0
[15:08:45.976] <TB1> INFO: overflow: 0
[15:08:45.976] <TB1> INFO: invalid 5bit words: 0
[15:08:45.976] <TB1> INFO: invalid XOR eye diagram: 0
[15:08:45.976] <TB1> INFO: frame (failed synchr.): 0
[15:08:45.976] <TB1> INFO: idle data (no TBM trl): 0
[15:08:45.976] <TB1> INFO: no data (only TBM hdr): 0
[15:08:45.976] <TB1> INFO: TBM errors: 0
[15:08:45.976] <TB1> INFO: flawed TBM headers: 0
[15:08:45.976] <TB1> INFO: flawed TBM trailers: 0
[15:08:45.976] <TB1> INFO: event ID mismatches: 0
[15:08:45.976] <TB1> INFO: ROC errors: 0
[15:08:45.976] <TB1> INFO: missing ROC header(s): 0
[15:08:45.976] <TB1> INFO: misplaced readback start: 0
[15:08:45.976] <TB1> INFO: Pixel decoding errors: 0
[15:08:45.976] <TB1> INFO: pixel data incomplete: 0
[15:08:45.976] <TB1> INFO: pixel address: 0
[15:08:45.976] <TB1> INFO: pulse height fill bit: 0
[15:08:45.976] <TB1> INFO: buffer corruption: 0
[15:08:46.731] <TB1> INFO: ######################################################################
[15:08:46.731] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[15:08:46.731] <TB1> INFO: ######################################################################
[15:08:46.988] <TB1> INFO: Expecting 41600 events.
[15:08:50.410] <TB1> INFO: 41600 events read in total (2830ms).
[15:08:50.411] <TB1> INFO: Test took 3679ms.
[15:08:50.846] <TB1> INFO: Expecting 41600 events.
[15:08:54.375] <TB1> INFO: 41600 events read in total (2937ms).
[15:08:54.376] <TB1> INFO: Test took 3762ms.
[15:08:54.665] <TB1> INFO: Expecting 41600 events.
[15:08:58.168] <TB1> INFO: 41600 events read in total (2911ms).
[15:08:58.169] <TB1> INFO: Test took 3769ms.
[15:08:58.457] <TB1> INFO: Expecting 41600 events.
[15:09:02.097] <TB1> INFO: 41600 events read in total (3048ms).
[15:09:02.099] <TB1> INFO: Test took 3907ms.
[15:09:02.387] <TB1> INFO: Expecting 41600 events.
[15:09:05.927] <TB1> INFO: 41600 events read in total (2948ms).
[15:09:05.928] <TB1> INFO: Test took 3805ms.
[15:09:06.223] <TB1> INFO: Expecting 41600 events.
[15:09:09.862] <TB1> INFO: 41600 events read in total (3048ms).
[15:09:09.863] <TB1> INFO: Test took 3909ms.
[15:09:10.151] <TB1> INFO: Expecting 41600 events.
[15:09:13.625] <TB1> INFO: 41600 events read in total (2882ms).
[15:09:13.626] <TB1> INFO: Test took 3739ms.
[15:09:13.914] <TB1> INFO: Expecting 41600 events.
[15:09:17.425] <TB1> INFO: 41600 events read in total (2919ms).
[15:09:17.427] <TB1> INFO: Test took 3777ms.
[15:09:17.717] <TB1> INFO: Expecting 41600 events.
[15:09:21.279] <TB1> INFO: 41600 events read in total (2971ms).
[15:09:21.280] <TB1> INFO: Test took 3828ms.
[15:09:21.568] <TB1> INFO: Expecting 41600 events.
[15:09:25.300] <TB1> INFO: 41600 events read in total (3140ms).
[15:09:25.301] <TB1> INFO: Test took 3997ms.
[15:09:25.590] <TB1> INFO: Expecting 41600 events.
[15:09:29.134] <TB1> INFO: 41600 events read in total (2952ms).
[15:09:29.135] <TB1> INFO: Test took 3810ms.
[15:09:29.426] <TB1> INFO: Expecting 41600 events.
[15:09:32.988] <TB1> INFO: 41600 events read in total (2971ms).
[15:09:32.989] <TB1> INFO: Test took 3828ms.
[15:09:33.280] <TB1> INFO: Expecting 41600 events.
[15:09:36.887] <TB1> INFO: 41600 events read in total (3016ms).
[15:09:36.887] <TB1> INFO: Test took 3872ms.
[15:09:37.181] <TB1> INFO: Expecting 41600 events.
[15:09:40.653] <TB1> INFO: 41600 events read in total (2880ms).
[15:09:40.654] <TB1> INFO: Test took 3743ms.
[15:09:40.941] <TB1> INFO: Expecting 41600 events.
[15:09:44.398] <TB1> INFO: 41600 events read in total (2865ms).
[15:09:44.399] <TB1> INFO: Test took 3722ms.
[15:09:44.687] <TB1> INFO: Expecting 41600 events.
[15:09:48.169] <TB1> INFO: 41600 events read in total (2890ms).
[15:09:48.170] <TB1> INFO: Test took 3747ms.
[15:09:48.465] <TB1> INFO: Expecting 41600 events.
[15:09:51.955] <TB1> INFO: 41600 events read in total (2899ms).
[15:09:51.956] <TB1> INFO: Test took 3763ms.
[15:09:52.244] <TB1> INFO: Expecting 41600 events.
[15:09:55.810] <TB1> INFO: 41600 events read in total (2975ms).
[15:09:55.811] <TB1> INFO: Test took 3832ms.
[15:09:56.101] <TB1> INFO: Expecting 41600 events.
[15:09:59.620] <TB1> INFO: 41600 events read in total (2927ms).
[15:09:59.621] <TB1> INFO: Test took 3784ms.
[15:09:59.909] <TB1> INFO: Expecting 41600 events.
[15:10:03.460] <TB1> INFO: 41600 events read in total (2959ms).
[15:10:03.461] <TB1> INFO: Test took 3817ms.
[15:10:03.749] <TB1> INFO: Expecting 41600 events.
[15:10:07.298] <TB1> INFO: 41600 events read in total (2957ms).
[15:10:07.299] <TB1> INFO: Test took 3814ms.
[15:10:07.590] <TB1> INFO: Expecting 41600 events.
[15:10:11.048] <TB1> INFO: 41600 events read in total (2866ms).
[15:10:11.049] <TB1> INFO: Test took 3723ms.
[15:10:11.337] <TB1> INFO: Expecting 41600 events.
[15:10:14.885] <TB1> INFO: 41600 events read in total (2956ms).
[15:10:14.887] <TB1> INFO: Test took 3814ms.
[15:10:15.175] <TB1> INFO: Expecting 41600 events.
[15:10:18.672] <TB1> INFO: 41600 events read in total (2906ms).
[15:10:18.673] <TB1> INFO: Test took 3763ms.
[15:10:18.966] <TB1> INFO: Expecting 41600 events.
[15:10:22.491] <TB1> INFO: 41600 events read in total (2933ms).
[15:10:22.492] <TB1> INFO: Test took 3795ms.
[15:10:22.780] <TB1> INFO: Expecting 41600 events.
[15:10:26.305] <TB1> INFO: 41600 events read in total (2933ms).
[15:10:26.306] <TB1> INFO: Test took 3790ms.
[15:10:26.594] <TB1> INFO: Expecting 41600 events.
[15:10:30.046] <TB1> INFO: 41600 events read in total (2860ms).
[15:10:30.047] <TB1> INFO: Test took 3718ms.
[15:10:30.337] <TB1> INFO: Expecting 41600 events.
[15:10:33.900] <TB1> INFO: 41600 events read in total (2971ms).
[15:10:33.902] <TB1> INFO: Test took 3829ms.
[15:10:34.197] <TB1> INFO: Expecting 41600 events.
[15:10:37.646] <TB1> INFO: 41600 events read in total (2858ms).
[15:10:37.647] <TB1> INFO: Test took 3719ms.
[15:10:37.936] <TB1> INFO: Expecting 41600 events.
[15:10:41.448] <TB1> INFO: 41600 events read in total (2920ms).
[15:10:41.449] <TB1> INFO: Test took 3777ms.
[15:10:41.738] <TB1> INFO: Expecting 2560 events.
[15:10:42.625] <TB1> INFO: 2560 events read in total (295ms).
[15:10:42.625] <TB1> INFO: Test took 1163ms.
[15:10:42.933] <TB1> INFO: Expecting 2560 events.
[15:10:43.817] <TB1> INFO: 2560 events read in total (293ms).
[15:10:43.817] <TB1> INFO: Test took 1192ms.
[15:10:44.125] <TB1> INFO: Expecting 2560 events.
[15:10:45.008] <TB1> INFO: 2560 events read in total (291ms).
[15:10:45.008] <TB1> INFO: Test took 1190ms.
[15:10:45.316] <TB1> INFO: Expecting 2560 events.
[15:10:46.197] <TB1> INFO: 2560 events read in total (289ms).
[15:10:46.198] <TB1> INFO: Test took 1189ms.
[15:10:46.506] <TB1> INFO: Expecting 2560 events.
[15:10:47.384] <TB1> INFO: 2560 events read in total (287ms).
[15:10:47.385] <TB1> INFO: Test took 1187ms.
[15:10:47.693] <TB1> INFO: Expecting 2560 events.
[15:10:48.574] <TB1> INFO: 2560 events read in total (290ms).
[15:10:48.574] <TB1> INFO: Test took 1189ms.
[15:10:48.882] <TB1> INFO: Expecting 2560 events.
[15:10:49.761] <TB1> INFO: 2560 events read in total (288ms).
[15:10:49.761] <TB1> INFO: Test took 1187ms.
[15:10:50.069] <TB1> INFO: Expecting 2560 events.
[15:10:50.953] <TB1> INFO: 2560 events read in total (292ms).
[15:10:50.953] <TB1> INFO: Test took 1192ms.
[15:10:51.261] <TB1> INFO: Expecting 2560 events.
[15:10:52.144] <TB1> INFO: 2560 events read in total (291ms).
[15:10:52.144] <TB1> INFO: Test took 1190ms.
[15:10:52.451] <TB1> INFO: Expecting 2560 events.
[15:10:53.330] <TB1> INFO: 2560 events read in total (287ms).
[15:10:53.330] <TB1> INFO: Test took 1185ms.
[15:10:53.638] <TB1> INFO: Expecting 2560 events.
[15:10:54.519] <TB1> INFO: 2560 events read in total (290ms).
[15:10:54.520] <TB1> INFO: Test took 1189ms.
[15:10:54.827] <TB1> INFO: Expecting 2560 events.
[15:10:55.708] <TB1> INFO: 2560 events read in total (289ms).
[15:10:55.708] <TB1> INFO: Test took 1188ms.
[15:10:56.016] <TB1> INFO: Expecting 2560 events.
[15:10:56.898] <TB1> INFO: 2560 events read in total (290ms).
[15:10:56.898] <TB1> INFO: Test took 1189ms.
[15:10:57.207] <TB1> INFO: Expecting 2560 events.
[15:10:58.090] <TB1> INFO: 2560 events read in total (292ms).
[15:10:58.090] <TB1> INFO: Test took 1191ms.
[15:10:58.398] <TB1> INFO: Expecting 2560 events.
[15:10:59.285] <TB1> INFO: 2560 events read in total (295ms).
[15:10:59.285] <TB1> INFO: Test took 1194ms.
[15:10:59.593] <TB1> INFO: Expecting 2560 events.
[15:11:00.475] <TB1> INFO: 2560 events read in total (291ms).
[15:11:00.475] <TB1> INFO: Test took 1190ms.
[15:11:00.478] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:11:00.784] <TB1> INFO: Expecting 655360 events.
[15:11:15.217] <TB1> INFO: 655360 events read in total (13842ms).
[15:11:15.227] <TB1> INFO: Expecting 655360 events.
[15:11:29.357] <TB1> INFO: 655360 events read in total (13727ms).
[15:11:29.372] <TB1> INFO: Expecting 655360 events.
[15:11:43.493] <TB1> INFO: 655360 events read in total (13718ms).
[15:11:43.518] <TB1> INFO: Expecting 655360 events.
[15:11:57.646] <TB1> INFO: 655360 events read in total (13725ms).
[15:11:57.668] <TB1> INFO: Expecting 655360 events.
[15:12:11.716] <TB1> INFO: 655360 events read in total (13645ms).
[15:12:11.743] <TB1> INFO: Expecting 655360 events.
[15:12:25.894] <TB1> INFO: 655360 events read in total (13748ms).
[15:12:25.937] <TB1> INFO: Expecting 655360 events.
[15:12:40.008] <TB1> INFO: 655360 events read in total (13668ms).
[15:12:40.043] <TB1> INFO: Expecting 655360 events.
[15:12:54.087] <TB1> INFO: 655360 events read in total (13641ms).
[15:12:54.127] <TB1> INFO: Expecting 655360 events.
[15:13:08.105] <TB1> INFO: 655360 events read in total (13575ms).
[15:13:08.147] <TB1> INFO: Expecting 655360 events.
[15:13:22.217] <TB1> INFO: 655360 events read in total (13667ms).
[15:13:22.266] <TB1> INFO: Expecting 655360 events.
[15:13:36.332] <TB1> INFO: 655360 events read in total (13664ms).
[15:13:36.401] <TB1> INFO: Expecting 655360 events.
[15:13:50.552] <TB1> INFO: 655360 events read in total (13748ms).
[15:13:50.618] <TB1> INFO: Expecting 655360 events.
[15:14:04.647] <TB1> INFO: 655360 events read in total (13627ms).
[15:14:04.716] <TB1> INFO: Expecting 655360 events.
[15:14:18.866] <TB1> INFO: 655360 events read in total (13747ms).
[15:14:18.960] <TB1> INFO: Expecting 655360 events.
[15:14:33.106] <TB1> INFO: 655360 events read in total (13743ms).
[15:14:33.216] <TB1> INFO: Expecting 655360 events.
[15:14:47.333] <TB1> INFO: 655360 events read in total (13714ms).
[15:14:47.437] <TB1> INFO: Test took 226959ms.
[15:14:47.514] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:14:47.779] <TB1> INFO: Expecting 655360 events.
[15:15:02.049] <TB1> INFO: 655360 events read in total (13678ms).
[15:15:02.059] <TB1> INFO: Expecting 655360 events.
[15:15:16.083] <TB1> INFO: 655360 events read in total (13621ms).
[15:15:16.102] <TB1> INFO: Expecting 655360 events.
[15:15:30.029] <TB1> INFO: 655360 events read in total (13524ms).
[15:15:30.053] <TB1> INFO: Expecting 655360 events.
[15:15:43.949] <TB1> INFO: 655360 events read in total (13493ms).
[15:15:43.979] <TB1> INFO: Expecting 655360 events.
[15:15:57.988] <TB1> INFO: 655360 events read in total (13606ms).
[15:15:58.014] <TB1> INFO: Expecting 655360 events.
[15:16:12.087] <TB1> INFO: 655360 events read in total (13670ms).
[15:16:12.129] <TB1> INFO: Expecting 655360 events.
[15:16:25.973] <TB1> INFO: 655360 events read in total (13441ms).
[15:16:26.017] <TB1> INFO: Expecting 655360 events.
[15:16:39.768] <TB1> INFO: 655360 events read in total (13349ms).
[15:16:39.828] <TB1> INFO: Expecting 655360 events.
[15:16:53.786] <TB1> INFO: 655360 events read in total (13555ms).
[15:16:53.827] <TB1> INFO: Expecting 655360 events.
[15:17:07.853] <TB1> INFO: 655360 events read in total (13623ms).
[15:17:07.903] <TB1> INFO: Expecting 655360 events.
[15:17:21.601] <TB1> INFO: 655360 events read in total (13295ms).
[15:17:21.662] <TB1> INFO: Expecting 655360 events.
[15:17:35.427] <TB1> INFO: 655360 events read in total (13362ms).
[15:17:35.494] <TB1> INFO: Expecting 655360 events.
[15:17:49.558] <TB1> INFO: 655360 events read in total (13661ms).
[15:17:49.625] <TB1> INFO: Expecting 655360 events.
[15:18:03.784] <TB1> INFO: 655360 events read in total (13756ms).
[15:18:03.880] <TB1> INFO: Expecting 655360 events.
[15:18:17.996] <TB1> INFO: 655360 events read in total (13713ms).
[15:18:18.131] <TB1> INFO: Expecting 655360 events.
[15:18:32.077] <TB1> INFO: 655360 events read in total (13543ms).
[15:18:32.182] <TB1> INFO: Test took 224668ms.
[15:18:32.337] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.341] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.346] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.350] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.355] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.359] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:18:32.364] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[15:18:32.368] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[15:18:32.373] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[15:18:32.377] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[15:18:32.382] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[15:18:32.387] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[15:18:32.391] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[15:18:32.396] <TB1> INFO: safety margin for low PH: adding 9, margin is now 29
[15:18:32.400] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.405] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.409] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:18:32.414] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[15:18:32.419] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[15:18:32.423] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.428] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.432] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:18:32.437] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[15:18:32.441] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[15:18:32.446] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.451] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:18:32.455] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[15:18:32.460] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[15:18:32.464] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.469] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.473] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.478] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.483] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.488] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:18:32.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C0.dat
[15:18:32.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C1.dat
[15:18:32.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C2.dat
[15:18:32.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C3.dat
[15:18:32.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C4.dat
[15:18:32.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C5.dat
[15:18:32.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C6.dat
[15:18:32.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C7.dat
[15:18:32.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C8.dat
[15:18:32.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C9.dat
[15:18:32.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C10.dat
[15:18:32.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C11.dat
[15:18:32.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C12.dat
[15:18:32.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C13.dat
[15:18:32.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C14.dat
[15:18:32.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters35_C15.dat
[15:18:32.764] <TB1> INFO: Expecting 41600 events.
[15:18:35.875] <TB1> INFO: 41600 events read in total (2519ms).
[15:18:35.876] <TB1> INFO: Test took 3347ms.
[15:18:36.350] <TB1> INFO: Expecting 41600 events.
[15:18:39.342] <TB1> INFO: 41600 events read in total (2401ms).
[15:18:39.343] <TB1> INFO: Test took 3255ms.
[15:18:39.788] <TB1> INFO: Expecting 41600 events.
[15:18:42.870] <TB1> INFO: 41600 events read in total (2490ms).
[15:18:42.871] <TB1> INFO: Test took 3315ms.
[15:18:43.086] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:43.174] <TB1> INFO: Expecting 2560 events.
[15:18:44.059] <TB1> INFO: 2560 events read in total (293ms).
[15:18:44.059] <TB1> INFO: Test took 974ms.
[15:18:44.061] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:44.368] <TB1> INFO: Expecting 2560 events.
[15:18:45.250] <TB1> INFO: 2560 events read in total (291ms).
[15:18:45.250] <TB1> INFO: Test took 1189ms.
[15:18:45.252] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:45.559] <TB1> INFO: Expecting 2560 events.
[15:18:46.442] <TB1> INFO: 2560 events read in total (292ms).
[15:18:46.442] <TB1> INFO: Test took 1190ms.
[15:18:46.444] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:46.750] <TB1> INFO: Expecting 2560 events.
[15:18:47.633] <TB1> INFO: 2560 events read in total (292ms).
[15:18:47.634] <TB1> INFO: Test took 1190ms.
[15:18:47.636] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:47.942] <TB1> INFO: Expecting 2560 events.
[15:18:48.827] <TB1> INFO: 2560 events read in total (294ms).
[15:18:48.827] <TB1> INFO: Test took 1191ms.
[15:18:48.829] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:49.136] <TB1> INFO: Expecting 2560 events.
[15:18:50.018] <TB1> INFO: 2560 events read in total (291ms).
[15:18:50.018] <TB1> INFO: Test took 1189ms.
[15:18:50.020] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:50.327] <TB1> INFO: Expecting 2560 events.
[15:18:51.210] <TB1> INFO: 2560 events read in total (292ms).
[15:18:51.210] <TB1> INFO: Test took 1190ms.
[15:18:51.213] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:51.518] <TB1> INFO: Expecting 2560 events.
[15:18:52.401] <TB1> INFO: 2560 events read in total (291ms).
[15:18:52.402] <TB1> INFO: Test took 1189ms.
[15:18:52.404] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:52.710] <TB1> INFO: Expecting 2560 events.
[15:18:53.589] <TB1> INFO: 2560 events read in total (288ms).
[15:18:53.589] <TB1> INFO: Test took 1185ms.
[15:18:53.592] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:53.898] <TB1> INFO: Expecting 2560 events.
[15:18:54.775] <TB1> INFO: 2560 events read in total (286ms).
[15:18:54.776] <TB1> INFO: Test took 1184ms.
[15:18:54.778] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:55.083] <TB1> INFO: Expecting 2560 events.
[15:18:55.961] <TB1> INFO: 2560 events read in total (286ms).
[15:18:55.961] <TB1> INFO: Test took 1183ms.
[15:18:55.963] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:56.269] <TB1> INFO: Expecting 2560 events.
[15:18:57.152] <TB1> INFO: 2560 events read in total (291ms).
[15:18:57.152] <TB1> INFO: Test took 1189ms.
[15:18:57.154] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:57.460] <TB1> INFO: Expecting 2560 events.
[15:18:58.339] <TB1> INFO: 2560 events read in total (287ms).
[15:18:58.340] <TB1> INFO: Test took 1186ms.
[15:18:58.342] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:58.648] <TB1> INFO: Expecting 2560 events.
[15:18:59.527] <TB1> INFO: 2560 events read in total (287ms).
[15:18:59.527] <TB1> INFO: Test took 1186ms.
[15:18:59.529] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:18:59.836] <TB1> INFO: Expecting 2560 events.
[15:19:00.714] <TB1> INFO: 2560 events read in total (287ms).
[15:19:00.714] <TB1> INFO: Test took 1185ms.
[15:19:00.716] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:01.022] <TB1> INFO: Expecting 2560 events.
[15:19:01.902] <TB1> INFO: 2560 events read in total (288ms).
[15:19:01.902] <TB1> INFO: Test took 1186ms.
[15:19:01.905] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:02.211] <TB1> INFO: Expecting 2560 events.
[15:19:03.089] <TB1> INFO: 2560 events read in total (286ms).
[15:19:03.089] <TB1> INFO: Test took 1184ms.
[15:19:03.091] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:03.397] <TB1> INFO: Expecting 2560 events.
[15:19:04.275] <TB1> INFO: 2560 events read in total (286ms).
[15:19:04.275] <TB1> INFO: Test took 1184ms.
[15:19:04.277] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:04.583] <TB1> INFO: Expecting 2560 events.
[15:19:05.464] <TB1> INFO: 2560 events read in total (289ms).
[15:19:05.465] <TB1> INFO: Test took 1188ms.
[15:19:05.467] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:05.773] <TB1> INFO: Expecting 2560 events.
[15:19:06.650] <TB1> INFO: 2560 events read in total (285ms).
[15:19:06.651] <TB1> INFO: Test took 1184ms.
[15:19:06.653] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:06.959] <TB1> INFO: Expecting 2560 events.
[15:19:07.836] <TB1> INFO: 2560 events read in total (285ms).
[15:19:07.837] <TB1> INFO: Test took 1184ms.
[15:19:07.839] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:08.145] <TB1> INFO: Expecting 2560 events.
[15:19:09.024] <TB1> INFO: 2560 events read in total (287ms).
[15:19:09.024] <TB1> INFO: Test took 1185ms.
[15:19:09.026] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:09.332] <TB1> INFO: Expecting 2560 events.
[15:19:10.213] <TB1> INFO: 2560 events read in total (289ms).
[15:19:10.213] <TB1> INFO: Test took 1187ms.
[15:19:10.215] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:10.521] <TB1> INFO: Expecting 2560 events.
[15:19:11.404] <TB1> INFO: 2560 events read in total (291ms).
[15:19:11.404] <TB1> INFO: Test took 1189ms.
[15:19:11.406] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:11.713] <TB1> INFO: Expecting 2560 events.
[15:19:12.598] <TB1> INFO: 2560 events read in total (294ms).
[15:19:12.599] <TB1> INFO: Test took 1193ms.
[15:19:12.601] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:12.907] <TB1> INFO: Expecting 2560 events.
[15:19:13.791] <TB1> INFO: 2560 events read in total (292ms).
[15:19:13.791] <TB1> INFO: Test took 1191ms.
[15:19:13.793] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:14.099] <TB1> INFO: Expecting 2560 events.
[15:19:14.985] <TB1> INFO: 2560 events read in total (294ms).
[15:19:14.986] <TB1> INFO: Test took 1193ms.
[15:19:14.987] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:15.294] <TB1> INFO: Expecting 2560 events.
[15:19:16.177] <TB1> INFO: 2560 events read in total (291ms).
[15:19:16.177] <TB1> INFO: Test took 1190ms.
[15:19:16.179] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:16.486] <TB1> INFO: Expecting 2560 events.
[15:19:17.371] <TB1> INFO: 2560 events read in total (293ms).
[15:19:17.372] <TB1> INFO: Test took 1193ms.
[15:19:17.373] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:17.680] <TB1> INFO: Expecting 2560 events.
[15:19:18.565] <TB1> INFO: 2560 events read in total (294ms).
[15:19:18.566] <TB1> INFO: Test took 1193ms.
[15:19:18.568] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:18.874] <TB1> INFO: Expecting 2560 events.
[15:19:19.757] <TB1> INFO: 2560 events read in total (292ms).
[15:19:19.757] <TB1> INFO: Test took 1189ms.
[15:19:19.759] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:20.065] <TB1> INFO: Expecting 2560 events.
[15:19:20.951] <TB1> INFO: 2560 events read in total (294ms).
[15:19:20.951] <TB1> INFO: Test took 1193ms.
[15:19:21.413] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 634 seconds
[15:19:21.413] <TB1> INFO: PH scale (per ROC): 41 33 46 42 29 42 32 32 26 35 40 55 33 29 40 43
[15:19:21.413] <TB1> INFO: PH offset (per ROC): 105 84 90 99 80 91 102 99 91 94 104 116 92 107 113 96
[15:19:21.419] <TB1> INFO: Decoding statistics:
[15:19:21.419] <TB1> INFO: General information:
[15:19:21.419] <TB1> INFO: 16bit words read: 127850
[15:19:21.419] <TB1> INFO: valid events total: 20480
[15:19:21.419] <TB1> INFO: empty events: 17995
[15:19:21.419] <TB1> INFO: valid events with pixels: 2485
[15:19:21.419] <TB1> INFO: valid pixel hits: 2485
[15:19:21.419] <TB1> INFO: Event errors: 0
[15:19:21.419] <TB1> INFO: start marker: 0
[15:19:21.419] <TB1> INFO: stop marker: 0
[15:19:21.419] <TB1> INFO: overflow: 0
[15:19:21.419] <TB1> INFO: invalid 5bit words: 0
[15:19:21.419] <TB1> INFO: invalid XOR eye diagram: 0
[15:19:21.419] <TB1> INFO: frame (failed synchr.): 0
[15:19:21.419] <TB1> INFO: idle data (no TBM trl): 0
[15:19:21.419] <TB1> INFO: no data (only TBM hdr): 0
[15:19:21.419] <TB1> INFO: TBM errors: 0
[15:19:21.419] <TB1> INFO: flawed TBM headers: 0
[15:19:21.419] <TB1> INFO: flawed TBM trailers: 0
[15:19:21.420] <TB1> INFO: event ID mismatches: 0
[15:19:21.420] <TB1> INFO: ROC errors: 0
[15:19:21.420] <TB1> INFO: missing ROC header(s): 0
[15:19:21.420] <TB1> INFO: misplaced readback start: 0
[15:19:21.420] <TB1> INFO: Pixel decoding errors: 0
[15:19:21.420] <TB1> INFO: pixel data incomplete: 0
[15:19:21.420] <TB1> INFO: pixel address: 0
[15:19:21.420] <TB1> INFO: pulse height fill bit: 0
[15:19:21.420] <TB1> INFO: buffer corruption: 0
[15:19:21.688] <TB1> INFO: ######################################################################
[15:19:21.688] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[15:19:21.688] <TB1> INFO: ######################################################################
[15:19:21.701] <TB1> INFO: scanning low vcal = 10
[15:19:21.933] <TB1> INFO: Expecting 41600 events.
[15:19:25.516] <TB1> INFO: 41600 events read in total (2992ms).
[15:19:25.516] <TB1> INFO: Test took 3815ms.
[15:19:25.517] <TB1> INFO: scanning low vcal = 20
[15:19:25.817] <TB1> INFO: Expecting 41600 events.
[15:19:29.399] <TB1> INFO: 41600 events read in total (2990ms).
[15:19:29.399] <TB1> INFO: Test took 3881ms.
[15:19:29.401] <TB1> INFO: scanning low vcal = 30
[15:19:29.700] <TB1> INFO: Expecting 41600 events.
[15:19:33.317] <TB1> INFO: 41600 events read in total (3026ms).
[15:19:33.318] <TB1> INFO: Test took 3917ms.
[15:19:33.320] <TB1> INFO: scanning low vcal = 40
[15:19:33.599] <TB1> INFO: Expecting 41600 events.
[15:19:37.523] <TB1> INFO: 41600 events read in total (3332ms).
[15:19:37.525] <TB1> INFO: Test took 4205ms.
[15:19:37.528] <TB1> INFO: scanning low vcal = 50
[15:19:37.804] <TB1> INFO: Expecting 41600 events.
[15:19:41.774] <TB1> INFO: 41600 events read in total (3378ms).
[15:19:41.774] <TB1> INFO: Test took 4245ms.
[15:19:41.777] <TB1> INFO: scanning low vcal = 60
[15:19:42.054] <TB1> INFO: Expecting 41600 events.
[15:19:45.973] <TB1> INFO: 41600 events read in total (3327ms).
[15:19:45.974] <TB1> INFO: Test took 4197ms.
[15:19:45.976] <TB1> INFO: scanning low vcal = 70
[15:19:46.253] <TB1> INFO: Expecting 41600 events.
[15:19:50.191] <TB1> INFO: 41600 events read in total (3346ms).
[15:19:50.192] <TB1> INFO: Test took 4216ms.
[15:19:50.195] <TB1> INFO: scanning low vcal = 80
[15:19:50.471] <TB1> INFO: Expecting 41600 events.
[15:19:54.405] <TB1> INFO: 41600 events read in total (3342ms).
[15:19:54.406] <TB1> INFO: Test took 4211ms.
[15:19:54.409] <TB1> INFO: scanning low vcal = 90
[15:19:54.685] <TB1> INFO: Expecting 41600 events.
[15:19:58.628] <TB1> INFO: 41600 events read in total (3351ms).
[15:19:58.629] <TB1> INFO: Test took 4220ms.
[15:19:58.632] <TB1> INFO: scanning low vcal = 100
[15:19:58.909] <TB1> INFO: Expecting 41600 events.
[15:20:02.827] <TB1> INFO: 41600 events read in total (3327ms).
[15:20:02.827] <TB1> INFO: Test took 4196ms.
[15:20:02.830] <TB1> INFO: scanning low vcal = 110
[15:20:03.107] <TB1> INFO: Expecting 41600 events.
[15:20:07.033] <TB1> INFO: 41600 events read in total (3334ms).
[15:20:07.034] <TB1> INFO: Test took 4203ms.
[15:20:07.037] <TB1> INFO: scanning low vcal = 120
[15:20:07.314] <TB1> INFO: Expecting 41600 events.
[15:20:11.230] <TB1> INFO: 41600 events read in total (3325ms).
[15:20:11.231] <TB1> INFO: Test took 4194ms.
[15:20:11.234] <TB1> INFO: scanning low vcal = 130
[15:20:11.510] <TB1> INFO: Expecting 41600 events.
[15:20:15.440] <TB1> INFO: 41600 events read in total (3338ms).
[15:20:15.441] <TB1> INFO: Test took 4207ms.
[15:20:15.444] <TB1> INFO: scanning low vcal = 140
[15:20:15.721] <TB1> INFO: Expecting 41600 events.
[15:20:19.670] <TB1> INFO: 41600 events read in total (3357ms).
[15:20:19.671] <TB1> INFO: Test took 4227ms.
[15:20:19.675] <TB1> INFO: scanning low vcal = 150
[15:20:19.951] <TB1> INFO: Expecting 41600 events.
[15:20:23.870] <TB1> INFO: 41600 events read in total (3327ms).
[15:20:23.871] <TB1> INFO: Test took 4196ms.
[15:20:23.874] <TB1> INFO: scanning low vcal = 160
[15:20:24.150] <TB1> INFO: Expecting 41600 events.
[15:20:28.072] <TB1> INFO: 41600 events read in total (3330ms).
[15:20:28.073] <TB1> INFO: Test took 4199ms.
[15:20:28.076] <TB1> INFO: scanning low vcal = 170
[15:20:28.377] <TB1> INFO: Expecting 41600 events.
[15:20:32.304] <TB1> INFO: 41600 events read in total (3336ms).
[15:20:32.304] <TB1> INFO: Test took 4228ms.
[15:20:32.308] <TB1> INFO: scanning low vcal = 180
[15:20:32.584] <TB1> INFO: Expecting 41600 events.
[15:20:36.493] <TB1> INFO: 41600 events read in total (3317ms).
[15:20:36.494] <TB1> INFO: Test took 4185ms.
[15:20:36.497] <TB1> INFO: scanning low vcal = 190
[15:20:36.773] <TB1> INFO: Expecting 41600 events.
[15:20:40.730] <TB1> INFO: 41600 events read in total (3366ms).
[15:20:40.731] <TB1> INFO: Test took 4234ms.
[15:20:40.734] <TB1> INFO: scanning low vcal = 200
[15:20:41.011] <TB1> INFO: Expecting 41600 events.
[15:20:44.948] <TB1> INFO: 41600 events read in total (3346ms).
[15:20:44.949] <TB1> INFO: Test took 4215ms.
[15:20:44.951] <TB1> INFO: scanning low vcal = 210
[15:20:45.228] <TB1> INFO: Expecting 41600 events.
[15:20:49.176] <TB1> INFO: 41600 events read in total (3356ms).
[15:20:49.177] <TB1> INFO: Test took 4225ms.
[15:20:49.179] <TB1> INFO: scanning low vcal = 220
[15:20:49.456] <TB1> INFO: Expecting 41600 events.
[15:20:53.407] <TB1> INFO: 41600 events read in total (3359ms).
[15:20:53.408] <TB1> INFO: Test took 4228ms.
[15:20:53.411] <TB1> INFO: scanning low vcal = 230
[15:20:53.688] <TB1> INFO: Expecting 41600 events.
[15:20:57.634] <TB1> INFO: 41600 events read in total (3355ms).
[15:20:57.635] <TB1> INFO: Test took 4224ms.
[15:20:57.639] <TB1> INFO: scanning low vcal = 240
[15:20:57.917] <TB1> INFO: Expecting 41600 events.
[15:21:01.828] <TB1> INFO: 41600 events read in total (3319ms).
[15:21:01.829] <TB1> INFO: Test took 4190ms.
[15:21:01.832] <TB1> INFO: scanning low vcal = 250
[15:21:02.109] <TB1> INFO: Expecting 41600 events.
[15:21:06.014] <TB1> INFO: 41600 events read in total (3314ms).
[15:21:06.015] <TB1> INFO: Test took 4183ms.
[15:21:06.019] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[15:21:06.295] <TB1> INFO: Expecting 41600 events.
[15:21:10.252] <TB1> INFO: 41600 events read in total (3365ms).
[15:21:10.253] <TB1> INFO: Test took 4234ms.
[15:21:10.256] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[15:21:10.532] <TB1> INFO: Expecting 41600 events.
[15:21:14.451] <TB1> INFO: 41600 events read in total (3327ms).
[15:21:14.452] <TB1> INFO: Test took 4196ms.
[15:21:14.454] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[15:21:14.731] <TB1> INFO: Expecting 41600 events.
[15:21:18.662] <TB1> INFO: 41600 events read in total (3340ms).
[15:21:18.663] <TB1> INFO: Test took 4208ms.
[15:21:18.666] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[15:21:18.942] <TB1> INFO: Expecting 41600 events.
[15:21:22.884] <TB1> INFO: 41600 events read in total (3350ms).
[15:21:22.885] <TB1> INFO: Test took 4219ms.
[15:21:22.888] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[15:21:23.164] <TB1> INFO: Expecting 41600 events.
[15:21:27.122] <TB1> INFO: 41600 events read in total (3366ms).
[15:21:27.123] <TB1> INFO: Test took 4235ms.
[15:21:27.579] <TB1> INFO: PixTestGainPedestal::measure() done
[15:22:05.597] <TB1> INFO: PixTestGainPedestal::fit() done
[15:22:05.597] <TB1> INFO: non-linearity mean: 0.961 0.992 0.956 0.941 1.060 0.948 0.960 0.940 0.908 0.936 0.932 0.982 1.018 0.935 0.940 0.962
[15:22:05.597] <TB1> INFO: non-linearity RMS: 0.036 0.174 0.029 0.099 0.142 0.055 0.156 0.100 0.153 0.088 0.113 0.004 0.167 0.177 0.073 0.029
[15:22:05.597] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C0.dat
[15:22:05.616] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C1.dat
[15:22:05.631] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C2.dat
[15:22:05.646] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C3.dat
[15:22:05.661] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C4.dat
[15:22:05.676] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C5.dat
[15:22:05.692] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C6.dat
[15:22:05.707] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C7.dat
[15:22:05.722] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C8.dat
[15:22:05.738] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C9.dat
[15:22:05.753] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C10.dat
[15:22:05.768] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C11.dat
[15:22:05.782] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C12.dat
[15:22:05.797] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C13.dat
[15:22:05.812] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C14.dat
[15:22:05.827] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//phCalibrationFitErr35_C15.dat
[15:22:05.842] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 164 seconds
[15:22:05.842] <TB1> INFO: Decoding statistics:
[15:22:05.842] <TB1> INFO: General information:
[15:22:05.842] <TB1> INFO: 16bit words read: 3277942
[15:22:05.842] <TB1> INFO: valid events total: 332800
[15:22:05.842] <TB1> INFO: empty events: 1130
[15:22:05.842] <TB1> INFO: valid events with pixels: 331670
[15:22:05.842] <TB1> INFO: valid pixel hits: 640571
[15:22:05.842] <TB1> INFO: Event errors: 0
[15:22:05.842] <TB1> INFO: start marker: 0
[15:22:05.842] <TB1> INFO: stop marker: 0
[15:22:05.842] <TB1> INFO: overflow: 0
[15:22:05.842] <TB1> INFO: invalid 5bit words: 0
[15:22:05.842] <TB1> INFO: invalid XOR eye diagram: 0
[15:22:05.842] <TB1> INFO: frame (failed synchr.): 0
[15:22:05.842] <TB1> INFO: idle data (no TBM trl): 0
[15:22:05.842] <TB1> INFO: no data (only TBM hdr): 0
[15:22:05.842] <TB1> INFO: TBM errors: 0
[15:22:05.842] <TB1> INFO: flawed TBM headers: 0
[15:22:05.842] <TB1> INFO: flawed TBM trailers: 0
[15:22:05.842] <TB1> INFO: event ID mismatches: 0
[15:22:05.842] <TB1> INFO: ROC errors: 0
[15:22:05.842] <TB1> INFO: missing ROC header(s): 0
[15:22:05.842] <TB1> INFO: misplaced readback start: 0
[15:22:05.842] <TB1> INFO: Pixel decoding errors: 0
[15:22:05.842] <TB1> INFO: pixel data incomplete: 0
[15:22:05.842] <TB1> INFO: pixel address: 0
[15:22:05.842] <TB1> INFO: pulse height fill bit: 0
[15:22:05.842] <TB1> INFO: buffer corruption: 0
[15:22:05.857] <TB1> INFO: Decoding statistics:
[15:22:05.857] <TB1> INFO: General information:
[15:22:05.857] <TB1> INFO: 16bit words read: 3407328
[15:22:05.857] <TB1> INFO: valid events total: 353536
[15:22:05.857] <TB1> INFO: empty events: 19381
[15:22:05.857] <TB1> INFO: valid events with pixels: 334155
[15:22:05.857] <TB1> INFO: valid pixel hits: 643056
[15:22:05.857] <TB1> INFO: Event errors: 0
[15:22:05.857] <TB1> INFO: start marker: 0
[15:22:05.857] <TB1> INFO: stop marker: 0
[15:22:05.857] <TB1> INFO: overflow: 0
[15:22:05.857] <TB1> INFO: invalid 5bit words: 0
[15:22:05.858] <TB1> INFO: invalid XOR eye diagram: 0
[15:22:05.858] <TB1> INFO: frame (failed synchr.): 0
[15:22:05.858] <TB1> INFO: idle data (no TBM trl): 0
[15:22:05.858] <TB1> INFO: no data (only TBM hdr): 0
[15:22:05.858] <TB1> INFO: TBM errors: 0
[15:22:05.858] <TB1> INFO: flawed TBM headers: 0
[15:22:05.858] <TB1> INFO: flawed TBM trailers: 0
[15:22:05.858] <TB1> INFO: event ID mismatches: 0
[15:22:05.858] <TB1> INFO: ROC errors: 0
[15:22:05.858] <TB1> INFO: missing ROC header(s): 0
[15:22:05.858] <TB1> INFO: misplaced readback start: 0
[15:22:05.858] <TB1> INFO: Pixel decoding errors: 0
[15:22:05.858] <TB1> INFO: pixel data incomplete: 0
[15:22:05.858] <TB1> INFO: pixel address: 0
[15:22:05.858] <TB1> INFO: pulse height fill bit: 0
[15:22:05.858] <TB1> INFO: buffer corruption: 0
[15:22:05.858] <TB1> INFO: enter test to run
[15:22:05.858] <TB1> INFO: test: Trim80 no parameter change
[15:22:05.858] <TB1> INFO: running: trim80
[15:22:05.874] <TB1> INFO: ######################################################################
[15:22:05.874] <TB1> INFO: PixTestTrim80::doTest()
[15:22:05.874] <TB1> INFO: ######################################################################
[15:22:05.875] <TB1> INFO: ----------------------------------------------------------------------
[15:22:05.875] <TB1> INFO: PixTestTrim80::trimTest() ntrig = 8, vcal = 80
[15:22:05.875] <TB1> INFO: ----------------------------------------------------------------------
[15:22:05.926] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[15:22:05.926] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:22:05.937] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:22:05.937] <TB1> INFO: run 1 of 1
[15:22:06.205] <TB1> INFO: Expecting 5025280 events.
[15:22:33.570] <TB1> INFO: 685768 events read in total (26773ms).
[15:23:00.353] <TB1> INFO: 1368336 events read in total (53556ms).
[15:23:27.300] <TB1> INFO: 2049032 events read in total (80503ms).
[15:23:54.343] <TB1> INFO: 2728384 events read in total (107546ms).
[15:24:21.584] <TB1> INFO: 3408440 events read in total (134787ms).
[15:24:49.063] <TB1> INFO: 4087848 events read in total (162266ms).
[15:25:16.270] <TB1> INFO: 4767784 events read in total (189473ms).
[15:25:26.901] <TB1> INFO: 5025280 events read in total (200104ms).
[15:25:26.000] <TB1> INFO: Test took 201063ms.
[15:25:50.661] <TB1> INFO: ROC 0 VthrComp = 78
[15:25:50.661] <TB1> INFO: ROC 1 VthrComp = 73
[15:25:50.662] <TB1> INFO: ROC 2 VthrComp = 82
[15:25:50.662] <TB1> INFO: ROC 3 VthrComp = 90
[15:25:50.663] <TB1> INFO: ROC 4 VthrComp = 77
[15:25:50.663] <TB1> INFO: ROC 5 VthrComp = 72
[15:25:50.663] <TB1> INFO: ROC 6 VthrComp = 72
[15:25:50.663] <TB1> INFO: ROC 7 VthrComp = 73
[15:25:50.663] <TB1> INFO: ROC 8 VthrComp = 88
[15:25:50.663] <TB1> INFO: ROC 9 VthrComp = 78
[15:25:50.663] <TB1> INFO: ROC 10 VthrComp = 89
[15:25:50.664] <TB1> INFO: ROC 11 VthrComp = 75
[15:25:50.664] <TB1> INFO: ROC 12 VthrComp = 72
[15:25:50.664] <TB1> INFO: ROC 13 VthrComp = 79
[15:25:50.664] <TB1> INFO: ROC 14 VthrComp = 73
[15:25:50.664] <TB1> INFO: ROC 15 VthrComp = 88
[15:25:50.903] <TB1> INFO: Expecting 41600 events.
[15:25:54.426] <TB1> INFO: 41600 events read in total (2931ms).
[15:25:54.427] <TB1> INFO: Test took 3761ms.
[15:25:54.436] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[15:25:54.436] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:25:54.445] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:25:54.445] <TB1> INFO: run 1 of 1
[15:25:54.723] <TB1> INFO: Expecting 5025280 events.
[15:26:22.340] <TB1> INFO: 689120 events read in total (27026ms).
[15:26:49.322] <TB1> INFO: 1374248 events read in total (54008ms).
[15:27:17.144] <TB1> INFO: 2059488 events read in total (81830ms).
[15:27:44.547] <TB1> INFO: 2742152 events read in total (109233ms).
[15:28:11.669] <TB1> INFO: 3422048 events read in total (136356ms).
[15:28:38.917] <TB1> INFO: 4100672 events read in total (163603ms).
[15:29:06.008] <TB1> INFO: 4777688 events read in total (190694ms).
[15:29:16.367] <TB1> INFO: 5025280 events read in total (201053ms).
[15:29:16.468] <TB1> INFO: Test took 202023ms.
[15:29:39.931] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 110.206 for pixel 0/78 mean/min/max = 94.1083/77.762/110.455
[15:29:39.934] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 116.28 for pixel 0/75 mean/min/max = 96.5637/76.8097/116.318
[15:29:39.935] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 107.501 for pixel 0/31 mean/min/max = 91.516/75.4847/107.547
[15:29:39.935] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 112.56 for pixel 51/34 mean/min/max = 94.7899/76.894/112.686
[15:29:39.936] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 110.989 for pixel 0/69 mean/min/max = 94.5586/78.1006/111.017
[15:29:39.937] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 110.999 for pixel 18/77 mean/min/max = 93.9608/76.8305/111.091
[15:29:39.937] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 113.616 for pixel 0/13 mean/min/max = 95.2087/76.4657/113.952
[15:29:39.938] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 112.149 for pixel 0/77 mean/min/max = 95.3063/77.9994/112.613
[15:29:39.938] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 111.592 for pixel 0/29 mean/min/max = 93.9521/76.1376/111.767
[15:29:39.939] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 111.673 for pixel 0/6 mean/min/max = 94.7957/77.8228/111.769
[15:29:39.939] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 111.532 for pixel 0/27 mean/min/max = 93.5402/75.4863/111.594
[15:29:39.940] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 110.047 for pixel 0/14 mean/min/max = 93.6331/77.0618/110.204
[15:29:39.941] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 106.032 for pixel 0/26 mean/min/max = 91.438/76.689/106.187
[15:29:39.941] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 112.189 for pixel 20/79 mean/min/max = 95.0746/77.6932/112.456
[15:29:39.942] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 111.331 for pixel 0/68 mean/min/max = 94.6946/77.8325/111.557
[15:29:39.942] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 110.204 for pixel 51/26 mean/min/max = 92.8192/75.2974/110.341
[15:29:39.943] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:29:40.032] <TB1> INFO: Expecting 411648 events.
[15:29:49.444] <TB1> INFO: 411648 events read in total (8820ms).
[15:29:49.451] <TB1> INFO: Expecting 411648 events.
[15:29:58.536] <TB1> INFO: 411648 events read in total (8682ms).
[15:29:58.548] <TB1> INFO: Expecting 411648 events.
[15:30:07.742] <TB1> INFO: 411648 events read in total (8791ms).
[15:30:07.754] <TB1> INFO: Expecting 411648 events.
[15:30:16.954] <TB1> INFO: 411648 events read in total (8797ms).
[15:30:16.969] <TB1> INFO: Expecting 411648 events.
[15:30:26.031] <TB1> INFO: 411648 events read in total (8659ms).
[15:30:26.048] <TB1> INFO: Expecting 411648 events.
[15:30:35.214] <TB1> INFO: 411648 events read in total (8763ms).
[15:30:35.241] <TB1> INFO: Expecting 411648 events.
[15:30:44.346] <TB1> INFO: 411648 events read in total (8702ms).
[15:30:44.371] <TB1> INFO: Expecting 411648 events.
[15:30:53.497] <TB1> INFO: 411648 events read in total (8719ms).
[15:30:53.530] <TB1> INFO: Expecting 411648 events.
[15:31:02.728] <TB1> INFO: 411648 events read in total (8795ms).
[15:31:02.797] <TB1> INFO: Expecting 411648 events.
[15:31:11.913] <TB1> INFO: 411648 events read in total (8714ms).
[15:31:11.959] <TB1> INFO: Expecting 411648 events.
[15:31:21.056] <TB1> INFO: 411648 events read in total (8694ms).
[15:31:21.140] <TB1> INFO: Expecting 411648 events.
[15:31:30.183] <TB1> INFO: 411648 events read in total (8640ms).
[15:31:30.220] <TB1> INFO: Expecting 411648 events.
[15:31:39.371] <TB1> INFO: 411648 events read in total (8748ms).
[15:31:39.437] <TB1> INFO: Expecting 411648 events.
[15:31:48.523] <TB1> INFO: 411648 events read in total (8683ms).
[15:31:48.595] <TB1> INFO: Expecting 411648 events.
[15:31:57.703] <TB1> INFO: 411648 events read in total (8705ms).
[15:31:57.820] <TB1> INFO: Expecting 411648 events.
[15:32:06.891] <TB1> INFO: 411648 events read in total (8668ms).
[15:32:06.975] <TB1> INFO: Test took 147033ms.
[15:32:08.491] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[15:32:08.501] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:32:08.501] <TB1> INFO: run 1 of 1
[15:32:08.744] <TB1> INFO: Expecting 5025280 events.
[15:32:35.907] <TB1> INFO: 666952 events read in total (26572ms).
[15:33:02.621] <TB1> INFO: 1332112 events read in total (53285ms).
[15:33:29.758] <TB1> INFO: 1996336 events read in total (80422ms).
[15:33:56.771] <TB1> INFO: 2658256 events read in total (107435ms).
[15:34:23.437] <TB1> INFO: 3316296 events read in total (134101ms).
[15:34:50.232] <TB1> INFO: 3973504 events read in total (160896ms).
[15:35:16.708] <TB1> INFO: 4628640 events read in total (187372ms).
[15:35:33.133] <TB1> INFO: 5025280 events read in total (203797ms).
[15:35:33.185] <TB1> INFO: Test took 204684ms.
[15:35:57.595] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 47.060607 .. 100.288035
[15:35:57.851] <TB1> INFO: Expecting 208000 events.
[15:36:07.482] <TB1> INFO: 208000 events read in total (9039ms).
[15:36:07.482] <TB1> INFO: Test took 9886ms.
[15:36:07.532] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 37 .. 110 (-1/-1) hits flags = 528 (plus default)
[15:36:07.543] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:36:07.543] <TB1> INFO: run 1 of 1
[15:36:07.821] <TB1> INFO: Expecting 2462720 events.
[15:36:36.153] <TB1> INFO: 703248 events read in total (27741ms).
[15:37:03.927] <TB1> INFO: 1405824 events read in total (55515ms).
[15:37:31.311] <TB1> INFO: 2102568 events read in total (82899ms).
[15:37:45.972] <TB1> INFO: 2462720 events read in total (97560ms).
[15:37:46.007] <TB1> INFO: Test took 98464ms.
[15:38:03.773] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 54.739842 .. 91.657470
[15:38:04.037] <TB1> INFO: Expecting 208000 events.
[15:38:13.767] <TB1> INFO: 208000 events read in total (9138ms).
[15:38:13.768] <TB1> INFO: Test took 9993ms.
[15:38:13.833] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 44 .. 101 (-1/-1) hits flags = 528 (plus default)
[15:38:13.844] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:38:13.845] <TB1> INFO: run 1 of 1
[15:38:14.122] <TB1> INFO: Expecting 1930240 events.
[15:38:43.351] <TB1> INFO: 714736 events read in total (28637ms).
[15:39:11.349] <TB1> INFO: 1428456 events read in total (56635ms).
[15:39:31.157] <TB1> INFO: 1930240 events read in total (76443ms).
[15:39:31.186] <TB1> INFO: Test took 77342ms.
[15:39:49.195] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 59.259016 .. 89.231282
[15:39:49.430] <TB1> INFO: Expecting 208000 events.
[15:39:59.104] <TB1> INFO: 208000 events read in total (9082ms).
[15:39:59.105] <TB1> INFO: Test took 9908ms.
[15:39:59.157] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 49 .. 99 (-1/-1) hits flags = 528 (plus default)
[15:39:59.169] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:39:59.169] <TB1> INFO: run 1 of 1
[15:39:59.446] <TB1> INFO: Expecting 1697280 events.
[15:40:27.763] <TB1> INFO: 710288 events read in total (27725ms).
[15:40:55.966] <TB1> INFO: 1419792 events read in total (55928ms).
[15:41:07.264] <TB1> INFO: 1697280 events read in total (67226ms).
[15:41:07.297] <TB1> INFO: Test took 68129ms.
[15:41:23.542] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 61.840475 .. 86.480009
[15:41:23.791] <TB1> INFO: Expecting 208000 events.
[15:41:33.776] <TB1> INFO: 208000 events read in total (9393ms).
[15:41:33.777] <TB1> INFO: Test took 10233ms.
[15:41:33.827] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 51 .. 96 (-1/-1) hits flags = 528 (plus default)
[15:41:33.837] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:41:33.838] <TB1> INFO: run 1 of 1
[15:41:34.115] <TB1> INFO: Expecting 1530880 events.
[15:42:02.986] <TB1> INFO: 720872 events read in total (28279ms).
[15:42:31.081] <TB1> INFO: 1441064 events read in total (56374ms).
[15:42:35.155] <TB1> INFO: 1530880 events read in total (60448ms).
[15:42:35.180] <TB1> INFO: Test took 61342ms.
[15:42:50.478] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 60 .. 100
[15:42:50.478] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 60 .. 100 (-1/-1) hits flags = 528 (plus default)
[15:42:50.490] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:42:50.490] <TB1> INFO: run 1 of 1
[15:42:50.742] <TB1> INFO: Expecting 1364480 events.
[15:43:18.973] <TB1> INFO: 668424 events read in total (27639ms).
[15:43:45.964] <TB1> INFO: 1336424 events read in total (54630ms).
[15:43:47.525] <TB1> INFO: 1364480 events read in total (56191ms).
[15:43:47.553] <TB1> INFO: Test took 57063ms.
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C0.dat
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C1.dat
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C2.dat
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C3.dat
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C4.dat
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C5.dat
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C6.dat
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C7.dat
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C8.dat
[15:44:03.473] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C9.dat
[15:44:03.474] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C10.dat
[15:44:03.474] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C11.dat
[15:44:03.474] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C12.dat
[15:44:03.474] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C13.dat
[15:44:03.474] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C14.dat
[15:44:03.474] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//dacParameters80_C15.dat
[15:44:03.474] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C0.dat
[15:44:03.480] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C1.dat
[15:44:03.486] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C2.dat
[15:44:03.492] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C3.dat
[15:44:03.497] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C4.dat
[15:44:03.503] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C5.dat
[15:44:03.509] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C6.dat
[15:44:03.515] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C7.dat
[15:44:03.521] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C8.dat
[15:44:03.527] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C9.dat
[15:44:03.533] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C10.dat
[15:44:03.539] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C11.dat
[15:44:03.545] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C12.dat
[15:44:03.551] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C13.dat
[15:44:03.557] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C14.dat
[15:44:03.562] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1132_FullQualification_2016-11-07_11h20m_1478514052//003_FulltestTrim80_p17//trimParameters80_C15.dat
[15:44:03.568] <TB1> INFO: PixTestTrim80::trimTest() done
[15:44:03.568] <TB1> INFO: vtrim: 113 102 103 107 115 97 100 115 123 116 126 109 90 104 99 117
[15:44:03.568] <TB1> INFO: vthrcomp: 78 73 82 90 77 72 72 73 88 78 89 75 72 79 73 88
[15:44:03.568] <TB1> INFO: vcal mean: 80.00 79.96 79.99 79.95 80.00 79.93 79.96 79.98 79.96 79.94 79.92 79.99 79.96 79.98 79.99 79.91
[15:44:03.568] <TB1> INFO: vcal RMS: 0.83 0.90 0.78 0.87 0.81 0.76 0.84 0.86 1.49 1.45 1.51 0.74 0.71 0.83 0.74 0.78
[15:44:03.568] <TB1> INFO: bits mean: 10.05 9.20 10.10 9.42 9.55 9.61 9.60 9.75 10.26 9.69 10.51 9.65 9.61 9.57 9.16 10.18
[15:44:03.568] <TB1> INFO: bits RMS: 2.00 2.36 2.33 2.33 2.13 2.27 2.27 2.08 2.06 2.09 2.01 2.25 2.41 2.17 2.31 2.22
[15:44:03.574] <TB1> INFO: ----------------------------------------------------------------------
[15:44:03.574] <TB1> INFO: PixTestTrim80::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[15:44:03.575] <TB1> INFO: ----------------------------------------------------------------------
[15:44:03.577] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[15:44:03.587] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:44:03.588] <TB1> INFO: run 1 of 1
[15:44:03.820] <TB1> INFO: Expecting 4160000 events.
[15:44:36.692] <TB1> INFO: 782410 events read in total (32281ms).
[15:45:08.393] <TB1> INFO: 1558865 events read in total (63982ms).
[15:45:40.459] <TB1> INFO: 2330890 events read in total (96048ms).
[15:46:12.385] <TB1> INFO: 3099955 events read in total (127974ms).
[15:46:44.177] <TB1> INFO: 3866450 events read in total (159766ms).
[15:46:56.385] <TB1> INFO: 4160000 events read in total (171974ms).
[15:46:56.431] <TB1> INFO: Test took 172843ms.
[15:47:21.432] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 214 (-1/-1) hits flags = 528 (plus default)
[15:47:21.443] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:47:21.443] <TB1> INFO: run 1 of 1
[15:47:21.675] <TB1> INFO: Expecting 4472000 events.
[15:47:53.803] <TB1> INFO: 732395 events read in total (31537ms).
[15:48:24.530] <TB1> INFO: 1461250 events read in total (62264ms).
[15:48:55.317] <TB1> INFO: 2186975 events read in total (93051ms).
[15:49:26.383] <TB1> INFO: 2909910 events read in total (124117ms).
[15:49:57.174] <TB1> INFO: 3632500 events read in total (154908ms).
[15:50:28.229] <TB1> INFO: 4354190 events read in total (185963ms).
[15:50:33.424] <TB1> INFO: 4472000 events read in total (191158ms).
[15:50:33.477] <TB1> INFO: Test took 192034ms.
[15:51:00.915] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 214 (-1/-1) hits flags = 528 (plus default)
[15:51:00.925] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:51:00.925] <TB1> INFO: run 1 of 1
[15:51:01.159] <TB1> INFO: Expecting 4472000 events.
[15:51:32.760] <TB1> INFO: 732815 events read in total (31009ms).
[15:52:04.491] <TB1> INFO: 1461900 events read in total (62740ms).
[15:52:35.080] <TB1> INFO: 2187820 events read in total (93329ms).
[15:53:05.687] <TB1> INFO: 2910970 events read in total (123936ms).
[15:53:36.457] <TB1> INFO: 3633855 events read in total (154706ms).
[15:54:07.089] <TB1> INFO: 4355900 events read in total (185338ms).
[15:54:12.284] <TB1> INFO: 4472000 events read in total (190533ms).
[15:54:12.335] <TB1> INFO: Test took 191410ms.
[15:54:40.265] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 214 (-1/-1) hits flags = 528 (plus default)
[15:54:40.277] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:54:40.277] <TB1> INFO: run 1 of 1
[15:54:40.563] <TB1> INFO: Expecting 4472000 events.
[15:55:11.892] <TB1> INFO: 732880 events read in total (30738ms).
[15:55:42.613] <TB1> INFO: 1461930 events read in total (61459ms).
[15:56:15.113] <TB1> INFO: 2187950 events read in total (93959ms).
[15:56:45.763] <TB1> INFO: 2911110 events read in total (124609ms).
[15:57:16.425] <TB1> INFO: 3634245 events read in total (155271ms).
[15:57:47.259] <TB1> INFO: 4356590 events read in total (186105ms).
[15:57:52.473] <TB1> INFO: 4472000 events read in total (191319ms).
[15:57:52.524] <TB1> INFO: Test took 192246ms.
[15:58:21.910] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 216 (-1/-1) hits flags = 528 (plus default)
[15:58:21.920] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:58:21.920] <TB1> INFO: run 1 of 1
[15:58:22.152] <TB1> INFO: Expecting 4513600 events.
[15:58:53.630] <TB1> INFO: 730315 events read in total (30886ms).
[15:59:24.351] <TB1> INFO: 1457055 events read in total (61607ms).
[15:59:55.668] <TB1> INFO: 2181030 events read in total (92924ms).
[16:00:26.357] <TB1> INFO: 2902185 events read in total (123613ms).
[16:00:57.104] <TB1> INFO: 3622530 events read in total (154360ms).
[16:01:27.646] <TB1> INFO: 4342475 events read in total (184902ms).
[16:01:35.142] <TB1> INFO: 4513600 events read in total (192398ms).
[16:01:35.197] <TB1> INFO: Test took 193276ms.
[16:02:03.597] <TB1> INFO: PixTestTrim80::trimBitTest() done
[16:02:03.598] <TB1> INFO: PixTestTrim80::doTest() done, duration: 2397 seconds
[16:02:04.406] <TB1> INFO: enter test to run
[16:02:04.406] <TB1> INFO: test: exit no parameter change
[16:02:04.523] <TB1> QUIET: Connection to board 153 closed.
[16:02:04.524] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud