Test Date: 2016-11-04 10:05
Analysis date: 2016-11-07 10:35
Logfile
LogfileView
[18:29:56.696] <TB1> INFO: *** Welcome to pxar ***
[18:29:56.696] <TB1> INFO: *** Today: 2016/11/04
[18:29:56.702] <TB1> INFO: *** Version: c8ba-dirty
[18:29:56.702] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C15.dat
[18:29:56.703] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[18:29:56.703] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//defaultMaskFile.dat
[18:29:56.703] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters_C15.dat
[18:29:56.757] <TB1> INFO: clk: 4
[18:29:56.757] <TB1> INFO: ctr: 4
[18:29:56.757] <TB1> INFO: sda: 19
[18:29:56.757] <TB1> INFO: tin: 9
[18:29:56.757] <TB1> INFO: level: 15
[18:29:56.757] <TB1> INFO: triggerdelay: 0
[18:29:56.758] <TB1> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[18:29:56.758] <TB1> INFO: Log level: INFO
[18:29:56.766] <TB1> INFO: Found DTB DTB_WXBYFL
[18:29:56.776] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[18:29:56.778] <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:
------------------------------------------------------
[18:29:56.780] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[18:29:58.332] <TB1> INFO: DUT info:
[18:29:58.332] <TB1> INFO: The DUT currently contains the following objects:
[18:29:58.332] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[18:29:58.332] <TB1> INFO: TBM Core alpha (0): 7 registers set
[18:29:58.332] <TB1> INFO: TBM Core beta (1): 7 registers set
[18:29:58.332] <TB1> INFO: TBM Core alpha (2): 7 registers set
[18:29:58.332] <TB1> INFO: TBM Core beta (3): 7 registers set
[18:29:58.332] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[18:29:58.332] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.332] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:29:58.733] <TB1> INFO: enter 'restricted' command line mode
[18:29:58.733] <TB1> INFO: enter test to run
[18:29:58.733] <TB1> INFO: test: pretest no parameter change
[18:29:58.733] <TB1> INFO: running: pretest
[18:29:59.277] <TB1> INFO: ######################################################################
[18:29:59.277] <TB1> INFO: PixTestPretest::doTest()
[18:29:59.277] <TB1> INFO: ######################################################################
[18:29:59.278] <TB1> INFO: ----------------------------------------------------------------------
[18:29:59.278] <TB1> INFO: PixTestPretest::programROC()
[18:29:59.278] <TB1> INFO: ----------------------------------------------------------------------
[18:30:17.291] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[18:30:17.291] <TB1> INFO: IA differences per ROC: 19.3 16.1 18.5 20.1 17.7 19.3 19.3 16.9 16.1 20.9 16.1 18.5 18.5 17.7 18.5 18.5
[18:30:17.327] <TB1> INFO: ----------------------------------------------------------------------
[18:30:17.327] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[18:30:17.327] <TB1> INFO: ----------------------------------------------------------------------
[18:30:38.570] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 383.5 mA = 23.9688 mA/ROC
[18:30:38.570] <TB1> INFO: i(loss) [mA/ROC]: 20.1 19.3 19.3 19.3 20.9 19.3 20.1 20.9 20.1 20.1 19.3 20.1 20.1 20.1 18.5 19.3
[18:30:38.601] <TB1> INFO: ----------------------------------------------------------------------
[18:30:38.601] <TB1> INFO: PixTestPretest::findTiming()
[18:30:38.601] <TB1> INFO: ----------------------------------------------------------------------
[18:30:38.601] <TB1> INFO: PixTestCmd::init()
[18:30:39.160] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[18:31:10.004] <TB1> INFO: TBM phases: 160MHz: 7, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[18:31:10.004] <TB1> INFO: (success/tries = 100/100), width = 4
[18:31:11.509] <TB1> INFO: ----------------------------------------------------------------------
[18:31:11.510] <TB1> INFO: PixTestPretest::findWorkingPixel()
[18:31:11.510] <TB1> INFO: ----------------------------------------------------------------------
[18:31:11.601] <TB1> INFO: Expecting 231680 events.
[18:31:21.274] <TB1> INFO: 231680 events read in total (9081ms).
[18:31:21.281] <TB1> INFO: Test took 9769ms.
[18:31:21.527] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[18:31:21.561] <TB1> INFO: ----------------------------------------------------------------------
[18:31:21.561] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[18:31:21.561] <TB1> INFO: ----------------------------------------------------------------------
[18:31:21.653] <TB1> INFO: Expecting 231680 events.
[18:31:31.321] <TB1> INFO: 231680 events read in total (9076ms).
[18:31:31.329] <TB1> INFO: Test took 9764ms.
[18:31:31.584] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[18:31:31.584] <TB1> INFO: CalDel: 87 91 95 91 95 91 81 83 80 96 91 88 94 98 99 90
[18:31:31.584] <TB1> INFO: VthrComp: 51 54 51 57 51 51 54 51 54 52 51 51 59 52 51 51
[18:31:31.586] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C0.dat
[18:31:31.586] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C1.dat
[18:31:31.586] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C2.dat
[18:31:31.586] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C3.dat
[18:31:31.586] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C4.dat
[18:31:31.586] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C5.dat
[18:31:31.586] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C6.dat
[18:31:31.587] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C7.dat
[18:31:31.587] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C8.dat
[18:31:31.587] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C9.dat
[18:31:31.587] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C10.dat
[18:31:31.587] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C11.dat
[18:31:31.587] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C12.dat
[18:31:31.587] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C13.dat
[18:31:31.587] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C14.dat
[18:31:31.587] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C15.dat
[18:31:31.588] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C0a.dat
[18:31:31.588] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C0b.dat
[18:31:31.588] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C1a.dat
[18:31:31.588] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[18:31:31.588] <TB1> INFO: PixTestPretest::doTest() done, duration: 92 seconds
[18:31:31.684] <TB1> INFO: enter test to run
[18:31:31.684] <TB1> INFO: test: fulltest no parameter change
[18:31:31.684] <TB1> INFO: running: fulltest
[18:31:31.684] <TB1> INFO: ######################################################################
[18:31:31.684] <TB1> INFO: PixTestFullTest::doTest()
[18:31:31.684] <TB1> INFO: ######################################################################
[18:31:31.685] <TB1> INFO: ######################################################################
[18:31:31.685] <TB1> INFO: PixTestAlive::doTest()
[18:31:31.685] <TB1> INFO: ######################################################################
[18:31:31.686] <TB1> INFO: ----------------------------------------------------------------------
[18:31:31.686] <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)
[18:31:31.686] <TB1> INFO: ----------------------------------------------------------------------
[18:31:31.921] <TB1> INFO: Expecting 41600 events.
[18:31:35.442] <TB1> INFO: 41600 events read in total (2930ms).
[18:31:35.443] <TB1> INFO: Test took 3755ms.
[18:31:35.670] <TB1> INFO: PixTestAlive::aliveTest() done
[18:31:35.670] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 57 0 0 2 0 0 0 29 22 0 0 0 0
[18:31:35.671] <TB1> INFO: ----------------------------------------------------------------------
[18:31:35.671] <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)
[18:31:35.671] <TB1> INFO: ----------------------------------------------------------------------
[18:31:35.905] <TB1> INFO: Expecting 41600 events.
[18:31:38.815] <TB1> INFO: 41600 events read in total (2318ms).
[18:31:38.816] <TB1> INFO: Test took 3144ms.
[18:31:38.816] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[18:31:39.056] <TB1> INFO: PixTestAlive::maskTest() done
[18:31:39.056] <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
[18:31:39.057] <TB1> INFO: ----------------------------------------------------------------------
[18:31:39.057] <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)
[18:31:39.057] <TB1> INFO: ----------------------------------------------------------------------
[18:31:39.300] <TB1> INFO: Expecting 41600 events.
[18:31:42.831] <TB1> INFO: 41600 events read in total (2939ms).
[18:31:42.832] <TB1> INFO: Test took 3774ms.
[18:31:43.061] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[18:31:43.061] <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
[18:31:43.062] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[18:31:43.062] <TB1> INFO: Decoding statistics:
[18:31:43.062] <TB1> INFO: General information:
[18:31:43.062] <TB1> INFO: 16bit words read: 0
[18:31:43.062] <TB1> INFO: valid events total: 0
[18:31:43.062] <TB1> INFO: empty events: 0
[18:31:43.062] <TB1> INFO: valid events with pixels: 0
[18:31:43.062] <TB1> INFO: valid pixel hits: 0
[18:31:43.062] <TB1> INFO: Event errors: 0
[18:31:43.062] <TB1> INFO: start marker: 0
[18:31:43.062] <TB1> INFO: stop marker: 0
[18:31:43.062] <TB1> INFO: overflow: 0
[18:31:43.062] <TB1> INFO: invalid 5bit words: 0
[18:31:43.062] <TB1> INFO: invalid XOR eye diagram: 0
[18:31:43.062] <TB1> INFO: frame (failed synchr.): 0
[18:31:43.062] <TB1> INFO: idle data (no TBM trl): 0
[18:31:43.062] <TB1> INFO: no data (only TBM hdr): 0
[18:31:43.062] <TB1> INFO: TBM errors: 0
[18:31:43.062] <TB1> INFO: flawed TBM headers: 0
[18:31:43.062] <TB1> INFO: flawed TBM trailers: 0
[18:31:43.062] <TB1> INFO: event ID mismatches: 0
[18:31:43.062] <TB1> INFO: ROC errors: 0
[18:31:43.062] <TB1> INFO: missing ROC header(s): 0
[18:31:43.062] <TB1> INFO: misplaced readback start: 0
[18:31:43.062] <TB1> INFO: Pixel decoding errors: 0
[18:31:43.062] <TB1> INFO: pixel data incomplete: 0
[18:31:43.062] <TB1> INFO: pixel address: 0
[18:31:43.062] <TB1> INFO: pulse height fill bit: 0
[18:31:43.062] <TB1> INFO: buffer corruption: 0
[18:31:43.072] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C15.dat
[18:31:43.072] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr_C15.dat
[18:31:43.072] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[18:31:43.072] <TB1> INFO: ######################################################################
[18:31:43.072] <TB1> INFO: PixTestReadback::doTest()
[18:31:43.072] <TB1> INFO: ######################################################################
[18:31:43.072] <TB1> INFO: ----------------------------------------------------------------------
[18:31:43.072] <TB1> INFO: PixTestReadback::CalibrateVd()
[18:31:43.072] <TB1> INFO: ----------------------------------------------------------------------
[18:31:53.032] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C0.dat
[18:31:53.032] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C1.dat
[18:31:53.032] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C2.dat
[18:31:53.032] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C3.dat
[18:31:53.032] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C4.dat
[18:31:53.032] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C5.dat
[18:31:53.032] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C6.dat
[18:31:53.032] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C7.dat
[18:31:53.032] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C8.dat
[18:31:53.033] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C9.dat
[18:31:53.033] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C10.dat
[18:31:53.033] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C11.dat
[18:31:53.033] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C12.dat
[18:31:53.033] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C13.dat
[18:31:53.033] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C14.dat
[18:31:53.033] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C15.dat
[18:31:53.060] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[18:31:53.060] <TB1> INFO: ----------------------------------------------------------------------
[18:31:53.060] <TB1> INFO: PixTestReadback::CalibrateVa()
[18:31:53.060] <TB1> INFO: ----------------------------------------------------------------------
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C0.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C1.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C2.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C3.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C4.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C5.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C6.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C7.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C8.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C9.dat
[18:32:02.948] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C10.dat
[18:32:02.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C11.dat
[18:32:02.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C12.dat
[18:32:02.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C13.dat
[18:32:02.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C14.dat
[18:32:02.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C15.dat
[18:32:02.978] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[18:32:02.978] <TB1> INFO: ----------------------------------------------------------------------
[18:32:02.978] <TB1> INFO: PixTestReadback::readbackVbg()
[18:32:02.978] <TB1> INFO: ----------------------------------------------------------------------
[18:32:10.619] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[18:32:10.619] <TB1> INFO: ----------------------------------------------------------------------
[18:32:10.619] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[18:32:10.619] <TB1> INFO: ----------------------------------------------------------------------
[18:32:10.619] <TB1> INFO: Vbg will be calibrated using Vd calibration
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 155calibrated Vbg = 1.16519 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 149.1calibrated Vbg = 1.15795 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 151.6calibrated Vbg = 1.15639 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 157.8calibrated Vbg = 1.15641 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 153calibrated Vbg = 1.16215 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 159calibrated Vbg = 1.16538 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 163.1calibrated Vbg = 1.16526 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 152.1calibrated Vbg = 1.16281 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 168.9calibrated Vbg = 1.1548 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 148.1calibrated Vbg = 1.1546 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 162.9calibrated Vbg = 1.14507 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 150.6calibrated Vbg = 1.14459 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 157.3calibrated Vbg = 1.1518 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 158.1calibrated Vbg = 1.16195 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 158.3calibrated Vbg = 1.15974 :::*/*/*/*/
[18:32:10.619] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 161calibrated Vbg = 1.15973 :::*/*/*/*/
[18:32:10.621] <TB1> INFO: ----------------------------------------------------------------------
[18:32:10.621] <TB1> INFO: PixTestReadback::CalibrateIa()
[18:32:10.621] <TB1> INFO: ----------------------------------------------------------------------
[18:34:50.925] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C0.dat
[18:34:50.925] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C1.dat
[18:34:50.925] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C2.dat
[18:34:50.925] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C3.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C4.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C5.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C6.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C7.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C8.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C9.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C10.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C11.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C12.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C13.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C14.dat
[18:34:50.926] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C15.dat
[18:34:50.953] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[18:34:50.954] <TB1> INFO: PixTestReadback::doTest() done
[18:34:50.954] <TB1> INFO: Decoding statistics:
[18:34:50.954] <TB1> INFO: General information:
[18:34:50.954] <TB1> INFO: 16bit words read: 1536
[18:34:50.954] <TB1> INFO: valid events total: 256
[18:34:50.954] <TB1> INFO: empty events: 256
[18:34:50.954] <TB1> INFO: valid events with pixels: 0
[18:34:50.954] <TB1> INFO: valid pixel hits: 0
[18:34:50.954] <TB1> INFO: Event errors: 0
[18:34:50.954] <TB1> INFO: start marker: 0
[18:34:50.955] <TB1> INFO: stop marker: 0
[18:34:50.955] <TB1> INFO: overflow: 0
[18:34:50.955] <TB1> INFO: invalid 5bit words: 0
[18:34:50.955] <TB1> INFO: invalid XOR eye diagram: 0
[18:34:50.955] <TB1> INFO: frame (failed synchr.): 0
[18:34:50.955] <TB1> INFO: idle data (no TBM trl): 0
[18:34:50.955] <TB1> INFO: no data (only TBM hdr): 0
[18:34:50.955] <TB1> INFO: TBM errors: 0
[18:34:50.955] <TB1> INFO: flawed TBM headers: 0
[18:34:50.955] <TB1> INFO: flawed TBM trailers: 0
[18:34:50.955] <TB1> INFO: event ID mismatches: 0
[18:34:50.955] <TB1> INFO: ROC errors: 0
[18:34:50.955] <TB1> INFO: missing ROC header(s): 0
[18:34:50.955] <TB1> INFO: misplaced readback start: 0
[18:34:50.955] <TB1> INFO: Pixel decoding errors: 0
[18:34:50.955] <TB1> INFO: pixel data incomplete: 0
[18:34:50.955] <TB1> INFO: pixel address: 0
[18:34:50.955] <TB1> INFO: pulse height fill bit: 0
[18:34:50.955] <TB1> INFO: buffer corruption: 0
[18:34:50.990] <TB1> INFO: ######################################################################
[18:34:50.990] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[18:34:50.990] <TB1> INFO: ######################################################################
[18:34:50.992] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[18:34:51.006] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:34:51.006] <TB1> INFO: run 1 of 1
[18:34:51.281] <TB1> INFO: Expecting 3120000 events.
[18:35:21.411] <TB1> INFO: 671765 events read in total (29538ms).
[18:35:33.674] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (150) != TBM ID (129)

[18:35:33.808] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 150 150 129 150 150 150 150 150

[18:35:33.808] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (151)

[18:35:33.808] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:35:33.808] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09a 80c0 4c11 262 2fef 4c11 262 2fef e022 c000

[18:35:33.808] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a094 8040 4810 262 2fef 4c11 262 2fef e022 c000

[18:35:33.808] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a095 80b1 4810 262 2fef 4c10 262 2fef e022 c000

[18:35:33.808] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 4c10 4c10 2fef 4c10 262 2fef e022 c000

[18:35:33.808] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a097 8000 4810 262 2fef 4810 262 2fef e022 c000

[18:35:33.808] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a098 8040 4c10 262 2fef 4c10 262 2fef e022 c000

[18:35:33.808] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a099 80b1 4c10 262 2fef 4c10 262 2fef e022 c000

[18:35:50.912] <TB1> INFO: 1339440 events read in total (59039ms).
[18:36:03.103] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (177) != TBM ID (129)

[18:36:03.238] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 177 177 129 177 177 177 177 177

[18:36:03.238] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (178)

[18:36:03.239] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:36:03.239] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b5 80b1 4c10 4c6 23ef 4c10 4c6 23ef e022 c000

[18:36:03.239] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0af 8000 4c11 4c6 23ef 4c11 4c6 23ef e022 c000

[18:36:03.239] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b0 8040 4c12 4c6 23ef 4c12 4c6 23ef e022 c000

[18:36:03.239] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 4c10 4c10 23ef 4c10 4c6 23ef e022 c000

[18:36:03.239] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b2 80c0 4c11 4c6 23ef 4c11 4c6 23ef e022 c000

[18:36:03.239] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b3 8000 4c10 4c6 23ef 4c10 4c6 23ef e022 c000

[18:36:03.239] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b4 8040 4810 4c6 23ef 4c11 4c6 23ef e022 c000

[18:36:20.386] <TB1> INFO: 2003515 events read in total (88513ms).
[18:36:32.563] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (188) != TBM ID (129)

[18:36:32.701] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 188 188 129 188 188 188 188 188

[18:36:32.701] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (189)

[18:36:32.702] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:36:32.702] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c0 8040 4c12 4c12 e022 c000

[18:36:32.702] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ba 80c0 4c10 4810 e022 c000

[18:36:32.702] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bb 8000 4811 4811 e022 c000

[18:36:32.702] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 4c10 4c10 e022 c000

[18:36:32.702] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bd 80b1 4810 4c10 e022 c000

[18:36:32.702] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0be 80c0 4810 4810 e022 c000

[18:36:32.702] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bf 8000 4c11 4c11 e022 c000

[18:36:50.131] <TB1> INFO: 2666075 events read in total (118258ms).
[18:36:58.569] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (220) != TBM ID (129)

[18:36:58.707] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 220 220 129 220 220 220 220 220

[18:36:58.707] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (221)

[18:36:58.707] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:36:58.707] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e0 8040 4812 a88 25ef 4c12 a88 25ef e022 c000

[18:36:58.707] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0da 80c0 4811 a88 25ef 4811 a88 25ef e022 c000

[18:36:58.707] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0db 8000 4c11 a88 25ef 4c11 a88 25ef e022 c000

[18:36:58.707] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80b1 4c10 4c10 25ef 4c11 a88 25ef e022 c000

[18:36:58.707] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dd 80b1 4810 a88 25ef 4c10 a88 25ef e022 c000

[18:36:58.707] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0de 80c0 4c10 a88 25ef 4c10 a88 25ef e022 c000

[18:36:58.707] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0df 8000 4810 a88 25ef 4810 a88 25ef e022 c000

[18:37:10.723] <TB1> INFO: 3120000 events read in total (138850ms).
[18:37:10.784] <TB1> INFO: Test took 139780ms.
[18:37:35.766] <TB1> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 164 seconds
[18:37:35.766] <TB1> INFO: number of dead bumps (per ROC): 0 1 0 64 0 1 0 0 0 0 2 4 0 1 2 0
[18:37:35.766] <TB1> INFO: separation cut (per ROC): 104 101 105 105 105 101 118 115 104 124 123 123 126 116 103 105
[18:37:35.766] <TB1> INFO: Decoding statistics:
[18:37:35.766] <TB1> INFO: General information:
[18:37:35.766] <TB1> INFO: 16bit words read: 0
[18:37:35.766] <TB1> INFO: valid events total: 0
[18:37:35.766] <TB1> INFO: empty events: 0
[18:37:35.766] <TB1> INFO: valid events with pixels: 0
[18:37:35.766] <TB1> INFO: valid pixel hits: 0
[18:37:35.766] <TB1> INFO: Event errors: 0
[18:37:35.766] <TB1> INFO: start marker: 0
[18:37:35.766] <TB1> INFO: stop marker: 0
[18:37:35.766] <TB1> INFO: overflow: 0
[18:37:35.766] <TB1> INFO: invalid 5bit words: 0
[18:37:35.766] <TB1> INFO: invalid XOR eye diagram: 0
[18:37:35.766] <TB1> INFO: frame (failed synchr.): 0
[18:37:35.766] <TB1> INFO: idle data (no TBM trl): 0
[18:37:35.766] <TB1> INFO: no data (only TBM hdr): 0
[18:37:35.767] <TB1> INFO: TBM errors: 0
[18:37:35.767] <TB1> INFO: flawed TBM headers: 0
[18:37:35.767] <TB1> INFO: flawed TBM trailers: 0
[18:37:35.767] <TB1> INFO: event ID mismatches: 0
[18:37:35.767] <TB1> INFO: ROC errors: 0
[18:37:35.767] <TB1> INFO: missing ROC header(s): 0
[18:37:35.767] <TB1> INFO: misplaced readback start: 0
[18:37:35.767] <TB1> INFO: Pixel decoding errors: 0
[18:37:35.767] <TB1> INFO: pixel data incomplete: 0
[18:37:35.767] <TB1> INFO: pixel address: 0
[18:37:35.767] <TB1> INFO: pulse height fill bit: 0
[18:37:35.767] <TB1> INFO: buffer corruption: 0
[18:37:35.819] <TB1> INFO: ######################################################################
[18:37:35.819] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[18:37:35.819] <TB1> INFO: ######################################################################
[18:37:35.820] <TB1> INFO: ----------------------------------------------------------------------
[18:37:35.820] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[18:37:35.820] <TB1> INFO: ----------------------------------------------------------------------
[18:37:35.820] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[18:37:35.832] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[18:37:35.832] <TB1> INFO: run 1 of 1
[18:37:36.118] <TB1> INFO: Expecting 36608000 events.
[18:37:59.731] <TB1> INFO: 703950 events read in total (23021ms).
[18:38:22.234] <TB1> INFO: 1390150 events read in total (45524ms).
[18:38:45.071] <TB1> INFO: 2079050 events read in total (68361ms).
[18:39:07.787] <TB1> INFO: 2762650 events read in total (91077ms).
[18:39:30.603] <TB1> INFO: 3449050 events read in total (113894ms).
[18:39:53.270] <TB1> INFO: 4134750 events read in total (136560ms).
[18:40:16.071] <TB1> INFO: 4821300 events read in total (159361ms).
[18:40:38.578] <TB1> INFO: 5505900 events read in total (181868ms).
[18:41:01.499] <TB1> INFO: 6191500 events read in total (204789ms).
[18:41:23.997] <TB1> INFO: 6875500 events read in total (227287ms).
[18:41:46.248] <TB1> INFO: 7560200 events read in total (249538ms).
[18:42:09.055] <TB1> INFO: 8244600 events read in total (272345ms).
[18:42:31.592] <TB1> INFO: 8928100 events read in total (294882ms).
[18:42:54.126] <TB1> INFO: 9609000 events read in total (317416ms).
[18:43:16.596] <TB1> INFO: 10292450 events read in total (339886ms).
[18:43:38.954] <TB1> INFO: 10973150 events read in total (362244ms).
[18:44:01.373] <TB1> INFO: 11654950 events read in total (384663ms).
[18:44:23.734] <TB1> INFO: 12335700 events read in total (407024ms).
[18:44:46.012] <TB1> INFO: 13015600 events read in total (429302ms).
[18:45:08.472] <TB1> INFO: 13698000 events read in total (451762ms).
[18:45:30.931] <TB1> INFO: 14378950 events read in total (474221ms).
[18:45:53.433] <TB1> INFO: 15058050 events read in total (496723ms).
[18:46:15.769] <TB1> INFO: 15735800 events read in total (519059ms).
[18:46:38.046] <TB1> INFO: 16414900 events read in total (541336ms).
[18:47:00.555] <TB1> INFO: 17092400 events read in total (563845ms).
[18:47:22.779] <TB1> INFO: 17773100 events read in total (586069ms).
[18:47:45.355] <TB1> INFO: 18450450 events read in total (608645ms).
[18:48:07.899] <TB1> INFO: 19128700 events read in total (631189ms).
[18:48:30.319] <TB1> INFO: 19805700 events read in total (653609ms).
[18:48:52.649] <TB1> INFO: 20481650 events read in total (675939ms).
[18:49:15.214] <TB1> INFO: 21157350 events read in total (698504ms).
[18:49:37.621] <TB1> INFO: 21833800 events read in total (720911ms).
[18:50:00.069] <TB1> INFO: 22508500 events read in total (743359ms).
[18:50:22.554] <TB1> INFO: 23181700 events read in total (765844ms).
[18:50:45.086] <TB1> INFO: 23855250 events read in total (788376ms).
[18:51:07.717] <TB1> INFO: 24531100 events read in total (811007ms).
[18:51:30.334] <TB1> INFO: 25203000 events read in total (833624ms).
[18:51:52.820] <TB1> INFO: 25878050 events read in total (856110ms).
[18:52:15.283] <TB1> INFO: 26548450 events read in total (878573ms).
[18:52:37.577] <TB1> INFO: 27222850 events read in total (900867ms).
[18:53:00.112] <TB1> INFO: 27893950 events read in total (923402ms).
[18:53:22.446] <TB1> INFO: 28567450 events read in total (945736ms).
[18:53:44.800] <TB1> INFO: 29241100 events read in total (968090ms).
[18:54:07.225] <TB1> INFO: 29911250 events read in total (990515ms).
[18:54:29.509] <TB1> INFO: 30583350 events read in total (1012799ms).
[18:54:51.761] <TB1> INFO: 31253500 events read in total (1035051ms).
[18:55:14.005] <TB1> INFO: 31924650 events read in total (1057295ms).
[18:55:36.577] <TB1> INFO: 32599350 events read in total (1079867ms).
[18:55:59.045] <TB1> INFO: 33272650 events read in total (1102335ms).
[18:56:21.277] <TB1> INFO: 33946900 events read in total (1124567ms).
[18:56:43.689] <TB1> INFO: 34621150 events read in total (1146979ms).
[18:57:06.214] <TB1> INFO: 35296150 events read in total (1169504ms).
[18:57:28.798] <TB1> INFO: 35975900 events read in total (1192088ms).
[18:57:49.927] <TB1> INFO: 36608000 events read in total (1213217ms).
[18:57:49.989] <TB1> INFO: Test took 1214157ms.
[18:57:50.421] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:57:51.952] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:57:53.539] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:57:55.079] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:57:56.751] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:57:58.672] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:00.490] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:02.365] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:04.041] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:05.897] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:07.687] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:09.517] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:11.428] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:13.327] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:14.806] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:16.577] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:58:18.350] <TB1> INFO: PixTestScurves::scurves() done
[18:58:18.350] <TB1> INFO: Vcal mean: 127.51 128.70 125.38 136.98 125.26 118.41 131.82 121.68 131.25 140.91 131.44 126.84 134.56 132.78 124.49 114.94
[18:58:18.350] <TB1> INFO: Vcal RMS: 5.89 6.23 6.68 14.54 5.81 5.64 7.19 6.47 6.23 5.58 8.28 7.92 6.97 6.54 6.08 5.55
[18:58:18.350] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1242 seconds
[18:58:18.350] <TB1> INFO: Decoding statistics:
[18:58:18.351] <TB1> INFO: General information:
[18:58:18.351] <TB1> INFO: 16bit words read: 0
[18:58:18.351] <TB1> INFO: valid events total: 0
[18:58:18.351] <TB1> INFO: empty events: 0
[18:58:18.351] <TB1> INFO: valid events with pixels: 0
[18:58:18.351] <TB1> INFO: valid pixel hits: 0
[18:58:18.351] <TB1> INFO: Event errors: 0
[18:58:18.351] <TB1> INFO: start marker: 0
[18:58:18.351] <TB1> INFO: stop marker: 0
[18:58:18.351] <TB1> INFO: overflow: 0
[18:58:18.351] <TB1> INFO: invalid 5bit words: 0
[18:58:18.351] <TB1> INFO: invalid XOR eye diagram: 0
[18:58:18.351] <TB1> INFO: frame (failed synchr.): 0
[18:58:18.351] <TB1> INFO: idle data (no TBM trl): 0
[18:58:18.351] <TB1> INFO: no data (only TBM hdr): 0
[18:58:18.351] <TB1> INFO: TBM errors: 0
[18:58:18.351] <TB1> INFO: flawed TBM headers: 0
[18:58:18.351] <TB1> INFO: flawed TBM trailers: 0
[18:58:18.351] <TB1> INFO: event ID mismatches: 0
[18:58:18.351] <TB1> INFO: ROC errors: 0
[18:58:18.351] <TB1> INFO: missing ROC header(s): 0
[18:58:18.351] <TB1> INFO: misplaced readback start: 0
[18:58:18.351] <TB1> INFO: Pixel decoding errors: 0
[18:58:18.351] <TB1> INFO: pixel data incomplete: 0
[18:58:18.351] <TB1> INFO: pixel address: 0
[18:58:18.351] <TB1> INFO: pulse height fill bit: 0
[18:58:18.351] <TB1> INFO: buffer corruption: 0
[18:58:18.421] <TB1> INFO: ######################################################################
[18:58:18.421] <TB1> INFO: PixTestTrim::doTest()
[18:58:18.421] <TB1> INFO: ######################################################################
[18:58:18.422] <TB1> INFO: ----------------------------------------------------------------------
[18:58:18.422] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[18:58:18.422] <TB1> INFO: ----------------------------------------------------------------------
[18:58:18.461] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[18:58:18.461] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[18:58:18.471] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:58:18.471] <TB1> INFO: run 1 of 1
[18:58:18.713] <TB1> INFO: Expecting 5025280 events.
[18:58:49.361] <TB1> INFO: 836624 events read in total (30054ms).
[18:59:19.106] <TB1> INFO: 1669888 events read in total (59799ms).
[18:59:49.090] <TB1> INFO: 2500456 events read in total (89784ms).
[19:00:19.154] <TB1> INFO: 3327104 events read in total (119847ms).
[19:00:48.870] <TB1> INFO: 4150016 events read in total (149563ms).
[19:01:18.679] <TB1> INFO: 4973600 events read in total (179372ms).
[19:01:20.949] <TB1> INFO: 5025280 events read in total (181642ms).
[19:01:20.986] <TB1> INFO: Test took 182514ms.
[19:01:37.875] <TB1> INFO: ROC 0 VthrComp = 129
[19:01:37.875] <TB1> INFO: ROC 1 VthrComp = 130
[19:01:37.875] <TB1> INFO: ROC 2 VthrComp = 123
[19:01:37.875] <TB1> INFO: ROC 3 VthrComp = 131
[19:01:37.875] <TB1> INFO: ROC 4 VthrComp = 132
[19:01:37.875] <TB1> INFO: ROC 5 VthrComp = 118
[19:01:37.875] <TB1> INFO: ROC 6 VthrComp = 133
[19:01:37.876] <TB1> INFO: ROC 7 VthrComp = 122
[19:01:37.876] <TB1> INFO: ROC 8 VthrComp = 126
[19:01:37.876] <TB1> INFO: ROC 9 VthrComp = 133
[19:01:37.876] <TB1> INFO: ROC 10 VthrComp = 127
[19:01:37.876] <TB1> INFO: ROC 11 VthrComp = 127
[19:01:37.876] <TB1> INFO: ROC 12 VthrComp = 133
[19:01:37.877] <TB1> INFO: ROC 13 VthrComp = 132
[19:01:37.878] <TB1> INFO: ROC 14 VthrComp = 120
[19:01:37.878] <TB1> INFO: ROC 15 VthrComp = 113
[19:01:38.201] <TB1> INFO: Expecting 41600 events.
[19:01:41.726] <TB1> INFO: 41600 events read in total (2933ms).
[19:01:41.727] <TB1> INFO: Test took 3846ms.
[19:01:41.736] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[19:01:41.736] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[19:01:41.745] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:01:41.745] <TB1> INFO: run 1 of 1
[19:01:42.023] <TB1> INFO: Expecting 5025280 events.
[19:02:08.081] <TB1> INFO: 591640 events read in total (25466ms).
[19:02:33.356] <TB1> INFO: 1181480 events read in total (50741ms).
[19:02:58.688] <TB1> INFO: 1771448 events read in total (76073ms).
[19:03:23.870] <TB1> INFO: 2360696 events read in total (101255ms).
[19:03:49.241] <TB1> INFO: 2948456 events read in total (126626ms).
[19:04:14.503] <TB1> INFO: 3535344 events read in total (151888ms).
[19:04:39.828] <TB1> INFO: 4121568 events read in total (177213ms).
[19:05:04.874] <TB1> INFO: 4707464 events read in total (202259ms).
[19:05:18.548] <TB1> INFO: 5025280 events read in total (215933ms).
[19:05:18.608] <TB1> INFO: Test took 216863ms.
[19:05:44.372] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 60.297 for pixel 9/77 mean/min/max = 46.789/33.2207/60.3574
[19:05:44.372] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 60.8665 for pixel 17/0 mean/min/max = 46.592/32.1761/61.008
[19:05:44.373] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 62.2835 for pixel 4/1 mean/min/max = 47.0624/31.7057/62.4191
[19:05:44.373] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 72.6164 for pixel 37/6 mean/min/max = 52.3063/30.4665/74.1461
[19:05:44.373] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 58.7827 for pixel 36/16 mean/min/max = 45.5475/32.184/58.9109
[19:05:44.374] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 59.3251 for pixel 3/10 mean/min/max = 45.9495/32.4702/59.4287
[19:05:44.374] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 62.1121 for pixel 22/8 mean/min/max = 47.2884/32.1285/62.4483
[19:05:44.375] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 59.9272 for pixel 0/2 mean/min/max = 46.4724/32.9358/60.009
[19:05:44.375] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 65.087 for pixel 13/69 mean/min/max = 48.3152/31.3976/65.2327
[19:05:44.375] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 66.4202 for pixel 17/11 mean/min/max = 51.1885/35.9485/66.4286
[19:05:44.376] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 66.2251 for pixel 17/4 mean/min/max = 48.0021/29.5408/66.4634
[19:05:44.376] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 64.013 for pixel 51/3 mean/min/max = 48.4016/31.8664/64.9368
[19:05:44.376] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 67.6883 for pixel 20/2 mean/min/max = 51.0881/34.3933/67.7828
[19:05:44.377] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 63.2891 for pixel 1/16 mean/min/max = 48.4904/33.629/63.3518
[19:05:44.377] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 62.6886 for pixel 0/2 mean/min/max = 48.1288/33.3844/62.8731
[19:05:44.378] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 60.353 for pixel 51/75 mean/min/max = 46.7613/33.1671/60.3555
[19:05:44.378] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:05:44.466] <TB1> INFO: Expecting 411648 events.
[19:05:53.804] <TB1> INFO: 411648 events read in total (8746ms).
[19:05:53.810] <TB1> INFO: Expecting 411648 events.
[19:06:02.981] <TB1> INFO: 411648 events read in total (8768ms).
[19:06:02.991] <TB1> INFO: Expecting 411648 events.
[19:06:12.144] <TB1> INFO: 411648 events read in total (8750ms).
[19:06:12.156] <TB1> INFO: Expecting 411648 events.
[19:06:21.192] <TB1> INFO: 411648 events read in total (8633ms).
[19:06:21.204] <TB1> INFO: Expecting 411648 events.
[19:06:30.351] <TB1> INFO: 411648 events read in total (8744ms).
[19:06:30.368] <TB1> INFO: Expecting 411648 events.
[19:06:39.381] <TB1> INFO: 411648 events read in total (8610ms).
[19:06:39.403] <TB1> INFO: Expecting 411648 events.
[19:06:48.454] <TB1> INFO: 411648 events read in total (8648ms).
[19:06:48.476] <TB1> INFO: Expecting 411648 events.
[19:06:57.442] <TB1> INFO: 411648 events read in total (8563ms).
[19:06:57.466] <TB1> INFO: Expecting 411648 events.
[19:07:06.476] <TB1> INFO: 411648 events read in total (8607ms).
[19:07:06.508] <TB1> INFO: Expecting 411648 events.
[19:07:15.520] <TB1> INFO: 411648 events read in total (8609ms).
[19:07:15.548] <TB1> INFO: Expecting 411648 events.
[19:07:24.624] <TB1> INFO: 411648 events read in total (8673ms).
[19:07:24.656] <TB1> INFO: Expecting 411648 events.
[19:07:33.684] <TB1> INFO: 411648 events read in total (8625ms).
[19:07:33.719] <TB1> INFO: Expecting 411648 events.
[19:07:42.728] <TB1> INFO: 411648 events read in total (8606ms).
[19:07:42.765] <TB1> INFO: Expecting 411648 events.
[19:07:51.835] <TB1> INFO: 411648 events read in total (8667ms).
[19:07:51.877] <TB1> INFO: Expecting 411648 events.
[19:08:00.881] <TB1> INFO: 411648 events read in total (8601ms).
[19:08:00.923] <TB1> INFO: Expecting 411648 events.
[19:08:09.924] <TB1> INFO: 411648 events read in total (8598ms).
[19:08:09.974] <TB1> INFO: Test took 145596ms.
[19:08:10.606] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[19:08:10.618] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:08:10.618] <TB1> INFO: run 1 of 1
[19:08:10.851] <TB1> INFO: Expecting 5025280 events.
[19:08:36.335] <TB1> INFO: 589672 events read in total (24892ms).
[19:09:01.431] <TB1> INFO: 1179480 events read in total (49988ms).
[19:09:26.797] <TB1> INFO: 1769104 events read in total (75355ms).
[19:09:52.378] <TB1> INFO: 2358024 events read in total (100935ms).
[19:10:17.778] <TB1> INFO: 2947160 events read in total (126335ms).
[19:10:43.275] <TB1> INFO: 3539152 events read in total (151832ms).
[19:11:08.597] <TB1> INFO: 4127928 events read in total (177154ms).
[19:11:34.068] <TB1> INFO: 4716960 events read in total (202625ms).
[19:11:47.501] <TB1> INFO: 5025280 events read in total (216058ms).
[19:11:47.644] <TB1> INFO: Test took 217027ms.
[19:12:10.903] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 2.189509 .. 147.944805
[19:12:11.149] <TB1> INFO: Expecting 208000 events.
[19:12:20.568] <TB1> INFO: 208000 events read in total (8827ms).
[19:12:20.569] <TB1> INFO: Test took 9664ms.
[19:12:20.617] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 2 .. 157 (-1/-1) hits flags = 528 (plus default)
[19:12:20.627] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:12:20.627] <TB1> INFO: run 1 of 1
[19:12:20.905] <TB1> INFO: Expecting 5191680 events.
[19:12:47.197] <TB1> INFO: 584320 events read in total (25700ms).
[19:13:12.266] <TB1> INFO: 1167264 events read in total (50769ms).
[19:13:37.488] <TB1> INFO: 1750104 events read in total (75992ms).
[19:14:02.519] <TB1> INFO: 2333008 events read in total (101022ms).
[19:14:27.925] <TB1> INFO: 2915712 events read in total (126428ms).
[19:14:53.498] <TB1> INFO: 3498136 events read in total (152001ms).
[19:15:18.882] <TB1> INFO: 4079736 events read in total (177385ms).
[19:15:44.014] <TB1> INFO: 4661328 events read in total (202517ms).
[19:16:07.097] <TB1> INFO: 5191680 events read in total (225600ms).
[19:16:07.176] <TB1> INFO: Test took 226550ms.
[19:16:35.459] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 26.639286 .. 88.174492
[19:16:35.702] <TB1> INFO: Expecting 208000 events.
[19:16:45.492] <TB1> INFO: 208000 events read in total (9198ms).
[19:16:45.493] <TB1> INFO: Test took 10033ms.
[19:16:45.542] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 98 (-1/-1) hits flags = 528 (plus default)
[19:16:45.551] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:16:45.551] <TB1> INFO: run 1 of 1
[19:16:45.828] <TB1> INFO: Expecting 2762240 events.
[19:17:12.765] <TB1> INFO: 588656 events read in total (26345ms).
[19:17:38.104] <TB1> INFO: 1176744 events read in total (51685ms).
[19:18:03.735] <TB1> INFO: 1764392 events read in total (77315ms).
[19:18:29.557] <TB1> INFO: 2351640 events read in total (103138ms).
[19:18:47.454] <TB1> INFO: 2762240 events read in total (121034ms).
[19:18:47.495] <TB1> INFO: Test took 121944ms.
[19:19:05.570] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 27.101547 .. 76.045591
[19:19:05.833] <TB1> INFO: Expecting 208000 events.
[19:19:15.740] <TB1> INFO: 208000 events read in total (9316ms).
[19:19:15.741] <TB1> INFO: Test took 10170ms.
[19:19:15.787] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 17 .. 86 (-1/-1) hits flags = 528 (plus default)
[19:19:15.798] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:19:15.798] <TB1> INFO: run 1 of 1
[19:19:16.076] <TB1> INFO: Expecting 2329600 events.
[19:19:43.027] <TB1> INFO: 596640 events read in total (26359ms).
[19:20:09.174] <TB1> INFO: 1193064 events read in total (52506ms).
[19:20:34.900] <TB1> INFO: 1788576 events read in total (78232ms).
[19:20:58.097] <TB1> INFO: 2329600 events read in total (101429ms).
[19:20:58.150] <TB1> INFO: Test took 102353ms.
[19:21:15.626] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 25.212838 .. 69.347297
[19:21:15.859] <TB1> INFO: Expecting 208000 events.
[19:21:26.081] <TB1> INFO: 208000 events read in total (9631ms).
[19:21:26.082] <TB1> INFO: Test took 10455ms.
[19:21:26.159] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 15 .. 79 (-1/-1) hits flags = 528 (plus default)
[19:21:26.172] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:21:26.172] <TB1> INFO: run 1 of 1
[19:21:26.450] <TB1> INFO: Expecting 2163200 events.
[19:21:53.196] <TB1> INFO: 610472 events read in total (26155ms).
[19:22:19.233] <TB1> INFO: 1220952 events read in total (52192ms).
[19:22:45.511] <TB1> INFO: 1831208 events read in total (78470ms).
[19:22:59.455] <TB1> INFO: 2163200 events read in total (92414ms).
[19:22:59.492] <TB1> INFO: Test took 93321ms.
[19:23:16.861] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[19:23:16.861] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[19:23:16.872] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:23:16.872] <TB1> INFO: run 1 of 1
[19:23:17.106] <TB1> INFO: Expecting 1364480 events.
[19:23:45.472] <TB1> INFO: 668536 events read in total (27775ms).
[19:24:13.279] <TB1> INFO: 1336488 events read in total (55582ms).
[19:24:14.963] <TB1> INFO: 1364480 events read in total (57266ms).
[19:24:14.988] <TB1> INFO: Test took 58117ms.
[19:24:28.433] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C0.dat
[19:24:28.433] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C1.dat
[19:24:28.433] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C2.dat
[19:24:28.433] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C3.dat
[19:24:28.433] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C4.dat
[19:24:28.433] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C5.dat
[19:24:28.433] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C6.dat
[19:24:28.433] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C7.dat
[19:24:28.434] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C8.dat
[19:24:28.434] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C9.dat
[19:24:28.434] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C10.dat
[19:24:28.434] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C11.dat
[19:24:28.434] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C12.dat
[19:24:28.434] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C13.dat
[19:24:28.434] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C14.dat
[19:24:28.434] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C15.dat
[19:24:28.434] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C0.dat
[19:24:28.442] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C1.dat
[19:24:28.449] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C2.dat
[19:24:28.457] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C3.dat
[19:24:28.464] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C4.dat
[19:24:28.472] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C5.dat
[19:24:28.479] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C6.dat
[19:24:28.487] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C7.dat
[19:24:28.494] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C8.dat
[19:24:28.501] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C9.dat
[19:24:28.509] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C10.dat
[19:24:28.516] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C11.dat
[19:24:28.524] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C12.dat
[19:24:28.531] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C13.dat
[19:24:28.538] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C14.dat
[19:24:28.545] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C15.dat
[19:24:28.552] <TB1> INFO: PixTestTrim::trimTest() done
[19:24:28.552] <TB1> INFO: vtrim: 138 153 137 66 147 127 154 126 160 161 164 148 185 143 119 139
[19:24:28.552] <TB1> INFO: vthrcomp: 129 130 123 131 132 118 133 122 126 133 127 127 133 132 120 113
[19:24:28.552] <TB1> INFO: vcal mean: 35.10 35.80 35.03 37.77 34.95 34.94 35.11 34.94 35.91 35.39 35.71 35.33 36.10 35.23 35.35 34.95
[19:24:28.552] <TB1> INFO: vcal RMS: 1.15 2.04 1.27 6.90 1.08 1.00 1.46 0.97 2.19 1.55 2.02 1.58 2.24 1.30 1.48 1.03
[19:24:28.552] <TB1> INFO: bits mean: 9.45 10.57 9.64 3.01 10.31 9.71 9.77 9.58 10.24 9.00 10.56 9.72 9.73 9.47 9.40 9.42
[19:24:28.552] <TB1> INFO: bits RMS: 2.51 2.28 2.66 2.93 2.37 2.52 2.48 2.49 2.52 2.19 2.27 2.33 2.22 2.39 2.54 2.57
[19:24:28.560] <TB1> INFO: ----------------------------------------------------------------------
[19:24:28.561] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[19:24:28.561] <TB1> INFO: ----------------------------------------------------------------------
[19:24:28.563] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[19:24:28.574] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:24:28.575] <TB1> INFO: run 1 of 1
[19:24:28.853] <TB1> INFO: Expecting 4160000 events.
[19:25:01.242] <TB1> INFO: 778890 events read in total (31798ms).
[19:25:32.881] <TB1> INFO: 1549285 events read in total (63437ms).
[19:26:04.552] <TB1> INFO: 2313890 events read in total (95108ms).
[19:26:36.034] <TB1> INFO: 3073045 events read in total (126590ms).
[19:27:07.781] <TB1> INFO: 3829715 events read in total (158337ms).
[19:27:21.544] <TB1> INFO: 4160000 events read in total (172100ms).
[19:27:21.589] <TB1> INFO: Test took 173014ms.
[19:27:46.607] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 223 (-1/-1) hits flags = 528 (plus default)
[19:27:46.617] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:27:46.617] <TB1> INFO: run 1 of 1
[19:27:46.848] <TB1> INFO: Expecting 4659200 events.
[19:28:18.284] <TB1> INFO: 719885 events read in total (30844ms).
[19:28:48.902] <TB1> INFO: 1434620 events read in total (61462ms).
[19:29:19.330] <TB1> INFO: 2145745 events read in total (91890ms).
[19:29:49.923] <TB1> INFO: 2854930 events read in total (122483ms).
[19:30:20.334] <TB1> INFO: 3560125 events read in total (152894ms).
[19:30:50.767] <TB1> INFO: 4264445 events read in total (183327ms).
[19:31:07.692] <TB1> INFO: 4659200 events read in total (200252ms).
[19:31:07.754] <TB1> INFO: Test took 201137ms.
[19:31:36.230] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 226 (-1/-1) hits flags = 528 (plus default)
[19:31:36.242] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:31:36.242] <TB1> INFO: run 1 of 1
[19:31:36.503] <TB1> INFO: Expecting 4721600 events.
[19:32:07.482] <TB1> INFO: 716690 events read in total (30387ms).
[19:32:38.159] <TB1> INFO: 1428605 events read in total (61064ms).
[19:33:10.307] <TB1> INFO: 2137160 events read in total (93213ms).
[19:33:40.920] <TB1> INFO: 2843890 events read in total (123825ms).
[19:34:11.317] <TB1> INFO: 3546605 events read in total (154222ms).
[19:34:41.832] <TB1> INFO: 4247780 events read in total (184737ms).
[19:35:02.015] <TB1> INFO: 4721600 events read in total (204920ms).
[19:35:02.076] <TB1> INFO: Test took 205834ms.
[19:35:33.476] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[19:35:33.488] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:35:33.488] <TB1> INFO: run 1 of 1
[19:35:33.723] <TB1> INFO: Expecting 5324800 events.
[19:36:04.181] <TB1> INFO: 690005 events read in total (29866ms).
[19:36:34.730] <TB1> INFO: 1376190 events read in total (60415ms).
[19:37:04.255] <TB1> INFO: 2060440 events read in total (89940ms).
[19:37:33.481] <TB1> INFO: 2742050 events read in total (119166ms).
[19:38:03.155] <TB1> INFO: 3422070 events read in total (148840ms).
[19:38:32.531] <TB1> INFO: 4099510 events read in total (178216ms).
[19:39:02.210] <TB1> INFO: 4776210 events read in total (207895ms).
[19:39:26.162] <TB1> INFO: 5324800 events read in total (231847ms).
[19:39:26.234] <TB1> INFO: Test took 232746ms.
[19:40:01.650] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[19:40:01.661] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:40:01.661] <TB1> INFO: run 1 of 1
[19:40:01.903] <TB1> INFO: Expecting 5324800 events.
[19:40:32.644] <TB1> INFO: 690035 events read in total (30149ms).
[19:41:02.121] <TB1> INFO: 1376315 events read in total (59626ms).
[19:41:31.954] <TB1> INFO: 2060515 events read in total (89459ms).
[19:42:01.669] <TB1> INFO: 2742235 events read in total (119174ms).
[19:42:31.174] <TB1> INFO: 3422270 events read in total (148679ms).
[19:43:00.268] <TB1> INFO: 4099875 events read in total (177773ms).
[19:43:29.221] <TB1> INFO: 4776610 events read in total (206726ms).
[19:43:53.053] <TB1> INFO: 5324800 events read in total (230558ms).
[19:43:53.124] <TB1> INFO: Test took 231462ms.
[19:44:22.968] <TB1> INFO: PixTestTrim::trimBitTest() done
[19:44:22.969] <TB1> INFO: PixTestTrim::doTest() done, duration: 2764 seconds
[19:44:22.969] <TB1> INFO: Decoding statistics:
[19:44:22.969] <TB1> INFO: General information:
[19:44:22.969] <TB1> INFO: 16bit words read: 0
[19:44:22.969] <TB1> INFO: valid events total: 0
[19:44:22.969] <TB1> INFO: empty events: 0
[19:44:22.969] <TB1> INFO: valid events with pixels: 0
[19:44:22.969] <TB1> INFO: valid pixel hits: 0
[19:44:22.969] <TB1> INFO: Event errors: 0
[19:44:22.969] <TB1> INFO: start marker: 0
[19:44:22.970] <TB1> INFO: stop marker: 0
[19:44:22.970] <TB1> INFO: overflow: 0
[19:44:22.970] <TB1> INFO: invalid 5bit words: 0
[19:44:22.970] <TB1> INFO: invalid XOR eye diagram: 0
[19:44:22.970] <TB1> INFO: frame (failed synchr.): 0
[19:44:22.970] <TB1> INFO: idle data (no TBM trl): 0
[19:44:22.970] <TB1> INFO: no data (only TBM hdr): 0
[19:44:22.970] <TB1> INFO: TBM errors: 0
[19:44:22.970] <TB1> INFO: flawed TBM headers: 0
[19:44:22.970] <TB1> INFO: flawed TBM trailers: 0
[19:44:22.970] <TB1> INFO: event ID mismatches: 0
[19:44:22.970] <TB1> INFO: ROC errors: 0
[19:44:22.970] <TB1> INFO: missing ROC header(s): 0
[19:44:22.970] <TB1> INFO: misplaced readback start: 0
[19:44:22.970] <TB1> INFO: Pixel decoding errors: 0
[19:44:22.970] <TB1> INFO: pixel data incomplete: 0
[19:44:22.970] <TB1> INFO: pixel address: 0
[19:44:22.970] <TB1> INFO: pulse height fill bit: 0
[19:44:22.970] <TB1> INFO: buffer corruption: 0
[19:44:23.640] <TB1> INFO: ######################################################################
[19:44:23.640] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[19:44:23.640] <TB1> INFO: ######################################################################
[19:44:23.874] <TB1> INFO: Expecting 41600 events.
[19:44:27.359] <TB1> INFO: 41600 events read in total (2893ms).
[19:44:27.360] <TB1> INFO: Test took 3719ms.
[19:44:27.799] <TB1> INFO: Expecting 41600 events.
[19:44:31.257] <TB1> INFO: 41600 events read in total (2866ms).
[19:44:31.258] <TB1> INFO: Test took 3696ms.
[19:44:31.549] <TB1> INFO: Expecting 41600 events.
[19:44:35.058] <TB1> INFO: 41600 events read in total (2917ms).
[19:44:35.059] <TB1> INFO: Test took 3775ms.
[19:44:35.347] <TB1> INFO: Expecting 41600 events.
[19:44:38.791] <TB1> INFO: 41600 events read in total (2852ms).
[19:44:38.791] <TB1> INFO: Test took 3709ms.
[19:44:39.079] <TB1> INFO: Expecting 41600 events.
[19:44:42.586] <TB1> INFO: 41600 events read in total (2915ms).
[19:44:42.587] <TB1> INFO: Test took 3772ms.
[19:44:42.876] <TB1> INFO: Expecting 41600 events.
[19:44:46.396] <TB1> INFO: 41600 events read in total (2929ms).
[19:44:46.397] <TB1> INFO: Test took 3786ms.
[19:44:46.686] <TB1> INFO: Expecting 41600 events.
[19:44:50.246] <TB1> INFO: 41600 events read in total (2968ms).
[19:44:50.246] <TB1> INFO: Test took 3824ms.
[19:44:50.537] <TB1> INFO: Expecting 41600 events.
[19:44:54.062] <TB1> INFO: 41600 events read in total (2934ms).
[19:44:54.063] <TB1> INFO: Test took 3791ms.
[19:44:54.351] <TB1> INFO: Expecting 41600 events.
[19:44:57.807] <TB1> INFO: 41600 events read in total (2864ms).
[19:44:57.807] <TB1> INFO: Test took 3720ms.
[19:44:58.111] <TB1> INFO: Expecting 41600 events.
[19:45:01.579] <TB1> INFO: 41600 events read in total (2876ms).
[19:45:01.580] <TB1> INFO: Test took 3749ms.
[19:45:01.868] <TB1> INFO: Expecting 41600 events.
[19:45:05.390] <TB1> INFO: 41600 events read in total (2931ms).
[19:45:05.391] <TB1> INFO: Test took 3788ms.
[19:45:05.680] <TB1> INFO: Expecting 41600 events.
[19:45:09.261] <TB1> INFO: 41600 events read in total (2990ms).
[19:45:09.262] <TB1> INFO: Test took 3847ms.
[19:45:09.550] <TB1> INFO: Expecting 41600 events.
[19:45:13.013] <TB1> INFO: 41600 events read in total (2872ms).
[19:45:13.014] <TB1> INFO: Test took 3729ms.
[19:45:13.304] <TB1> INFO: Expecting 41600 events.
[19:45:16.843] <TB1> INFO: 41600 events read in total (2948ms).
[19:45:16.844] <TB1> INFO: Test took 3805ms.
[19:45:17.145] <TB1> INFO: Expecting 41600 events.
[19:45:20.555] <TB1> INFO: 41600 events read in total (2818ms).
[19:45:20.556] <TB1> INFO: Test took 3686ms.
[19:45:20.844] <TB1> INFO: Expecting 41600 events.
[19:45:24.295] <TB1> INFO: 41600 events read in total (2859ms).
[19:45:24.296] <TB1> INFO: Test took 3717ms.
[19:45:24.584] <TB1> INFO: Expecting 41600 events.
[19:45:28.072] <TB1> INFO: 41600 events read in total (2897ms).
[19:45:28.073] <TB1> INFO: Test took 3754ms.
[19:45:28.361] <TB1> INFO: Expecting 41600 events.
[19:45:31.908] <TB1> INFO: 41600 events read in total (2955ms).
[19:45:31.909] <TB1> INFO: Test took 3812ms.
[19:45:32.207] <TB1> INFO: Expecting 41600 events.
[19:45:35.734] <TB1> INFO: 41600 events read in total (2929ms).
[19:45:35.735] <TB1> INFO: Test took 3803ms.
[19:45:36.028] <TB1> INFO: Expecting 41600 events.
[19:45:39.523] <TB1> INFO: 41600 events read in total (2904ms).
[19:45:39.524] <TB1> INFO: Test took 3761ms.
[19:45:39.817] <TB1> INFO: Expecting 41600 events.
[19:45:43.364] <TB1> INFO: 41600 events read in total (2956ms).
[19:45:43.365] <TB1> INFO: Test took 3813ms.
[19:45:43.655] <TB1> INFO: Expecting 41600 events.
[19:45:47.217] <TB1> INFO: 41600 events read in total (2970ms).
[19:45:47.218] <TB1> INFO: Test took 3829ms.
[19:45:47.506] <TB1> INFO: Expecting 41600 events.
[19:45:51.055] <TB1> INFO: 41600 events read in total (2957ms).
[19:45:51.056] <TB1> INFO: Test took 3814ms.
[19:45:51.344] <TB1> INFO: Expecting 41600 events.
[19:45:54.884] <TB1> INFO: 41600 events read in total (2949ms).
[19:45:54.884] <TB1> INFO: Test took 3805ms.
[19:45:55.173] <TB1> INFO: Expecting 41600 events.
[19:45:58.795] <TB1> INFO: 41600 events read in total (3031ms).
[19:45:58.796] <TB1> INFO: Test took 3888ms.
[19:45:59.084] <TB1> INFO: Expecting 41600 events.
[19:46:02.610] <TB1> INFO: 41600 events read in total (2934ms).
[19:46:02.611] <TB1> INFO: Test took 3792ms.
[19:46:02.899] <TB1> INFO: Expecting 41600 events.
[19:46:06.435] <TB1> INFO: 41600 events read in total (2944ms).
[19:46:06.436] <TB1> INFO: Test took 3801ms.
[19:46:06.727] <TB1> INFO: Expecting 41600 events.
[19:46:10.276] <TB1> INFO: 41600 events read in total (2957ms).
[19:46:10.277] <TB1> INFO: Test took 3815ms.
[19:46:10.566] <TB1> INFO: Expecting 41600 events.
[19:46:14.008] <TB1> INFO: 41600 events read in total (2850ms).
[19:46:14.009] <TB1> INFO: Test took 3707ms.
[19:46:14.298] <TB1> INFO: Expecting 2560 events.
[19:46:15.181] <TB1> INFO: 2560 events read in total (291ms).
[19:46:15.181] <TB1> INFO: Test took 1160ms.
[19:46:15.489] <TB1> INFO: Expecting 2560 events.
[19:46:16.371] <TB1> INFO: 2560 events read in total (290ms).
[19:46:16.371] <TB1> INFO: Test took 1189ms.
[19:46:16.679] <TB1> INFO: Expecting 2560 events.
[19:46:17.562] <TB1> INFO: 2560 events read in total (291ms).
[19:46:17.562] <TB1> INFO: Test took 1190ms.
[19:46:17.869] <TB1> INFO: Expecting 2560 events.
[19:46:18.754] <TB1> INFO: 2560 events read in total (293ms).
[19:46:18.755] <TB1> INFO: Test took 1193ms.
[19:46:19.062] <TB1> INFO: Expecting 2560 events.
[19:46:19.940] <TB1> INFO: 2560 events read in total (286ms).
[19:46:19.940] <TB1> INFO: Test took 1185ms.
[19:46:20.248] <TB1> INFO: Expecting 2560 events.
[19:46:21.126] <TB1> INFO: 2560 events read in total (286ms).
[19:46:21.126] <TB1> INFO: Test took 1185ms.
[19:46:21.434] <TB1> INFO: Expecting 2560 events.
[19:46:22.311] <TB1> INFO: 2560 events read in total (286ms).
[19:46:22.311] <TB1> INFO: Test took 1185ms.
[19:46:22.619] <TB1> INFO: Expecting 2560 events.
[19:46:23.497] <TB1> INFO: 2560 events read in total (286ms).
[19:46:23.497] <TB1> INFO: Test took 1185ms.
[19:46:23.805] <TB1> INFO: Expecting 2560 events.
[19:46:24.683] <TB1> INFO: 2560 events read in total (287ms).
[19:46:24.683] <TB1> INFO: Test took 1186ms.
[19:46:24.991] <TB1> INFO: Expecting 2560 events.
[19:46:25.871] <TB1> INFO: 2560 events read in total (288ms).
[19:46:25.871] <TB1> INFO: Test took 1187ms.
[19:46:26.178] <TB1> INFO: Expecting 2560 events.
[19:46:27.056] <TB1> INFO: 2560 events read in total (286ms).
[19:46:27.057] <TB1> INFO: Test took 1186ms.
[19:46:27.364] <TB1> INFO: Expecting 2560 events.
[19:46:28.245] <TB1> INFO: 2560 events read in total (290ms).
[19:46:28.245] <TB1> INFO: Test took 1188ms.
[19:46:28.553] <TB1> INFO: Expecting 2560 events.
[19:46:29.435] <TB1> INFO: 2560 events read in total (291ms).
[19:46:29.436] <TB1> INFO: Test took 1191ms.
[19:46:29.744] <TB1> INFO: Expecting 2560 events.
[19:46:30.628] <TB1> INFO: 2560 events read in total (293ms).
[19:46:30.629] <TB1> INFO: Test took 1193ms.
[19:46:30.937] <TB1> INFO: Expecting 2560 events.
[19:46:31.818] <TB1> INFO: 2560 events read in total (290ms).
[19:46:31.818] <TB1> INFO: Test took 1189ms.
[19:46:32.126] <TB1> INFO: Expecting 2560 events.
[19:46:33.014] <TB1> INFO: 2560 events read in total (296ms).
[19:46:33.014] <TB1> INFO: Test took 1196ms.
[19:46:33.017] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:46:33.323] <TB1> INFO: Expecting 655360 events.
[19:46:47.586] <TB1> INFO: 655360 events read in total (13672ms).
[19:46:47.597] <TB1> INFO: Expecting 655360 events.
[19:47:01.619] <TB1> INFO: 655360 events read in total (13619ms).
[19:47:01.637] <TB1> INFO: Expecting 655360 events.
[19:47:15.729] <TB1> INFO: 655360 events read in total (13689ms).
[19:47:15.748] <TB1> INFO: Expecting 655360 events.
[19:47:29.870] <TB1> INFO: 655360 events read in total (13719ms).
[19:47:29.894] <TB1> INFO: Expecting 655360 events.
[19:47:43.886] <TB1> INFO: 655360 events read in total (13589ms).
[19:47:43.916] <TB1> INFO: Expecting 655360 events.
[19:47:57.917] <TB1> INFO: 655360 events read in total (13598ms).
[19:47:57.962] <TB1> INFO: Expecting 655360 events.
[19:48:12.006] <TB1> INFO: 655360 events read in total (13641ms).
[19:48:12.051] <TB1> INFO: Expecting 655360 events.
[19:48:26.195] <TB1> INFO: 655360 events read in total (13741ms).
[19:48:26.241] <TB1> INFO: Expecting 655360 events.
[19:48:40.363] <TB1> INFO: 655360 events read in total (13719ms).
[19:48:40.414] <TB1> INFO: Expecting 655360 events.
[19:48:54.421] <TB1> INFO: 655360 events read in total (13604ms).
[19:48:54.470] <TB1> INFO: Expecting 655360 events.
[19:49:08.545] <TB1> INFO: 655360 events read in total (13659ms).
[19:49:08.599] <TB1> INFO: Expecting 655360 events.
[19:49:22.762] <TB1> INFO: 655360 events read in total (13760ms).
[19:49:22.821] <TB1> INFO: Expecting 655360 events.
[19:49:36.888] <TB1> INFO: 655360 events read in total (13664ms).
[19:49:36.965] <TB1> INFO: Expecting 655360 events.
[19:49:51.072] <TB1> INFO: 655360 events read in total (13704ms).
[19:49:51.140] <TB1> INFO: Expecting 655360 events.
[19:50:05.182] <TB1> INFO: 655360 events read in total (13639ms).
[19:50:05.253] <TB1> INFO: Expecting 655360 events.
[19:50:19.557] <TB1> INFO: 655360 events read in total (13901ms).
[19:50:19.631] <TB1> INFO: Test took 226614ms.
[19:50:19.709] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:19.974] <TB1> INFO: Expecting 655360 events.
[19:50:34.426] <TB1> INFO: 655360 events read in total (13860ms).
[19:50:34.437] <TB1> INFO: Expecting 655360 events.
[19:50:48.371] <TB1> INFO: 655360 events read in total (13531ms).
[19:50:48.391] <TB1> INFO: Expecting 655360 events.
[19:51:02.543] <TB1> INFO: 655360 events read in total (13749ms).
[19:51:02.568] <TB1> INFO: Expecting 655360 events.
[19:51:16.553] <TB1> INFO: 655360 events read in total (13582ms).
[19:51:16.584] <TB1> INFO: Expecting 655360 events.
[19:51:30.446] <TB1> INFO: 655360 events read in total (13459ms).
[19:51:30.472] <TB1> INFO: Expecting 655360 events.
[19:51:44.548] <TB1> INFO: 655360 events read in total (13673ms).
[19:51:44.579] <TB1> INFO: Expecting 655360 events.
[19:51:58.495] <TB1> INFO: 655360 events read in total (13513ms).
[19:51:58.541] <TB1> INFO: Expecting 655360 events.
[19:52:12.665] <TB1> INFO: 655360 events read in total (13721ms).
[19:52:12.706] <TB1> INFO: Expecting 655360 events.
[19:52:26.602] <TB1> INFO: 655360 events read in total (13493ms).
[19:52:26.663] <TB1> INFO: Expecting 655360 events.
[19:52:40.801] <TB1> INFO: 655360 events read in total (13735ms).
[19:52:40.850] <TB1> INFO: Expecting 655360 events.
[19:52:55.033] <TB1> INFO: 655360 events read in total (13780ms).
[19:52:55.086] <TB1> INFO: Expecting 655360 events.
[19:53:09.382] <TB1> INFO: 655360 events read in total (13893ms).
[19:53:09.442] <TB1> INFO: Expecting 655360 events.
[19:53:23.735] <TB1> INFO: 655360 events read in total (13890ms).
[19:53:23.798] <TB1> INFO: Expecting 655360 events.
[19:53:38.159] <TB1> INFO: 655360 events read in total (13958ms).
[19:53:38.232] <TB1> INFO: Expecting 655360 events.
[19:53:52.225] <TB1> INFO: 655360 events read in total (13590ms).
[19:53:52.295] <TB1> INFO: Expecting 655360 events.
[19:54:06.402] <TB1> INFO: 655360 events read in total (13704ms).
[19:54:06.489] <TB1> INFO: Test took 226780ms.
[19:54:06.696] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.700] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:54:06.706] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[19:54:06.713] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[19:54:06.719] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[19:54:06.725] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[19:54:06.730] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[19:54:06.735] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[19:54:06.739] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.744] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.748] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:54:06.753] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[19:54:06.757] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[19:54:06.762] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.766] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:54:06.771] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[19:54:06.776] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[19:54:06.780] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[19:54:06.785] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[19:54:06.789] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[19:54:06.794] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[19:54:06.799] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.803] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.808] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.812] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.817] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.821] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:54:06.826] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[19:54:06.830] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[19:54:06.835] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.840] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.844] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.849] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:54:06.853] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[19:54:06.858] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.863] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.868] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.874] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:54:06.906] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C0.dat
[19:54:06.906] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C1.dat
[19:54:06.906] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C2.dat
[19:54:06.906] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C3.dat
[19:54:06.906] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C4.dat
[19:54:06.907] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C5.dat
[19:54:06.907] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C6.dat
[19:54:06.907] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C7.dat
[19:54:06.907] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C8.dat
[19:54:06.907] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C9.dat
[19:54:06.907] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C10.dat
[19:54:06.907] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C11.dat
[19:54:06.908] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C12.dat
[19:54:06.908] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C13.dat
[19:54:06.908] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C14.dat
[19:54:06.908] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C15.dat
[19:54:07.186] <TB1> INFO: Expecting 41600 events.
[19:54:10.282] <TB1> INFO: 41600 events read in total (2504ms).
[19:54:10.283] <TB1> INFO: Test took 3372ms.
[19:54:10.726] <TB1> INFO: Expecting 41600 events.
[19:54:13.742] <TB1> INFO: 41600 events read in total (2425ms).
[19:54:13.743] <TB1> INFO: Test took 3249ms.
[19:54:14.189] <TB1> INFO: Expecting 41600 events.
[19:54:17.266] <TB1> INFO: 41600 events read in total (2486ms).
[19:54:17.266] <TB1> INFO: Test took 3310ms.
[19:54:17.482] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:17.570] <TB1> INFO: Expecting 2560 events.
[19:54:18.452] <TB1> INFO: 2560 events read in total (290ms).
[19:54:18.452] <TB1> INFO: Test took 970ms.
[19:54:18.454] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:18.761] <TB1> INFO: Expecting 2560 events.
[19:54:19.642] <TB1> INFO: 2560 events read in total (290ms).
[19:54:19.643] <TB1> INFO: Test took 1189ms.
[19:54:19.644] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:19.951] <TB1> INFO: Expecting 2560 events.
[19:54:20.835] <TB1> INFO: 2560 events read in total (293ms).
[19:54:20.835] <TB1> INFO: Test took 1191ms.
[19:54:20.837] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:21.143] <TB1> INFO: Expecting 2560 events.
[19:54:22.030] <TB1> INFO: 2560 events read in total (296ms).
[19:54:22.031] <TB1> INFO: Test took 1194ms.
[19:54:22.033] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:22.339] <TB1> INFO: Expecting 2560 events.
[19:54:23.221] <TB1> INFO: 2560 events read in total (291ms).
[19:54:23.222] <TB1> INFO: Test took 1190ms.
[19:54:23.223] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:23.530] <TB1> INFO: Expecting 2560 events.
[19:54:24.413] <TB1> INFO: 2560 events read in total (291ms).
[19:54:24.413] <TB1> INFO: Test took 1190ms.
[19:54:24.415] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:24.722] <TB1> INFO: Expecting 2560 events.
[19:54:25.604] <TB1> INFO: 2560 events read in total (291ms).
[19:54:25.605] <TB1> INFO: Test took 1190ms.
[19:54:25.607] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:25.913] <TB1> INFO: Expecting 2560 events.
[19:54:26.794] <TB1> INFO: 2560 events read in total (289ms).
[19:54:26.794] <TB1> INFO: Test took 1188ms.
[19:54:26.796] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:27.102] <TB1> INFO: Expecting 2560 events.
[19:54:27.980] <TB1> INFO: 2560 events read in total (286ms).
[19:54:27.980] <TB1> INFO: Test took 1184ms.
[19:54:27.982] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:28.289] <TB1> INFO: Expecting 2560 events.
[19:54:29.168] <TB1> INFO: 2560 events read in total (288ms).
[19:54:29.168] <TB1> INFO: Test took 1186ms.
[19:54:29.170] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:29.477] <TB1> INFO: Expecting 2560 events.
[19:54:30.357] <TB1> INFO: 2560 events read in total (289ms).
[19:54:30.358] <TB1> INFO: Test took 1188ms.
[19:54:30.360] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:30.666] <TB1> INFO: Expecting 2560 events.
[19:54:31.544] <TB1> INFO: 2560 events read in total (286ms).
[19:54:31.545] <TB1> INFO: Test took 1185ms.
[19:54:31.547] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:31.852] <TB1> INFO: Expecting 2560 events.
[19:54:32.731] <TB1> INFO: 2560 events read in total (287ms).
[19:54:32.731] <TB1> INFO: Test took 1184ms.
[19:54:32.733] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:33.039] <TB1> INFO: Expecting 2560 events.
[19:54:33.920] <TB1> INFO: 2560 events read in total (289ms).
[19:54:33.920] <TB1> INFO: Test took 1187ms.
[19:54:33.921] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:34.228] <TB1> INFO: Expecting 2560 events.
[19:54:35.107] <TB1> INFO: 2560 events read in total (287ms).
[19:54:35.108] <TB1> INFO: Test took 1187ms.
[19:54:35.109] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:35.416] <TB1> INFO: Expecting 2560 events.
[19:54:36.297] <TB1> INFO: 2560 events read in total (290ms).
[19:54:36.297] <TB1> INFO: Test took 1188ms.
[19:54:36.300] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:36.605] <TB1> INFO: Expecting 2560 events.
[19:54:37.484] <TB1> INFO: 2560 events read in total (287ms).
[19:54:37.484] <TB1> INFO: Test took 1184ms.
[19:54:37.487] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:37.792] <TB1> INFO: Expecting 2560 events.
[19:54:38.670] <TB1> INFO: 2560 events read in total (286ms).
[19:54:38.671] <TB1> INFO: Test took 1184ms.
[19:54:38.673] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:38.979] <TB1> INFO: Expecting 2560 events.
[19:54:39.857] <TB1> INFO: 2560 events read in total (286ms).
[19:54:39.857] <TB1> INFO: Test took 1184ms.
[19:54:39.859] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:40.166] <TB1> INFO: Expecting 2560 events.
[19:54:41.044] <TB1> INFO: 2560 events read in total (287ms).
[19:54:41.044] <TB1> INFO: Test took 1185ms.
[19:54:41.046] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:41.352] <TB1> INFO: Expecting 2560 events.
[19:54:42.234] <TB1> INFO: 2560 events read in total (290ms).
[19:54:42.234] <TB1> INFO: Test took 1188ms.
[19:54:42.236] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:42.543] <TB1> INFO: Expecting 2560 events.
[19:54:43.424] <TB1> INFO: 2560 events read in total (290ms).
[19:54:43.424] <TB1> INFO: Test took 1188ms.
[19:54:43.426] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:43.733] <TB1> INFO: Expecting 2560 events.
[19:54:44.611] <TB1> INFO: 2560 events read in total (287ms).
[19:54:44.611] <TB1> INFO: Test took 1185ms.
[19:54:44.613] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:44.919] <TB1> INFO: Expecting 2560 events.
[19:54:45.800] <TB1> INFO: 2560 events read in total (289ms).
[19:54:45.800] <TB1> INFO: Test took 1187ms.
[19:54:45.802] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:46.108] <TB1> INFO: Expecting 2560 events.
[19:54:46.990] <TB1> INFO: 2560 events read in total (290ms).
[19:54:46.990] <TB1> INFO: Test took 1188ms.
[19:54:46.992] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:47.299] <TB1> INFO: Expecting 2560 events.
[19:54:48.181] <TB1> INFO: 2560 events read in total (291ms).
[19:54:48.182] <TB1> INFO: Test took 1190ms.
[19:54:48.184] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:48.490] <TB1> INFO: Expecting 2560 events.
[19:54:49.371] <TB1> INFO: 2560 events read in total (290ms).
[19:54:49.372] <TB1> INFO: Test took 1188ms.
[19:54:49.374] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:49.680] <TB1> INFO: Expecting 2560 events.
[19:54:50.567] <TB1> INFO: 2560 events read in total (295ms).
[19:54:50.567] <TB1> INFO: Test took 1193ms.
[19:54:50.570] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:50.875] <TB1> INFO: Expecting 2560 events.
[19:54:51.757] <TB1> INFO: 2560 events read in total (291ms).
[19:54:51.758] <TB1> INFO: Test took 1188ms.
[19:54:51.759] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:52.066] <TB1> INFO: Expecting 2560 events.
[19:54:52.949] <TB1> INFO: 2560 events read in total (291ms).
[19:54:52.949] <TB1> INFO: Test took 1190ms.
[19:54:52.952] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:53.257] <TB1> INFO: Expecting 2560 events.
[19:54:54.145] <TB1> INFO: 2560 events read in total (296ms).
[19:54:54.145] <TB1> INFO: Test took 1193ms.
[19:54:54.147] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:54:54.454] <TB1> INFO: Expecting 2560 events.
[19:54:55.337] <TB1> INFO: 2560 events read in total (292ms).
[19:54:55.337] <TB1> INFO: Test took 1190ms.
[19:54:55.800] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 632 seconds
[19:54:55.800] <TB1> INFO: PH scale (per ROC): 42 32 39 35 49 42 49 33 39 41 38 31 39 49 32 51
[19:54:55.800] <TB1> INFO: PH offset (per ROC): 80 85 117 101 115 109 120 99 108 108 92 106 99 131 97 123
[19:54:55.807] <TB1> INFO: Decoding statistics:
[19:54:55.807] <TB1> INFO: General information:
[19:54:55.807] <TB1> INFO: 16bit words read: 127880
[19:54:55.807] <TB1> INFO: valid events total: 20480
[19:54:55.807] <TB1> INFO: empty events: 17980
[19:54:55.807] <TB1> INFO: valid events with pixels: 2500
[19:54:55.807] <TB1> INFO: valid pixel hits: 2500
[19:54:55.807] <TB1> INFO: Event errors: 0
[19:54:55.807] <TB1> INFO: start marker: 0
[19:54:55.807] <TB1> INFO: stop marker: 0
[19:54:55.807] <TB1> INFO: overflow: 0
[19:54:55.807] <TB1> INFO: invalid 5bit words: 0
[19:54:55.807] <TB1> INFO: invalid XOR eye diagram: 0
[19:54:55.807] <TB1> INFO: frame (failed synchr.): 0
[19:54:55.807] <TB1> INFO: idle data (no TBM trl): 0
[19:54:55.807] <TB1> INFO: no data (only TBM hdr): 0
[19:54:55.807] <TB1> INFO: TBM errors: 0
[19:54:55.807] <TB1> INFO: flawed TBM headers: 0
[19:54:55.807] <TB1> INFO: flawed TBM trailers: 0
[19:54:55.807] <TB1> INFO: event ID mismatches: 0
[19:54:55.807] <TB1> INFO: ROC errors: 0
[19:54:55.807] <TB1> INFO: missing ROC header(s): 0
[19:54:55.807] <TB1> INFO: misplaced readback start: 0
[19:54:55.807] <TB1> INFO: Pixel decoding errors: 0
[19:54:55.807] <TB1> INFO: pixel data incomplete: 0
[19:54:55.807] <TB1> INFO: pixel address: 0
[19:54:55.807] <TB1> INFO: pulse height fill bit: 0
[19:54:55.807] <TB1> INFO: buffer corruption: 0
[19:54:56.159] <TB1> INFO: ######################################################################
[19:54:56.159] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[19:54:56.159] <TB1> INFO: ######################################################################
[19:54:56.171] <TB1> INFO: scanning low vcal = 10
[19:54:56.404] <TB1> INFO: Expecting 41600 events.
[19:54:59.959] <TB1> INFO: 41600 events read in total (2963ms).
[19:54:59.959] <TB1> INFO: Test took 3788ms.
[19:54:59.961] <TB1> INFO: scanning low vcal = 20
[19:55:00.259] <TB1> INFO: Expecting 41600 events.
[19:55:03.865] <TB1> INFO: 41600 events read in total (3014ms).
[19:55:03.865] <TB1> INFO: Test took 3903ms.
[19:55:03.867] <TB1> INFO: scanning low vcal = 30
[19:55:04.166] <TB1> INFO: Expecting 41600 events.
[19:55:07.805] <TB1> INFO: 41600 events read in total (3048ms).
[19:55:07.806] <TB1> INFO: Test took 3939ms.
[19:55:07.809] <TB1> INFO: scanning low vcal = 40
[19:55:08.088] <TB1> INFO: Expecting 41600 events.
[19:55:11.976] <TB1> INFO: 41600 events read in total (3296ms).
[19:55:11.978] <TB1> INFO: Test took 4169ms.
[19:55:11.980] <TB1> INFO: scanning low vcal = 50
[19:55:12.257] <TB1> INFO: Expecting 41600 events.
[19:55:16.178] <TB1> INFO: 41600 events read in total (3330ms).
[19:55:16.179] <TB1> INFO: Test took 4199ms.
[19:55:16.182] <TB1> INFO: scanning low vcal = 60
[19:55:16.459] <TB1> INFO: Expecting 41600 events.
[19:55:20.382] <TB1> INFO: 41600 events read in total (3332ms).
[19:55:20.383] <TB1> INFO: Test took 4201ms.
[19:55:20.385] <TB1> INFO: scanning low vcal = 70
[19:55:20.662] <TB1> INFO: Expecting 41600 events.
[19:55:24.604] <TB1> INFO: 41600 events read in total (3350ms).
[19:55:24.605] <TB1> INFO: Test took 4219ms.
[19:55:24.608] <TB1> INFO: scanning low vcal = 80
[19:55:24.885] <TB1> INFO: Expecting 41600 events.
[19:55:28.821] <TB1> INFO: 41600 events read in total (3345ms).
[19:55:28.822] <TB1> INFO: Test took 4214ms.
[19:55:28.825] <TB1> INFO: scanning low vcal = 90
[19:55:29.106] <TB1> INFO: Expecting 41600 events.
[19:55:33.097] <TB1> INFO: 41600 events read in total (3400ms).
[19:55:33.098] <TB1> INFO: Test took 4273ms.
[19:55:33.100] <TB1> INFO: scanning low vcal = 100
[19:55:33.377] <TB1> INFO: Expecting 41600 events.
[19:55:37.301] <TB1> INFO: 41600 events read in total (3332ms).
[19:55:37.302] <TB1> INFO: Test took 4201ms.
[19:55:37.305] <TB1> INFO: scanning low vcal = 110
[19:55:37.581] <TB1> INFO: Expecting 41600 events.
[19:55:41.506] <TB1> INFO: 41600 events read in total (3333ms).
[19:55:41.507] <TB1> INFO: Test took 4202ms.
[19:55:41.510] <TB1> INFO: scanning low vcal = 120
[19:55:41.786] <TB1> INFO: Expecting 41600 events.
[19:55:45.719] <TB1> INFO: 41600 events read in total (3341ms).
[19:55:45.720] <TB1> INFO: Test took 4210ms.
[19:55:45.723] <TB1> INFO: scanning low vcal = 130
[19:55:45.999] <TB1> INFO: Expecting 41600 events.
[19:55:49.922] <TB1> INFO: 41600 events read in total (3331ms).
[19:55:49.923] <TB1> INFO: Test took 4200ms.
[19:55:49.926] <TB1> INFO: scanning low vcal = 140
[19:55:50.202] <TB1> INFO: Expecting 41600 events.
[19:55:54.190] <TB1> INFO: 41600 events read in total (3396ms).
[19:55:54.191] <TB1> INFO: Test took 4265ms.
[19:55:54.194] <TB1> INFO: scanning low vcal = 150
[19:55:54.475] <TB1> INFO: Expecting 41600 events.
[19:55:58.456] <TB1> INFO: 41600 events read in total (3390ms).
[19:55:58.457] <TB1> INFO: Test took 4263ms.
[19:55:58.460] <TB1> INFO: scanning low vcal = 160
[19:55:58.736] <TB1> INFO: Expecting 41600 events.
[19:56:02.738] <TB1> INFO: 41600 events read in total (3410ms).
[19:56:02.739] <TB1> INFO: Test took 4279ms.
[19:56:02.741] <TB1> INFO: scanning low vcal = 170
[19:56:03.018] <TB1> INFO: Expecting 41600 events.
[19:56:06.954] <TB1> INFO: 41600 events read in total (3344ms).
[19:56:06.955] <TB1> INFO: Test took 4214ms.
[19:56:06.958] <TB1> INFO: scanning low vcal = 180
[19:56:07.234] <TB1> INFO: Expecting 41600 events.
[19:56:11.157] <TB1> INFO: 41600 events read in total (3332ms).
[19:56:11.158] <TB1> INFO: Test took 4200ms.
[19:56:11.162] <TB1> INFO: scanning low vcal = 190
[19:56:11.438] <TB1> INFO: Expecting 41600 events.
[19:56:15.402] <TB1> INFO: 41600 events read in total (3372ms).
[19:56:15.403] <TB1> INFO: Test took 4241ms.
[19:56:15.406] <TB1> INFO: scanning low vcal = 200
[19:56:15.683] <TB1> INFO: Expecting 41600 events.
[19:56:19.626] <TB1> INFO: 41600 events read in total (3352ms).
[19:56:19.627] <TB1> INFO: Test took 4221ms.
[19:56:19.630] <TB1> INFO: scanning low vcal = 210
[19:56:19.907] <TB1> INFO: Expecting 41600 events.
[19:56:23.906] <TB1> INFO: 41600 events read in total (3409ms).
[19:56:23.907] <TB1> INFO: Test took 4277ms.
[19:56:23.910] <TB1> INFO: scanning low vcal = 220
[19:56:24.187] <TB1> INFO: Expecting 41600 events.
[19:56:28.131] <TB1> INFO: 41600 events read in total (3353ms).
[19:56:28.132] <TB1> INFO: Test took 4222ms.
[19:56:28.135] <TB1> INFO: scanning low vcal = 230
[19:56:28.412] <TB1> INFO: Expecting 41600 events.
[19:56:32.356] <TB1> INFO: 41600 events read in total (3353ms).
[19:56:32.357] <TB1> INFO: Test took 4221ms.
[19:56:32.360] <TB1> INFO: scanning low vcal = 240
[19:56:32.636] <TB1> INFO: Expecting 41600 events.
[19:56:36.559] <TB1> INFO: 41600 events read in total (3331ms).
[19:56:36.560] <TB1> INFO: Test took 4200ms.
[19:56:36.563] <TB1> INFO: scanning low vcal = 250
[19:56:36.839] <TB1> INFO: Expecting 41600 events.
[19:56:40.827] <TB1> INFO: 41600 events read in total (3396ms).
[19:56:40.828] <TB1> INFO: Test took 4265ms.
[19:56:40.832] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[19:56:41.107] <TB1> INFO: Expecting 41600 events.
[19:56:45.064] <TB1> INFO: 41600 events read in total (3365ms).
[19:56:45.065] <TB1> INFO: Test took 4233ms.
[19:56:45.068] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[19:56:45.344] <TB1> INFO: Expecting 41600 events.
[19:56:49.322] <TB1> INFO: 41600 events read in total (3386ms).
[19:56:49.323] <TB1> INFO: Test took 4255ms.
[19:56:49.326] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[19:56:49.602] <TB1> INFO: Expecting 41600 events.
[19:56:53.566] <TB1> INFO: 41600 events read in total (3372ms).
[19:56:53.566] <TB1> INFO: Test took 4240ms.
[19:56:53.569] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[19:56:53.846] <TB1> INFO: Expecting 41600 events.
[19:56:57.779] <TB1> INFO: 41600 events read in total (3341ms).
[19:56:57.780] <TB1> INFO: Test took 4210ms.
[19:56:57.783] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[19:56:58.060] <TB1> INFO: Expecting 41600 events.
[19:57:02.132] <TB1> INFO: 41600 events read in total (3481ms).
[19:57:02.133] <TB1> INFO: Test took 4349ms.
[19:57:02.857] <TB1> INFO: PixTestGainPedestal::measure() done
[19:57:41.553] <TB1> INFO: PixTestGainPedestal::fit() done
[19:57:41.553] <TB1> INFO: non-linearity mean: 0.968 0.950 0.937 0.934 0.959 0.929 0.980 0.926 0.941 0.957 0.945 1.023 0.937 0.983 0.947 0.981
[19:57:41.553] <TB1> INFO: non-linearity RMS: 0.166 0.191 0.078 0.090 0.031 0.095 0.004 0.148 0.080 0.063 0.062 0.167 0.076 0.006 0.068 0.005
[19:57:41.553] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C0.dat
[19:57:41.567] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C1.dat
[19:57:41.581] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C2.dat
[19:57:41.595] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C3.dat
[19:57:41.609] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C4.dat
[19:57:41.625] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C5.dat
[19:57:41.641] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C6.dat
[19:57:41.656] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C7.dat
[19:57:41.679] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C8.dat
[19:57:41.698] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C9.dat
[19:57:41.718] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C10.dat
[19:57:41.738] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C11.dat
[19:57:41.758] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C12.dat
[19:57:41.777] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C13.dat
[19:57:41.797] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C14.dat
[19:57:41.816] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C15.dat
[19:57:41.835] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 165 seconds
[19:57:41.835] <TB1> INFO: Decoding statistics:
[19:57:41.835] <TB1> INFO: General information:
[19:57:41.835] <TB1> INFO: 16bit words read: 3265840
[19:57:41.835] <TB1> INFO: valid events total: 332800
[19:57:41.835] <TB1> INFO: empty events: 3240
[19:57:41.835] <TB1> INFO: valid events with pixels: 329560
[19:57:41.835] <TB1> INFO: valid pixel hits: 634520
[19:57:41.835] <TB1> INFO: Event errors: 0
[19:57:41.835] <TB1> INFO: start marker: 0
[19:57:41.835] <TB1> INFO: stop marker: 0
[19:57:41.835] <TB1> INFO: overflow: 0
[19:57:41.835] <TB1> INFO: invalid 5bit words: 0
[19:57:41.835] <TB1> INFO: invalid XOR eye diagram: 0
[19:57:41.835] <TB1> INFO: frame (failed synchr.): 0
[19:57:41.835] <TB1> INFO: idle data (no TBM trl): 0
[19:57:41.835] <TB1> INFO: no data (only TBM hdr): 0
[19:57:41.835] <TB1> INFO: TBM errors: 0
[19:57:41.835] <TB1> INFO: flawed TBM headers: 0
[19:57:41.835] <TB1> INFO: flawed TBM trailers: 0
[19:57:41.835] <TB1> INFO: event ID mismatches: 0
[19:57:41.835] <TB1> INFO: ROC errors: 0
[19:57:41.835] <TB1> INFO: missing ROC header(s): 0
[19:57:41.835] <TB1> INFO: misplaced readback start: 0
[19:57:41.835] <TB1> INFO: Pixel decoding errors: 0
[19:57:41.835] <TB1> INFO: pixel data incomplete: 0
[19:57:41.835] <TB1> INFO: pixel address: 0
[19:57:41.835] <TB1> INFO: pulse height fill bit: 0
[19:57:41.835] <TB1> INFO: buffer corruption: 0
[19:57:41.855] <TB1> INFO: Decoding statistics:
[19:57:41.855] <TB1> INFO: General information:
[19:57:41.855] <TB1> INFO: 16bit words read: 3395256
[19:57:41.855] <TB1> INFO: valid events total: 353536
[19:57:41.855] <TB1> INFO: empty events: 21476
[19:57:41.855] <TB1> INFO: valid events with pixels: 332060
[19:57:41.855] <TB1> INFO: valid pixel hits: 637020
[19:57:41.855] <TB1> INFO: Event errors: 0
[19:57:41.855] <TB1> INFO: start marker: 0
[19:57:41.855] <TB1> INFO: stop marker: 0
[19:57:41.855] <TB1> INFO: overflow: 0
[19:57:41.855] <TB1> INFO: invalid 5bit words: 0
[19:57:41.855] <TB1> INFO: invalid XOR eye diagram: 0
[19:57:41.855] <TB1> INFO: frame (failed synchr.): 0
[19:57:41.855] <TB1> INFO: idle data (no TBM trl): 0
[19:57:41.855] <TB1> INFO: no data (only TBM hdr): 0
[19:57:41.855] <TB1> INFO: TBM errors: 0
[19:57:41.855] <TB1> INFO: flawed TBM headers: 0
[19:57:41.855] <TB1> INFO: flawed TBM trailers: 0
[19:57:41.855] <TB1> INFO: event ID mismatches: 0
[19:57:41.855] <TB1> INFO: ROC errors: 0
[19:57:41.855] <TB1> INFO: missing ROC header(s): 0
[19:57:41.855] <TB1> INFO: misplaced readback start: 0
[19:57:41.855] <TB1> INFO: Pixel decoding errors: 0
[19:57:41.855] <TB1> INFO: pixel data incomplete: 0
[19:57:41.855] <TB1> INFO: pixel address: 0
[19:57:41.855] <TB1> INFO: pulse height fill bit: 0
[19:57:41.855] <TB1> INFO: buffer corruption: 0
[19:57:41.855] <TB1> INFO: enter test to run
[19:57:41.855] <TB1> INFO: test: Trim80 no parameter change
[19:57:41.855] <TB1> INFO: running: trim80
[19:57:41.878] <TB1> INFO: ######################################################################
[19:57:41.879] <TB1> INFO: PixTestTrim80::doTest()
[19:57:41.879] <TB1> INFO: ######################################################################
[19:57:41.880] <TB1> INFO: ----------------------------------------------------------------------
[19:57:41.880] <TB1> INFO: PixTestTrim80::trimTest() ntrig = 8, vcal = 80
[19:57:41.880] <TB1> INFO: ----------------------------------------------------------------------
[19:57:41.936] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[19:57:41.936] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[19:57:41.948] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:57:41.948] <TB1> INFO: run 1 of 1
[19:57:42.181] <TB1> INFO: Expecting 5025280 events.
[19:58:09.987] <TB1> INFO: 685464 events read in total (27215ms).
[19:58:36.653] <TB1> INFO: 1365784 events read in total (53881ms).
[19:59:03.722] <TB1> INFO: 2044632 events read in total (80950ms).
[19:59:30.650] <TB1> INFO: 2721040 events read in total (107878ms).
[19:59:57.583] <TB1> INFO: 3396848 events read in total (134811ms).
[20:00:24.562] <TB1> INFO: 4071544 events read in total (161790ms).
[20:00:52.075] <TB1> INFO: 4746928 events read in total (189303ms).
[20:01:03.261] <TB1> INFO: 5025280 events read in total (200489ms).
[20:01:03.335] <TB1> INFO: Test took 201387ms.
[20:01:26.048] <TB1> INFO: ROC 0 VthrComp = 79
[20:01:26.048] <TB1> INFO: ROC 1 VthrComp = 82
[20:01:26.048] <TB1> INFO: ROC 2 VthrComp = 75
[20:01:26.048] <TB1> INFO: ROC 3 VthrComp = 88
[20:01:26.049] <TB1> INFO: ROC 4 VthrComp = 78
[20:01:26.049] <TB1> INFO: ROC 5 VthrComp = 73
[20:01:26.049] <TB1> INFO: ROC 6 VthrComp = 84
[20:01:26.049] <TB1> INFO: ROC 7 VthrComp = 74
[20:01:26.049] <TB1> INFO: ROC 8 VthrComp = 82
[20:01:26.049] <TB1> INFO: ROC 9 VthrComp = 89
[20:01:26.049] <TB1> INFO: ROC 10 VthrComp = 79
[20:01:26.049] <TB1> INFO: ROC 11 VthrComp = 77
[20:01:26.049] <TB1> INFO: ROC 12 VthrComp = 89
[20:01:26.050] <TB1> INFO: ROC 13 VthrComp = 83
[20:01:26.050] <TB1> INFO: ROC 14 VthrComp = 76
[20:01:26.050] <TB1> INFO: ROC 15 VthrComp = 71
[20:01:26.283] <TB1> INFO: Expecting 41600 events.
[20:01:29.737] <TB1> INFO: 41600 events read in total (2862ms).
[20:01:29.738] <TB1> INFO: Test took 3686ms.
[20:01:29.747] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[20:01:29.747] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[20:01:29.756] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:01:29.756] <TB1> INFO: run 1 of 1
[20:01:30.034] <TB1> INFO: Expecting 5025280 events.
[20:01:57.753] <TB1> INFO: 686448 events read in total (27128ms).
[20:02:24.464] <TB1> INFO: 1370320 events read in total (53839ms).
[20:02:51.169] <TB1> INFO: 2053136 events read in total (80544ms).
[20:03:17.999] <TB1> INFO: 2732560 events read in total (107374ms).
[20:03:44.547] <TB1> INFO: 3408552 events read in total (133922ms).
[20:04:11.238] <TB1> INFO: 4082368 events read in total (160613ms).
[20:04:37.752] <TB1> INFO: 4755584 events read in total (187127ms).
[20:04:48.707] <TB1> INFO: 5025280 events read in total (198082ms).
[20:04:48.752] <TB1> INFO: Test took 198996ms.
[20:05:13.727] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 107.863 for pixel 5/79 mean/min/max = 92.7665/77.4639/108.069
[20:05:13.728] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 106.9 for pixel 0/16 mean/min/max = 90.7767/74.4951/107.058
[20:05:13.728] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 113.092 for pixel 0/67 mean/min/max = 95.205/77.1547/113.255
[20:05:13.728] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 115.401 for pixel 0/49 mean/min/max = 95.1213/74.1262/116.116
[20:05:13.729] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 109.359 for pixel 0/28 mean/min/max = 93.8662/78.0539/109.678
[20:05:13.729] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 107.148 for pixel 0/15 mean/min/max = 92.2374/77.0826/107.392
[20:05:13.729] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 109.167 for pixel 12/3 mean/min/max = 91.7444/74.2791/109.21
[20:05:13.730] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 109.283 for pixel 0/69 mean/min/max = 93.1278/76.8432/109.412
[20:05:13.730] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 109.514 for pixel 0/78 mean/min/max = 92.3153/74.9655/109.665
[20:05:13.730] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 108.966 for pixel 0/59 mean/min/max = 92.7348/76.44/109.03
[20:05:13.730] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 112.442 for pixel 51/12 mean/min/max = 94.8848/74.7358/115.034
[20:05:13.731] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 113.168 for pixel 0/26 mean/min/max = 94.8263/76.3696/113.283
[20:05:13.731] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 113.267 for pixel 0/72 mean/min/max = 94.4738/75.5418/113.406
[20:05:13.731] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 109.339 for pixel 0/34 mean/min/max = 91.8913/74.3513/109.431
[20:05:13.732] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 110.286 for pixel 0/12 mean/min/max = 93.8046/77.1917/110.418
[20:05:13.732] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 105.044 for pixel 5/79 mean/min/max = 89.1429/72.9683/105.318
[20:05:13.732] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:05:13.821] <TB1> INFO: Expecting 411648 events.
[20:05:23.189] <TB1> INFO: 411648 events read in total (8777ms).
[20:05:23.196] <TB1> INFO: Expecting 411648 events.
[20:05:32.341] <TB1> INFO: 411648 events read in total (8742ms).
[20:05:32.352] <TB1> INFO: Expecting 411648 events.
[20:05:41.473] <TB1> INFO: 411648 events read in total (8718ms).
[20:05:41.486] <TB1> INFO: Expecting 411648 events.
[20:05:50.656] <TB1> INFO: 411648 events read in total (8767ms).
[20:05:50.672] <TB1> INFO: Expecting 411648 events.
[20:05:59.884] <TB1> INFO: 411648 events read in total (8809ms).
[20:05:59.905] <TB1> INFO: Expecting 411648 events.
[20:06:09.077] <TB1> INFO: 411648 events read in total (8769ms).
[20:06:09.103] <TB1> INFO: Expecting 411648 events.
[20:06:18.181] <TB1> INFO: 411648 events read in total (8675ms).
[20:06:18.205] <TB1> INFO: Expecting 411648 events.
[20:06:27.348] <TB1> INFO: 411648 events read in total (8740ms).
[20:06:27.380] <TB1> INFO: Expecting 411648 events.
[20:06:36.425] <TB1> INFO: 411648 events read in total (8642ms).
[20:06:36.455] <TB1> INFO: Expecting 411648 events.
[20:06:45.561] <TB1> INFO: 411648 events read in total (8703ms).
[20:06:45.605] <TB1> INFO: Expecting 411648 events.
[20:06:54.824] <TB1> INFO: 411648 events read in total (8816ms).
[20:06:54.857] <TB1> INFO: Expecting 411648 events.
[20:07:04.163] <TB1> INFO: 411648 events read in total (8903ms).
[20:07:04.201] <TB1> INFO: Expecting 411648 events.
[20:07:13.501] <TB1> INFO: 411648 events read in total (8898ms).
[20:07:13.544] <TB1> INFO: Expecting 411648 events.
[20:07:22.829] <TB1> INFO: 411648 events read in total (8882ms).
[20:07:22.870] <TB1> INFO: Expecting 411648 events.
[20:07:31.949] <TB1> INFO: 411648 events read in total (8676ms).
[20:07:31.000] <TB1> INFO: Expecting 411648 events.
[20:07:41.156] <TB1> INFO: 411648 events read in total (8753ms).
[20:07:41.203] <TB1> INFO: Test took 147471ms.
[20:07:42.819] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[20:07:42.830] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:07:42.830] <TB1> INFO: run 1 of 1
[20:07:43.110] <TB1> INFO: Expecting 5025280 events.
[20:08:10.664] <TB1> INFO: 667544 events read in total (26963ms).
[20:08:37.083] <TB1> INFO: 1331352 events read in total (53382ms).
[20:09:03.679] <TB1> INFO: 1996136 events read in total (79978ms).
[20:09:30.282] <TB1> INFO: 2657816 events read in total (106581ms).
[20:09:56.739] <TB1> INFO: 3316200 events read in total (133038ms).
[20:10:23.536] <TB1> INFO: 3973704 events read in total (159835ms).
[20:10:50.153] <TB1> INFO: 4628320 events read in total (186452ms).
[20:11:06.324] <TB1> INFO: 5025280 events read in total (202623ms).
[20:11:06.390] <TB1> INFO: Test took 203560ms.
[20:11:32.556] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 51.097491 .. 145.228040
[20:11:32.792] <TB1> INFO: Expecting 208000 events.
[20:11:42.553] <TB1> INFO: 208000 events read in total (9169ms).
[20:11:42.554] <TB1> INFO: Test took 9996ms.
[20:11:42.600] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 41 .. 155 (-1/-1) hits flags = 528 (plus default)
[20:11:42.610] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:11:42.610] <TB1> INFO: run 1 of 1
[20:11:42.888] <TB1> INFO: Expecting 3827200 events.
[20:12:09.733] <TB1> INFO: 620504 events read in total (26254ms).
[20:12:36.019] <TB1> INFO: 1241208 events read in total (52540ms).
[20:13:01.951] <TB1> INFO: 1860688 events read in total (78472ms).
[20:13:27.972] <TB1> INFO: 2477920 events read in total (104493ms).
[20:13:54.530] <TB1> INFO: 3093840 events read in total (131051ms).
[20:14:20.222] <TB1> INFO: 3708784 events read in total (156743ms).
[20:14:25.539] <TB1> INFO: 3827200 events read in total (162060ms).
[20:14:25.588] <TB1> INFO: Test took 162978ms.
[20:14:49.732] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 62.256880 .. 150.937993
[20:14:49.969] <TB1> INFO: Expecting 208000 events.
[20:14:59.753] <TB1> INFO: 208000 events read in total (9192ms).
[20:14:59.754] <TB1> INFO: Test took 10020ms.
[20:14:59.799] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 52 .. 160 (-1/-1) hits flags = 528 (plus default)
[20:14:59.810] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:14:59.810] <TB1> INFO: run 1 of 1
[20:15:00.088] <TB1> INFO: Expecting 3627520 events.
[20:15:25.764] <TB1> INFO: 595048 events read in total (25085ms).
[20:15:51.395] <TB1> INFO: 1190104 events read in total (50716ms).
[20:16:16.827] <TB1> INFO: 1785000 events read in total (76148ms).
[20:16:42.444] <TB1> INFO: 2379640 events read in total (101765ms).
[20:17:08.541] <TB1> INFO: 2974296 events read in total (127862ms).
[20:17:34.615] <TB1> INFO: 3568616 events read in total (153936ms).
[20:17:37.653] <TB1> INFO: 3627520 events read in total (156974ms).
[20:17:37.701] <TB1> INFO: Test took 157891ms.
[20:18:02.256] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 66.307449 .. 155.042478
[20:18:02.510] <TB1> INFO: Expecting 208000 events.
[20:18:12.183] <TB1> INFO: 208000 events read in total (9082ms).
[20:18:12.184] <TB1> INFO: Test took 9927ms.
[20:18:12.244] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 56 .. 165 (-1/-1) hits flags = 528 (plus default)
[20:18:12.255] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:18:12.255] <TB1> INFO: run 1 of 1
[20:18:12.532] <TB1> INFO: Expecting 3660800 events.
[20:18:38.241] <TB1> INFO: 584728 events read in total (25117ms).
[20:19:03.153] <TB1> INFO: 1169224 events read in total (50029ms).
[20:19:28.347] <TB1> INFO: 1753840 events read in total (75223ms).
[20:19:53.685] <TB1> INFO: 2338264 events read in total (100561ms).
[20:20:19.346] <TB1> INFO: 2922696 events read in total (126222ms).
[20:20:45.093] <TB1> INFO: 3506904 events read in total (151969ms).
[20:20:52.221] <TB1> INFO: 3660800 events read in total (159097ms).
[20:20:52.280] <TB1> INFO: Test took 160025ms.
[20:21:14.427] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 69.681672 .. 158.531131
[20:21:14.684] <TB1> INFO: Expecting 208000 events.
[20:21:24.406] <TB1> INFO: 208000 events read in total (9130ms).
[20:21:24.407] <TB1> INFO: Test took 9979ms.
[20:21:24.466] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 59 .. 168 (-1/-1) hits flags = 528 (plus default)
[20:21:24.479] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:21:24.479] <TB1> INFO: run 1 of 1
[20:21:24.757] <TB1> INFO: Expecting 3660800 events.
[20:21:51.091] <TB1> INFO: 578072 events read in total (25743ms).
[20:22:16.343] <TB1> INFO: 1156064 events read in total (50996ms).
[20:22:41.685] <TB1> INFO: 1733952 events read in total (76337ms).
[20:23:06.861] <TB1> INFO: 2311672 events read in total (101513ms).
[20:23:32.329] <TB1> INFO: 2889520 events read in total (126981ms).
[20:23:57.997] <TB1> INFO: 3467120 events read in total (152649ms).
[20:24:06.499] <TB1> INFO: 3660800 events read in total (161151ms).
[20:24:06.558] <TB1> INFO: Test took 162080ms.
[20:24:31.071] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 60 .. 100
[20:24:31.071] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 60 .. 100 (-1/-1) hits flags = 528 (plus default)
[20:24:31.082] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:24:31.082] <TB1> INFO: run 1 of 1
[20:24:31.332] <TB1> INFO: Expecting 1364480 events.
[20:24:59.610] <TB1> INFO: 668008 events read in total (27686ms).
[20:25:26.931] <TB1> INFO: 1335648 events read in total (55007ms).
[20:25:28.519] <TB1> INFO: 1364480 events read in total (56595ms).
[20:25:28.540] <TB1> INFO: Test took 57458ms.
[20:25:44.978] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C0.dat
[20:25:44.978] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C1.dat
[20:25:44.978] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C2.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C3.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C4.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C5.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C6.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C7.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C8.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C9.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C10.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C11.dat
[20:25:44.979] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C12.dat
[20:25:44.980] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C13.dat
[20:25:44.980] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C14.dat
[20:25:44.980] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C15.dat
[20:25:44.980] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C0.dat
[20:25:44.988] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C1.dat
[20:25:44.997] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C2.dat
[20:25:45.005] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C3.dat
[20:25:45.012] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C4.dat
[20:25:45.018] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C5.dat
[20:25:45.023] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C6.dat
[20:25:45.029] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C7.dat
[20:25:45.034] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C8.dat
[20:25:45.040] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C9.dat
[20:25:45.045] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C10.dat
[20:25:45.051] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C11.dat
[20:25:45.056] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C12.dat
[20:25:45.062] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C13.dat
[20:25:45.067] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C14.dat
[20:25:45.076] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1001_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C15.dat
[20:25:45.084] <TB1> INFO: PixTestTrim80::trimTest() done
[20:25:45.084] <TB1> INFO: vtrim: 103 102 111 121 107 92 119 98 105 109 127 120 122 111 96 91
[20:25:45.084] <TB1> INFO: vthrcomp: 79 82 75 88 78 73 84 74 82 89 79 77 89 83 76 71
[20:25:45.084] <TB1> INFO: vcal mean: 79.94 79.95 79.97 79.64 79.96 79.94 79.90 79.96 79.94 79.96 79.84 79.68 79.95 79.93 79.93 79.92
[20:25:45.084] <TB1> INFO: vcal RMS: 0.75 0.74 0.74 5.08 0.69 0.69 1.91 0.70 0.75 0.75 3.19 4.89 0.77 0.77 0.76 0.76
[20:25:45.084] <TB1> INFO: bits mean: 9.57 10.24 9.26 10.01 9.44 9.44 10.57 9.75 9.51 9.92 10.09 9.93 9.52 10.51 9.67 10.42
[20:25:45.084] <TB1> INFO: bits RMS: 2.27 2.35 2.32 2.19 2.19 2.37 2.16 2.23 2.63 2.21 2.07 2.05 2.39 2.23 2.21 2.65
[20:25:45.090] <TB1> INFO: ----------------------------------------------------------------------
[20:25:45.091] <TB1> INFO: PixTestTrim80::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[20:25:45.091] <TB1> INFO: ----------------------------------------------------------------------
[20:25:45.093] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[20:25:45.104] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:25:45.104] <TB1> INFO: run 1 of 1
[20:25:45.431] <TB1> INFO: Expecting 4160000 events.
[20:26:17.906] <TB1> INFO: 778795 events read in total (31884ms).
[20:26:50.026] <TB1> INFO: 1549515 events read in total (64004ms).
[20:27:21.737] <TB1> INFO: 2314735 events read in total (95715ms).
[20:27:53.072] <TB1> INFO: 3074415 events read in total (127050ms).
[20:28:24.280] <TB1> INFO: 3831065 events read in total (158258ms).
[20:28:37.881] <TB1> INFO: 4160000 events read in total (171859ms).
[20:28:37.939] <TB1> INFO: Test took 172835ms.
[20:29:02.702] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 226 (-1/-1) hits flags = 528 (plus default)
[20:29:02.713] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:29:02.713] <TB1> INFO: run 1 of 1
[20:29:02.946] <TB1> INFO: Expecting 4721600 events.
[20:29:34.121] <TB1> INFO: 716515 events read in total (30583ms).
[20:30:04.610] <TB1> INFO: 1428040 events read in total (61072ms).
[20:30:34.766] <TB1> INFO: 2136495 events read in total (91228ms).
[20:31:04.915] <TB1> INFO: 2843055 events read in total (121377ms).
[20:31:35.098] <TB1> INFO: 3545870 events read in total (151560ms).
[20:32:05.391] <TB1> INFO: 4247000 events read in total (181853ms).
[20:32:26.644] <TB1> INFO: 4721600 events read in total (203106ms).
[20:32:26.727] <TB1> INFO: Test took 204014ms.
[20:32:53.427] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[20:32:53.437] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:32:53.437] <TB1> INFO: run 1 of 1
[20:32:53.668] <TB1> INFO: Expecting 5324800 events.
[20:33:25.485] <TB1> INFO: 690405 events read in total (31225ms).
[20:33:55.328] <TB1> INFO: 1376740 events read in total (61068ms).
[20:34:24.189] <TB1> INFO: 2061800 events read in total (89929ms).
[20:34:53.532] <TB1> INFO: 2744595 events read in total (119272ms).
[20:35:25.163] <TB1> INFO: 3425995 events read in total (150903ms).
[20:35:53.793] <TB1> INFO: 4104940 events read in total (179533ms).
[20:36:22.462] <TB1> INFO: 4783080 events read in total (208202ms).
[20:36:45.524] <TB1> INFO: 5324800 events read in total (231264ms).
[20:36:45.595] <TB1> INFO: Test took 232158ms.
[20:37:12.783] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[20:37:12.794] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:37:12.794] <TB1> INFO: run 1 of 1
[20:37:13.029] <TB1> INFO: Expecting 5324800 events.
[20:37:44.103] <TB1> INFO: 691730 events read in total (30482ms).
[20:38:12.915] <TB1> INFO: 1379090 events read in total (59294ms).
[20:38:41.758] <TB1> INFO: 2064635 events read in total (88138ms).
[20:39:10.598] <TB1> INFO: 2747915 events read in total (116977ms).
[20:39:39.318] <TB1> INFO: 3429280 events read in total (145697ms).
[20:40:08.031] <TB1> INFO: 4108450 events read in total (174410ms).
[20:40:36.682] <TB1> INFO: 4786565 events read in total (203061ms).
[20:40:59.961] <TB1> INFO: 5324800 events read in total (226340ms).
[20:41:00.040] <TB1> INFO: Test took 227246ms.
[20:41:26.956] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[20:41:26.966] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:41:26.966] <TB1> INFO: run 1 of 1
[20:41:27.199] <TB1> INFO: Expecting 5324800 events.
[20:41:56.776] <TB1> INFO: 691750 events read in total (28985ms).
[20:42:25.679] <TB1> INFO: 1379315 events read in total (57888ms).
[20:42:54.526] <TB1> INFO: 2064950 events read in total (86735ms).
[20:43:23.357] <TB1> INFO: 2748015 events read in total (115566ms).
[20:43:52.440] <TB1> INFO: 3429315 events read in total (144649ms).
[20:44:21.119] <TB1> INFO: 4108520 events read in total (173328ms).
[20:44:49.843] <TB1> INFO: 4786775 events read in total (202052ms).
[20:45:15.195] <TB1> INFO: 5324800 events read in total (227404ms).
[20:45:15.293] <TB1> INFO: Test took 228327ms.
[20:45:59.983] <TB1> INFO: PixTestTrim80::trimBitTest() done
[20:45:59.984] <TB1> INFO: PixTestTrim80::doTest() done, duration: 2898 seconds
[20:46:00.906] <TB1> INFO: enter test to run
[20:46:00.906] <TB1> INFO: test: exit no parameter change
[20:46:01.025] <TB1> QUIET: Connection to board 153 closed.
[20:46:01.026] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud