Test Date: 2016-10-26 12:02
Analysis date: 2016-10-26 17:27
Logfile
LogfileView
[14:34:48.299] <TB3> INFO: *** Welcome to pxar ***
[14:34:48.299] <TB3> INFO: *** Today: 2016/10/26
[14:34:48.307] <TB3> INFO: *** Version: c8ba-dirty
[14:34:48.307] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C15.dat
[14:34:48.308] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[14:34:48.308] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//defaultMaskFile.dat
[14:34:48.309] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters_C15.dat
[14:34:48.372] <TB3> INFO: clk: 4
[14:34:48.372] <TB3> INFO: ctr: 4
[14:34:48.372] <TB3> INFO: sda: 19
[14:34:48.372] <TB3> INFO: tin: 9
[14:34:48.372] <TB3> INFO: level: 15
[14:34:48.372] <TB3> INFO: triggerdelay: 0
[14:34:48.372] <TB3> QUIET: Instanciating API for pxar v2.7.6+61~g7f4a123
[14:34:48.373] <TB3> INFO: Log level: INFO
[14:34:48.382] <TB3> INFO: Found DTB DTB_WWVASW
[14:34:48.390] <TB3> QUIET: Connection to board DTB_WWVASW opened.
[14:34:48.392] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 126
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWVASW
MAC address: 40D85511807E
Hostname: pixelDTB126
Comment:
------------------------------------------------------
[14:34:48.394] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[14:34:49.901] <TB3> INFO: DUT info:
[14:34:49.901] <TB3> INFO: The DUT currently contains the following objects:
[14:34:49.901] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[14:34:49.901] <TB3> INFO: TBM Core alpha (0): 7 registers set
[14:34:49.901] <TB3> INFO: TBM Core beta (1): 7 registers set
[14:34:49.901] <TB3> INFO: TBM Core alpha (2): 7 registers set
[14:34:49.901] <TB3> INFO: TBM Core beta (3): 7 registers set
[14:34:49.901] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[14:34:49.901] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.901] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.901] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.901] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:49.902] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:50.303] <TB3> INFO: enter 'restricted' command line mode
[14:34:50.303] <TB3> INFO: enter test to run
[14:34:50.303] <TB3> INFO: test: pretest no parameter change
[14:34:50.303] <TB3> INFO: running: pretest
[14:34:50.312] <TB3> INFO: ######################################################################
[14:34:50.312] <TB3> INFO: PixTestPretest::doTest()
[14:34:50.312] <TB3> INFO: ######################################################################
[14:34:50.313] <TB3> INFO: ----------------------------------------------------------------------
[14:34:50.313] <TB3> INFO: PixTestPretest::programROC()
[14:34:50.313] <TB3> INFO: ----------------------------------------------------------------------
[14:35:08.329] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[14:35:08.329] <TB3> INFO: IA differences per ROC: 17.7 18.5 20.9 18.5 20.1 16.9 18.5 20.1 20.1 16.1 18.5 18.5 20.9 19.3 20.9 19.3
[14:35:08.395] <TB3> INFO: ----------------------------------------------------------------------
[14:35:08.395] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[14:35:08.395] <TB3> INFO: ----------------------------------------------------------------------
[14:35:15.497] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 383.5 mA = 23.9688 mA/ROC
[14:35:15.497] <TB3> INFO: i(loss) [mA/ROC]: 19.3 20.1 19.3 19.3 20.1 19.3 19.3 19.3 19.3 19.3 18.5 18.5 19.3 18.5 19.3 18.5
[14:35:15.531] <TB3> INFO: ----------------------------------------------------------------------
[14:35:15.531] <TB3> INFO: PixTestPretest::findTiming()
[14:35:15.531] <TB3> INFO: ----------------------------------------------------------------------
[14:35:15.531] <TB3> INFO: PixTestCmd::init()
[14:35:16.093] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!

[14:35:47.802] <TB3> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[14:35:47.802] <TB3> INFO: (success/tries = 100/100), width = 4
[14:35:49.309] <TB3> INFO: ----------------------------------------------------------------------
[14:35:49.309] <TB3> INFO: PixTestPretest::findWorkingPixel()
[14:35:49.309] <TB3> INFO: ----------------------------------------------------------------------
[14:35:49.404] <TB3> INFO: Expecting 231680 events.
[14:35:59.307] <TB3> INFO: 231680 events read in total (9312ms).
[14:35:59.317] <TB3> INFO: Test took 10003ms.
[14:35:59.569] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[14:35:59.603] <TB3> INFO: ----------------------------------------------------------------------
[14:35:59.603] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[14:35:59.603] <TB3> INFO: ----------------------------------------------------------------------
[14:35:59.699] <TB3> INFO: Expecting 231680 events.
[14:36:09.751] <TB3> INFO: 231680 events read in total (9460ms).
[14:36:09.764] <TB3> INFO: Test took 10154ms.
[14:36:10.035] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[14:36:10.035] <TB3> INFO: CalDel: 83 88 110 92 93 73 91 96 93 92 83 91 90 87 110 106
[14:36:10.036] <TB3> INFO: VthrComp: 51 57 51 51 51 51 51 51 51 51 52 51 51 51 59 51
[14:36:10.039] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C0.dat
[14:36:10.039] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C1.dat
[14:36:10.040] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C2.dat
[14:36:10.040] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C3.dat
[14:36:10.040] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C4.dat
[14:36:10.040] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C5.dat
[14:36:10.040] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C6.dat
[14:36:10.040] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C7.dat
[14:36:10.040] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C8.dat
[14:36:10.040] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C9.dat
[14:36:10.041] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C10.dat
[14:36:10.041] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C11.dat
[14:36:10.041] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C12.dat
[14:36:10.041] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C13.dat
[14:36:10.041] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C14.dat
[14:36:10.041] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C15.dat
[14:36:10.041] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C0a.dat
[14:36:10.041] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C0b.dat
[14:36:10.042] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C1a.dat
[14:36:10.042] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[14:36:10.042] <TB3> INFO: PixTestPretest::doTest() done, duration: 79 seconds
[14:36:10.095] <TB3> INFO: enter test to run
[14:36:10.095] <TB3> INFO: test: fulltest no parameter change
[14:36:10.095] <TB3> INFO: running: fulltest
[14:36:10.095] <TB3> INFO: ######################################################################
[14:36:10.095] <TB3> INFO: PixTestFullTest::doTest()
[14:36:10.095] <TB3> INFO: ######################################################################
[14:36:10.097] <TB3> INFO: ######################################################################
[14:36:10.097] <TB3> INFO: PixTestAlive::doTest()
[14:36:10.097] <TB3> INFO: ######################################################################
[14:36:10.098] <TB3> INFO: ----------------------------------------------------------------------
[14:36:10.098] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:36:10.098] <TB3> INFO: ----------------------------------------------------------------------
[14:36:10.337] <TB3> INFO: Expecting 41600 events.
[14:36:13.956] <TB3> INFO: 41600 events read in total (3028ms).
[14:36:13.956] <TB3> INFO: Test took 3856ms.
[14:36:14.190] <TB3> INFO: PixTestAlive::aliveTest() done
[14:36:14.190] <TB3> INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:36:14.192] <TB3> INFO: ----------------------------------------------------------------------
[14:36:14.192] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:36:14.192] <TB3> INFO: ----------------------------------------------------------------------
[14:36:14.456] <TB3> INFO: Expecting 41600 events.
[14:36:17.446] <TB3> INFO: 41600 events read in total (2399ms).
[14:36:17.446] <TB3> INFO: Test took 3252ms.
[14:36:17.447] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[14:36:17.687] <TB3> INFO: PixTestAlive::maskTest() done
[14:36:17.687] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:36:17.689] <TB3> INFO: ----------------------------------------------------------------------
[14:36:17.689] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:36:17.689] <TB3> INFO: ----------------------------------------------------------------------
[14:36:17.934] <TB3> INFO: Expecting 41600 events.
[14:36:21.470] <TB3> INFO: 41600 events read in total (2944ms).
[14:36:21.470] <TB3> INFO: Test took 3776ms.
[14:36:21.702] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[14:36:21.702] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:36:21.702] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[14:36:21.702] <TB3> INFO: Decoding statistics:
[14:36:21.702] <TB3> INFO: General information:
[14:36:21.702] <TB3> INFO: 16bit words read: 0
[14:36:21.702] <TB3> INFO: valid events total: 0
[14:36:21.702] <TB3> INFO: empty events: 0
[14:36:21.702] <TB3> INFO: valid events with pixels: 0
[14:36:21.703] <TB3> INFO: valid pixel hits: 0
[14:36:21.703] <TB3> INFO: Event errors: 0
[14:36:21.703] <TB3> INFO: start marker: 0
[14:36:21.703] <TB3> INFO: stop marker: 0
[14:36:21.703] <TB3> INFO: overflow: 0
[14:36:21.703] <TB3> INFO: invalid 5bit words: 0
[14:36:21.703] <TB3> INFO: invalid XOR eye diagram: 0
[14:36:21.703] <TB3> INFO: frame (failed synchr.): 0
[14:36:21.703] <TB3> INFO: idle data (no TBM trl): 0
[14:36:21.703] <TB3> INFO: no data (only TBM hdr): 0
[14:36:21.703] <TB3> INFO: TBM errors: 0
[14:36:21.703] <TB3> INFO: flawed TBM headers: 0
[14:36:21.703] <TB3> INFO: flawed TBM trailers: 0
[14:36:21.703] <TB3> INFO: event ID mismatches: 0
[14:36:21.703] <TB3> INFO: ROC errors: 0
[14:36:21.703] <TB3> INFO: missing ROC header(s): 0
[14:36:21.703] <TB3> INFO: misplaced readback start: 0
[14:36:21.703] <TB3> INFO: Pixel decoding errors: 0
[14:36:21.703] <TB3> INFO: pixel data incomplete: 0
[14:36:21.703] <TB3> INFO: pixel address: 0
[14:36:21.703] <TB3> INFO: pulse height fill bit: 0
[14:36:21.703] <TB3> INFO: buffer corruption: 0
[14:36:21.710] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:36:21.711] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr_C15.dat
[14:36:21.711] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[14:36:21.711] <TB3> INFO: ######################################################################
[14:36:21.711] <TB3> INFO: PixTestReadback::doTest()
[14:36:21.711] <TB3> INFO: ######################################################################
[14:36:21.711] <TB3> INFO: ----------------------------------------------------------------------
[14:36:21.711] <TB3> INFO: PixTestReadback::CalibrateVd()
[14:36:21.711] <TB3> INFO: ----------------------------------------------------------------------
[14:36:31.699] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C0.dat
[14:36:31.699] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C1.dat
[14:36:31.699] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C2.dat
[14:36:31.699] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C3.dat
[14:36:31.699] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C4.dat
[14:36:31.699] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C5.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C6.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C7.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C8.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C9.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C10.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C11.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C12.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C13.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C14.dat
[14:36:31.700] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:36:31.734] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[14:36:31.734] <TB3> INFO: ----------------------------------------------------------------------
[14:36:31.734] <TB3> INFO: PixTestReadback::CalibrateVa()
[14:36:31.734] <TB3> INFO: ----------------------------------------------------------------------
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C0.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C1.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C2.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C3.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C4.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C5.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C6.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C7.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C8.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C9.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C10.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C11.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C12.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C13.dat
[14:36:41.674] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C14.dat
[14:36:41.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:36:41.707] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[14:36:41.707] <TB3> INFO: ----------------------------------------------------------------------
[14:36:41.707] <TB3> INFO: PixTestReadback::readbackVbg()
[14:36:41.707] <TB3> INFO: ----------------------------------------------------------------------
[14:36:49.386] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[14:36:49.386] <TB3> INFO: ----------------------------------------------------------------------
[14:36:49.386] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[14:36:49.386] <TB3> INFO: ----------------------------------------------------------------------
[14:36:49.386] <TB3> INFO: Vbg will be calibrated using Vd calibration
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 153.8calibrated Vbg = 1.20803 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 157.2calibrated Vbg = 1.20652 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 145.5calibrated Vbg = 1.20475 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 158.9calibrated Vbg = 1.20505 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 153.5calibrated Vbg = 1.21225 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 164.3calibrated Vbg = 1.21389 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 157.3calibrated Vbg = 1.21807 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 156.4calibrated Vbg = 1.21606 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 165.3calibrated Vbg = 1.21078 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 155.9calibrated Vbg = 1.20318 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 156.9calibrated Vbg = 1.20322 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 157calibrated Vbg = 1.20323 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 157.4calibrated Vbg = 1.20567 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 157.1calibrated Vbg = 1.20918 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 159.9calibrated Vbg = 1.20744 :::*/*/*/*/
[14:36:49.386] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 162.8calibrated Vbg = 1.21199 :::*/*/*/*/
[14:36:49.389] <TB3> INFO: ----------------------------------------------------------------------
[14:36:49.389] <TB3> INFO: PixTestReadback::CalibrateIa()
[14:36:49.389] <TB3> INFO: ----------------------------------------------------------------------
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C0.dat
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C1.dat
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C2.dat
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C3.dat
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C4.dat
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C5.dat
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C6.dat
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C7.dat
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C8.dat
[14:39:30.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C9.dat
[14:39:30.220] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C10.dat
[14:39:30.220] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C11.dat
[14:39:30.220] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C12.dat
[14:39:30.220] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C13.dat
[14:39:30.220] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C14.dat
[14:39:30.220] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:39:30.247] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[14:39:30.249] <TB3> INFO: PixTestReadback::doTest() done
[14:39:30.249] <TB3> INFO: Decoding statistics:
[14:39:30.249] <TB3> INFO: General information:
[14:39:30.249] <TB3> INFO: 16bit words read: 1536
[14:39:30.249] <TB3> INFO: valid events total: 256
[14:39:30.249] <TB3> INFO: empty events: 256
[14:39:30.249] <TB3> INFO: valid events with pixels: 0
[14:39:30.249] <TB3> INFO: valid pixel hits: 0
[14:39:30.249] <TB3> INFO: Event errors: 0
[14:39:30.249] <TB3> INFO: start marker: 0
[14:39:30.249] <TB3> INFO: stop marker: 0
[14:39:30.249] <TB3> INFO: overflow: 0
[14:39:30.249] <TB3> INFO: invalid 5bit words: 0
[14:39:30.249] <TB3> INFO: invalid XOR eye diagram: 0
[14:39:30.249] <TB3> INFO: frame (failed synchr.): 0
[14:39:30.249] <TB3> INFO: idle data (no TBM trl): 0
[14:39:30.249] <TB3> INFO: no data (only TBM hdr): 0
[14:39:30.249] <TB3> INFO: TBM errors: 0
[14:39:30.249] <TB3> INFO: flawed TBM headers: 0
[14:39:30.249] <TB3> INFO: flawed TBM trailers: 0
[14:39:30.249] <TB3> INFO: event ID mismatches: 0
[14:39:30.249] <TB3> INFO: ROC errors: 0
[14:39:30.249] <TB3> INFO: missing ROC header(s): 0
[14:39:30.249] <TB3> INFO: misplaced readback start: 0
[14:39:30.249] <TB3> INFO: Pixel decoding errors: 0
[14:39:30.250] <TB3> INFO: pixel data incomplete: 0
[14:39:30.250] <TB3> INFO: pixel address: 0
[14:39:30.250] <TB3> INFO: pulse height fill bit: 0
[14:39:30.250] <TB3> INFO: buffer corruption: 0
[14:39:30.303] <TB3> INFO: ######################################################################
[14:39:30.303] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[14:39:30.303] <TB3> INFO: ######################################################################
[14:39:30.306] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[14:39:30.378] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[14:39:30.378] <TB3> INFO: run 1 of 1
[14:39:30.621] <TB3> INFO: Expecting 3120000 events.
[14:40:01.615] <TB3> INFO: 666455 events read in total (30402ms).
[14:40:13.951] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (216) != TBM ID (129)

[14:40:14.091] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 216 216 129 216 216 216 216 216

[14:40:14.091] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (217)

[14:40:14.091] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:40:14.091] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dc 80b1 4811 262 21ec 4811 262 21ef e022 c000

[14:40:14.091] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d6 8000 4810 262 21e8 4810 262 21ef e022 c000

[14:40:14.091] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d7 8040 4c00 262 21e9 4810 262 21ef e022 c000

[14:40:14.091] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4811 4811 21e9 4810 262 21ef e022 c000

[14:40:14.091] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d9 80c0 4c11 262 21ec 4811 262 21ef e022 c000

[14:40:14.091] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0da 8000 4c10 262 21e9 4810 262 21ef e022 c000

[14:40:14.091] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0db 8040 4811 262 21ec 4811 262 21ef e022 c000

[14:40:32.344] <TB3> INFO: 1336865 events read in total (61131ms).
[14:40:44.609] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (162) != TBM ID (129)

[14:40:44.744] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 162 162 129 162 162 162 162 162

[14:40:44.744] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (163)

[14:40:44.746] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:40:44.746] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a6 8000 4c00 4c00 e022 c000

[14:40:44.746] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a0 80b1 4810 4810 e022 c000

[14:40:44.746] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a1 80c0 4811 4811 e022 c000

[14:40:44.746] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4811 4811 4c4 2def e022 c000

[14:40:44.746] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a3 8040 4810 4811 e022 c000

[14:40:44.746] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a4 80b1 4810 4810 e022 c000

[14:40:44.746] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a5 80c0 4c00 4c00 e022 c000

[14:41:02.337] <TB3> INFO: 2003985 events read in total (91124ms).
[14:41:14.594] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (146) != TBM ID (129)

[14:41:14.731] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 146 146 129 146 146 146 146 146

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

[14:41:14.732] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:41:14.732] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a096 8000 4810 4810 826 2fef e022 c000

[14:41:14.732] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a090 80b1 4c10 4c10 826 2fef e022 c000

[14:41:14.732] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a091 80c0 4811 4811 826 2fed e022 c000

[14:41:14.732] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4811 4811 e022 c000

[14:41:14.732] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a093 8040 4810 4811 826 2fe9 e022 c000

[14:41:14.732] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a094 80b1 4810 4810 826 2fed e022 c000

[14:41:14.732] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a095 80c0 4c10 4810 e022 c000

[14:41:34.397] <TB3> INFO: 2670715 events read in total (123184ms).
[14:41:42.765] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (252) != TBM ID (129)

[14:41:42.907] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 252 252 129 252 252 252 252 252

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

[14:41:42.907] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:41:42.907] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a000 80b1 4c10 4810 a8a 21ef e022 c000

[14:41:42.907] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fa 8000 4810 a8a 21ef 4c10 a8a 21ef e022 c000

[14:41:42.907] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fb 8040 4c00 a8a 21ef 4c10 a8a 21ef e022 c000

[14:41:42.907] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4811 4811 21ef 4c11 a8a 21ef e022 c000

[14:41:42.907] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fd 80c0 4811 a8a 21ef 4811 a8a 21ef e022 c000

[14:41:42.907] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fe 8000 4810 4810 a8a 21ef e022 c000

[14:41:42.907] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ff 8040 4812 a8a 21ef 4812 a8a 21ef e022 c000

[14:41:55.296] <TB3> INFO: 3120000 events read in total (144083ms).
[14:41:55.424] <TB3> INFO: Test took 145047ms.
[14:42:18.314] <TB3> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 168 seconds
[14:42:18.314] <TB3> INFO: number of dead bumps (per ROC): 1 0 0 2 0 2 3 1 0 0 2 1 0 0 0 0
[14:42:18.314] <TB3> INFO: separation cut (per ROC): 111 123 107 119 104 107 105 102 117 108 110 107 112 110 103 103
[14:42:18.314] <TB3> INFO: Decoding statistics:
[14:42:18.314] <TB3> INFO: General information:
[14:42:18.314] <TB3> INFO: 16bit words read: 0
[14:42:18.314] <TB3> INFO: valid events total: 0
[14:42:18.314] <TB3> INFO: empty events: 0
[14:42:18.314] <TB3> INFO: valid events with pixels: 0
[14:42:18.314] <TB3> INFO: valid pixel hits: 0
[14:42:18.314] <TB3> INFO: Event errors: 0
[14:42:18.314] <TB3> INFO: start marker: 0
[14:42:18.314] <TB3> INFO: stop marker: 0
[14:42:18.314] <TB3> INFO: overflow: 0
[14:42:18.314] <TB3> INFO: invalid 5bit words: 0
[14:42:18.314] <TB3> INFO: invalid XOR eye diagram: 0
[14:42:18.314] <TB3> INFO: frame (failed synchr.): 0
[14:42:18.314] <TB3> INFO: idle data (no TBM trl): 0
[14:42:18.314] <TB3> INFO: no data (only TBM hdr): 0
[14:42:18.314] <TB3> INFO: TBM errors: 0
[14:42:18.314] <TB3> INFO: flawed TBM headers: 0
[14:42:18.314] <TB3> INFO: flawed TBM trailers: 0
[14:42:18.314] <TB3> INFO: event ID mismatches: 0
[14:42:18.314] <TB3> INFO: ROC errors: 0
[14:42:18.314] <TB3> INFO: missing ROC header(s): 0
[14:42:18.314] <TB3> INFO: misplaced readback start: 0
[14:42:18.314] <TB3> INFO: Pixel decoding errors: 0
[14:42:18.314] <TB3> INFO: pixel data incomplete: 0
[14:42:18.314] <TB3> INFO: pixel address: 0
[14:42:18.314] <TB3> INFO: pulse height fill bit: 0
[14:42:18.314] <TB3> INFO: buffer corruption: 0
[14:42:18.356] <TB3> INFO: ######################################################################
[14:42:18.356] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:42:18.356] <TB3> INFO: ######################################################################
[14:42:18.356] <TB3> INFO: ----------------------------------------------------------------------
[14:42:18.356] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:42:18.356] <TB3> INFO: ----------------------------------------------------------------------
[14:42:18.356] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[14:42:18.374] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[14:42:18.374] <TB3> INFO: run 1 of 1
[14:42:18.647] <TB3> INFO: Expecting 36608000 events.
[14:42:42.333] <TB3> INFO: 702600 events read in total (23094ms).
[14:43:04.938] <TB3> INFO: 1385950 events read in total (45699ms).
[14:43:27.959] <TB3> INFO: 2070050 events read in total (68720ms).
[14:43:50.937] <TB3> INFO: 2750150 events read in total (91698ms).
[14:44:13.750] <TB3> INFO: 3431200 events read in total (114511ms).
[14:44:36.865] <TB3> INFO: 4111200 events read in total (137626ms).
[14:44:59.707] <TB3> INFO: 4792750 events read in total (160468ms).
[14:45:22.485] <TB3> INFO: 5470350 events read in total (183246ms).
[14:45:44.857] <TB3> INFO: 6149450 events read in total (205618ms).
[14:46:07.737] <TB3> INFO: 6828000 events read in total (228498ms).
[14:46:30.241] <TB3> INFO: 7505550 events read in total (251002ms).
[14:46:53.345] <TB3> INFO: 8184250 events read in total (274106ms).
[14:47:16.189] <TB3> INFO: 8865750 events read in total (296950ms).
[14:47:39.394] <TB3> INFO: 9546800 events read in total (320155ms).
[14:48:02.330] <TB3> INFO: 10226500 events read in total (343091ms).
[14:48:24.003] <TB3> INFO: 10906050 events read in total (365764ms).
[14:48:47.689] <TB3> INFO: 11584650 events read in total (388450ms).
[14:49:10.265] <TB3> INFO: 12263500 events read in total (411026ms).
[14:49:33.113] <TB3> INFO: 12940200 events read in total (433874ms).
[14:49:55.722] <TB3> INFO: 13614500 events read in total (456483ms).
[14:50:18.647] <TB3> INFO: 14289500 events read in total (479408ms).
[14:50:41.594] <TB3> INFO: 14965550 events read in total (502355ms).
[14:51:04.613] <TB3> INFO: 15639400 events read in total (525374ms).
[14:51:27.283] <TB3> INFO: 16313750 events read in total (548044ms).
[14:51:50.232] <TB3> INFO: 16988350 events read in total (570993ms).
[14:52:12.824] <TB3> INFO: 17662250 events read in total (593585ms).
[14:52:35.639] <TB3> INFO: 18334200 events read in total (616400ms).
[14:52:58.413] <TB3> INFO: 19006550 events read in total (639174ms).
[14:53:21.294] <TB3> INFO: 19675600 events read in total (662055ms).
[14:53:44.038] <TB3> INFO: 20345900 events read in total (684799ms).
[14:54:06.910] <TB3> INFO: 21015850 events read in total (707671ms).
[14:54:29.735] <TB3> INFO: 21687250 events read in total (730496ms).
[14:54:52.770] <TB3> INFO: 22358450 events read in total (753531ms).
[14:55:15.416] <TB3> INFO: 23029600 events read in total (776177ms).
[14:55:38.574] <TB3> INFO: 23702300 events read in total (799335ms).
[14:56:01.419] <TB3> INFO: 24372200 events read in total (822180ms).
[14:56:24.380] <TB3> INFO: 25042300 events read in total (845141ms).
[14:56:47.129] <TB3> INFO: 25711550 events read in total (867890ms).
[14:57:10.055] <TB3> INFO: 26381800 events read in total (890816ms).
[14:57:32.002] <TB3> INFO: 27051600 events read in total (913763ms).
[14:57:55.690] <TB3> INFO: 27722500 events read in total (936451ms).
[14:58:18.662] <TB3> INFO: 28390700 events read in total (959423ms).
[14:58:41.571] <TB3> INFO: 29061150 events read in total (982332ms).
[14:59:04.594] <TB3> INFO: 29727900 events read in total (1005355ms).
[14:59:27.399] <TB3> INFO: 30397300 events read in total (1028160ms).
[14:59:50.266] <TB3> INFO: 31063800 events read in total (1051027ms).
[15:00:13.248] <TB3> INFO: 31732700 events read in total (1074009ms).
[15:00:36.250] <TB3> INFO: 32400650 events read in total (1097011ms).
[15:00:59.330] <TB3> INFO: 33071450 events read in total (1120092ms).
[15:01:22.369] <TB3> INFO: 33740050 events read in total (1143130ms).
[15:01:45.184] <TB3> INFO: 34411150 events read in total (1165945ms).
[15:02:08.099] <TB3> INFO: 35077800 events read in total (1188860ms).
[15:02:31.131] <TB3> INFO: 35750200 events read in total (1211892ms).
[15:02:55.265] <TB3> INFO: 36432000 events read in total (1236026ms).
[15:03:01.784] <TB3> INFO: 36608000 events read in total (1242545ms).
[15:03:01.881] <TB3> INFO: Test took 1243506ms.
[15:03:02.356] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:04.345] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:06.436] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:08.298] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:09.715] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:11.136] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:12.686] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:14.114] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:16.149] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:17.935] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:19.339] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:20.756] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:22.663] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:24.591] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:26.136] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:28.015] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:03:30.040] <TB3> INFO: PixTestScurves::scurves() done
[15:03:30.041] <TB3> INFO: Vcal mean: 134.90 136.98 120.49 130.78 114.56 120.55 122.66 120.56 136.98 125.84 135.23 126.56 133.76 128.19 132.79 123.11
[15:03:30.041] <TB3> INFO: Vcal RMS: 7.37 6.29 6.45 5.86 5.58 5.99 6.19 5.83 5.85 5.37 6.81 6.81 6.14 5.99 8.39 5.83
[15:03:30.041] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1271 seconds
[15:03:30.041] <TB3> INFO: Decoding statistics:
[15:03:30.041] <TB3> INFO: General information:
[15:03:30.041] <TB3> INFO: 16bit words read: 0
[15:03:30.041] <TB3> INFO: valid events total: 0
[15:03:30.041] <TB3> INFO: empty events: 0
[15:03:30.041] <TB3> INFO: valid events with pixels: 0
[15:03:30.041] <TB3> INFO: valid pixel hits: 0
[15:03:30.041] <TB3> INFO: Event errors: 0
[15:03:30.041] <TB3> INFO: start marker: 0
[15:03:30.041] <TB3> INFO: stop marker: 0
[15:03:30.041] <TB3> INFO: overflow: 0
[15:03:30.041] <TB3> INFO: invalid 5bit words: 0
[15:03:30.041] <TB3> INFO: invalid XOR eye diagram: 0
[15:03:30.041] <TB3> INFO: frame (failed synchr.): 0
[15:03:30.041] <TB3> INFO: idle data (no TBM trl): 0
[15:03:30.041] <TB3> INFO: no data (only TBM hdr): 0
[15:03:30.041] <TB3> INFO: TBM errors: 0
[15:03:30.041] <TB3> INFO: flawed TBM headers: 0
[15:03:30.041] <TB3> INFO: flawed TBM trailers: 0
[15:03:30.041] <TB3> INFO: event ID mismatches: 0
[15:03:30.041] <TB3> INFO: ROC errors: 0
[15:03:30.041] <TB3> INFO: missing ROC header(s): 0
[15:03:30.041] <TB3> INFO: misplaced readback start: 0
[15:03:30.041] <TB3> INFO: Pixel decoding errors: 0
[15:03:30.041] <TB3> INFO: pixel data incomplete: 0
[15:03:30.041] <TB3> INFO: pixel address: 0
[15:03:30.041] <TB3> INFO: pulse height fill bit: 0
[15:03:30.041] <TB3> INFO: buffer corruption: 0
[15:03:30.109] <TB3> INFO: ######################################################################
[15:03:30.109] <TB3> INFO: PixTestTrim::doTest()
[15:03:30.109] <TB3> INFO: ######################################################################
[15:03:30.110] <TB3> INFO: ----------------------------------------------------------------------
[15:03:30.110] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[15:03:30.110] <TB3> INFO: ----------------------------------------------------------------------
[15:03:30.167] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[15:03:30.167] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:03:30.181] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:03:30.181] <TB3> INFO: run 1 of 1
[15:03:30.418] <TB3> INFO: Expecting 5025280 events.
[15:04:00.923] <TB3> INFO: 827648 events read in total (29902ms).
[15:04:31.113] <TB3> INFO: 1652536 events read in total (60092ms).
[15:05:00.816] <TB3> INFO: 2474488 events read in total (89795ms).
[15:05:30.519] <TB3> INFO: 3292392 events read in total (119498ms).
[15:06:00.310] <TB3> INFO: 4107048 events read in total (149290ms).
[15:06:31.960] <TB3> INFO: 4920576 events read in total (180939ms).
[15:06:36.089] <TB3> INFO: 5025280 events read in total (185068ms).
[15:06:36.136] <TB3> INFO: Test took 185955ms.
[15:06:50.382] <TB3> INFO: ROC 0 VthrComp = 131
[15:06:50.382] <TB3> INFO: ROC 1 VthrComp = 139
[15:06:50.383] <TB3> INFO: ROC 2 VthrComp = 124
[15:06:50.383] <TB3> INFO: ROC 3 VthrComp = 131
[15:06:50.383] <TB3> INFO: ROC 4 VthrComp = 117
[15:06:50.383] <TB3> INFO: ROC 5 VthrComp = 120
[15:06:50.383] <TB3> INFO: ROC 6 VthrComp = 120
[15:06:50.383] <TB3> INFO: ROC 7 VthrComp = 121
[15:06:50.384] <TB3> INFO: ROC 8 VthrComp = 131
[15:06:50.384] <TB3> INFO: ROC 9 VthrComp = 125
[15:06:50.384] <TB3> INFO: ROC 10 VthrComp = 128
[15:06:50.384] <TB3> INFO: ROC 11 VthrComp = 125
[15:06:50.384] <TB3> INFO: ROC 12 VthrComp = 134
[15:06:50.384] <TB3> INFO: ROC 13 VthrComp = 126
[15:06:50.384] <TB3> INFO: ROC 14 VthrComp = 126
[15:06:50.385] <TB3> INFO: ROC 15 VthrComp = 116
[15:06:50.623] <TB3> INFO: Expecting 41600 events.
[15:06:54.127] <TB3> INFO: 41600 events read in total (2912ms).
[15:06:54.127] <TB3> INFO: Test took 3741ms.
[15:06:54.139] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[15:06:54.139] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:06:54.153] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:06:54.153] <TB3> INFO: run 1 of 1
[15:06:54.431] <TB3> INFO: Expecting 5025280 events.
[15:07:20.586] <TB3> INFO: 593312 events read in total (25563ms).
[15:07:46.302] <TB3> INFO: 1184832 events read in total (51279ms).
[15:08:12.036] <TB3> INFO: 1777480 events read in total (77013ms).
[15:08:37.770] <TB3> INFO: 2368256 events read in total (102747ms).
[15:09:03.709] <TB3> INFO: 2956872 events read in total (128686ms).
[15:09:29.708] <TB3> INFO: 3544832 events read in total (154685ms).
[15:09:55.198] <TB3> INFO: 4131800 events read in total (180175ms).
[15:10:20.629] <TB3> INFO: 4717632 events read in total (205606ms).
[15:10:35.132] <TB3> INFO: 5025280 events read in total (220109ms).
[15:10:35.221] <TB3> INFO: Test took 221068ms.
[15:11:00.706] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 63.8439 for pixel 20/7 mean/min/max = 48.0474/32.2298/63.865
[15:11:00.706] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 67.2546 for pixel 14/6 mean/min/max = 51.7135/35.9799/67.4471
[15:11:00.707] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 60.3316 for pixel 15/75 mean/min/max = 46.4778/32.5304/60.4252
[15:11:00.707] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 63.6769 for pixel 14/2 mean/min/max = 48.4701/33.1223/63.818
[15:11:00.708] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 60.3573 for pixel 34/0 mean/min/max = 46.2861/32.2138/60.3583
[15:11:00.708] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 60.013 for pixel 35/0 mean/min/max = 46.7493/33.4773/60.0213
[15:11:00.709] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 64.0372 for pixel 19/4 mean/min/max = 48.2846/32.3637/64.2055
[15:11:00.709] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 60.6771 for pixel 13/2 mean/min/max = 46.5074/32.2935/60.7213
[15:11:00.710] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 63.7248 for pixel 0/1 mean/min/max = 48.6221/33.4302/63.814
[15:11:00.710] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 62.3518 for pixel 33/11 mean/min/max = 47.8534/33.3191/62.3878
[15:11:00.711] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 63.6857 for pixel 1/11 mean/min/max = 47.6243/31.5539/63.6948
[15:11:00.711] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 63.2276 for pixel 0/14 mean/min/max = 47.6946/31.9988/63.3903
[15:11:00.712] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 61.5593 for pixel 26/66 mean/min/max = 47.0503/32.5034/61.5972
[15:11:00.712] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 61.6475 for pixel 0/4 mean/min/max = 46.5117/31.3455/61.6779
[15:11:00.713] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 69.0305 for pixel 18/2 mean/min/max = 49.6591/30.2852/69.033
[15:11:00.713] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 63.7544 for pixel 0/18 mean/min/max = 48.2076/32.6232/63.7919
[15:11:00.714] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:11:00.802] <TB3> INFO: Expecting 411648 events.
[15:11:10.396] <TB3> INFO: 411648 events read in total (9002ms).
[15:11:10.404] <TB3> INFO: Expecting 411648 events.
[15:11:19.783] <TB3> INFO: 411648 events read in total (8976ms).
[15:11:19.798] <TB3> INFO: Expecting 411648 events.
[15:11:29.213] <TB3> INFO: 411648 events read in total (9012ms).
[15:11:29.226] <TB3> INFO: Expecting 411648 events.
[15:11:38.660] <TB3> INFO: 411648 events read in total (9031ms).
[15:11:38.679] <TB3> INFO: Expecting 411648 events.
[15:11:48.085] <TB3> INFO: 411648 events read in total (9003ms).
[15:11:48.106] <TB3> INFO: Expecting 411648 events.
[15:11:57.524] <TB3> INFO: 411648 events read in total (9015ms).
[15:11:57.555] <TB3> INFO: Expecting 411648 events.
[15:12:06.900] <TB3> INFO: 411648 events read in total (8942ms).
[15:12:06.927] <TB3> INFO: Expecting 411648 events.
[15:12:16.295] <TB3> INFO: 411648 events read in total (8965ms).
[15:12:16.326] <TB3> INFO: Expecting 411648 events.
[15:12:25.716] <TB3> INFO: 411648 events read in total (8987ms).
[15:12:25.748] <TB3> INFO: Expecting 411648 events.
[15:12:35.197] <TB3> INFO: 411648 events read in total (9046ms).
[15:12:35.243] <TB3> INFO: Expecting 411648 events.
[15:12:44.562] <TB3> INFO: 411648 events read in total (8916ms).
[15:12:44.597] <TB3> INFO: Expecting 411648 events.
[15:12:53.904] <TB3> INFO: 411648 events read in total (8904ms).
[15:12:53.945] <TB3> INFO: Expecting 411648 events.
[15:13:03.433] <TB3> INFO: 411648 events read in total (9085ms).
[15:13:03.473] <TB3> INFO: Expecting 411648 events.
[15:13:12.827] <TB3> INFO: 411648 events read in total (8952ms).
[15:13:12.871] <TB3> INFO: Expecting 411648 events.
[15:13:22.474] <TB3> INFO: 411648 events read in total (9201ms).
[15:13:22.518] <TB3> INFO: Expecting 411648 events.
[15:13:31.654] <TB3> INFO: 411648 events read in total (8733ms).
[15:13:31.715] <TB3> INFO: Test took 151001ms.
[15:13:32.429] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[15:13:32.442] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:13:32.442] <TB3> INFO: run 1 of 1
[15:13:32.696] <TB3> INFO: Expecting 5025280 events.
[15:13:59.072] <TB3> INFO: 590360 events read in total (25784ms).
[15:14:24.886] <TB3> INFO: 1178608 events read in total (51599ms).
[15:14:51.507] <TB3> INFO: 1765864 events read in total (78219ms).
[15:15:18.753] <TB3> INFO: 2354632 events read in total (105465ms).
[15:15:45.398] <TB3> INFO: 2942752 events read in total (132111ms).
[15:16:12.540] <TB3> INFO: 3530704 events read in total (159252ms).
[15:16:38.712] <TB3> INFO: 4119664 events read in total (185424ms).
[15:17:04.513] <TB3> INFO: 4709160 events read in total (211225ms).
[15:17:19.516] <TB3> INFO: 5025280 events read in total (226228ms).
[15:17:19.708] <TB3> INFO: Test took 227266ms.
[15:17:42.123] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 8.054142 .. 145.699789
[15:17:42.365] <TB3> INFO: Expecting 208000 events.
[15:17:51.956] <TB3> INFO: 208000 events read in total (8999ms).
[15:17:51.957] <TB3> INFO: Test took 9833ms.
[15:17:52.017] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 8 .. 155 (-1/-1) hits flags = 528 (plus default)
[15:17:52.031] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:17:52.031] <TB3> INFO: run 1 of 1
[15:17:52.310] <TB3> INFO: Expecting 4925440 events.
[15:18:18.191] <TB3> INFO: 576144 events read in total (25289ms).
[15:18:43.867] <TB3> INFO: 1152112 events read in total (50966ms).
[15:19:09.361] <TB3> INFO: 1727728 events read in total (76459ms).
[15:19:35.205] <TB3> INFO: 2303552 events read in total (102303ms).
[15:20:01.391] <TB3> INFO: 2879288 events read in total (128490ms).
[15:20:26.970] <TB3> INFO: 3454720 events read in total (154068ms).
[15:20:53.032] <TB3> INFO: 4029584 events read in total (180130ms).
[15:21:19.096] <TB3> INFO: 4604072 events read in total (206194ms).
[15:21:34.477] <TB3> INFO: 4925440 events read in total (221575ms).
[15:21:34.641] <TB3> INFO: Test took 222611ms.
[15:22:05.628] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 26.436161 .. 47.344217
[15:22:05.866] <TB3> INFO: Expecting 208000 events.
[15:22:15.642] <TB3> INFO: 208000 events read in total (9185ms).
[15:22:15.643] <TB3> INFO: Test took 10013ms.
[15:22:15.692] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 57 (-1/-1) hits flags = 528 (plus default)
[15:22:15.704] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:22:15.704] <TB3> INFO: run 1 of 1
[15:22:15.983] <TB3> INFO: Expecting 1397760 events.
[15:22:44.487] <TB3> INFO: 658336 events read in total (27912ms).
[15:23:12.411] <TB3> INFO: 1315088 events read in total (55837ms).
[15:23:16.402] <TB3> INFO: 1397760 events read in total (59828ms).
[15:23:16.450] <TB3> INFO: Test took 60746ms.
[15:23:31.602] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 28.939834 .. 49.417419
[15:23:31.846] <TB3> INFO: Expecting 208000 events.
[15:23:41.684] <TB3> INFO: 208000 events read in total (9246ms).
[15:23:41.686] <TB3> INFO: Test took 10083ms.
[15:23:41.739] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 18 .. 59 (-1/-1) hits flags = 528 (plus default)
[15:23:41.753] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:23:41.753] <TB3> INFO: run 1 of 1
[15:23:42.032] <TB3> INFO: Expecting 1397760 events.
[15:24:10.419] <TB3> INFO: 642696 events read in total (27795ms).
[15:24:38.246] <TB3> INFO: 1284320 events read in total (55623ms).
[15:24:43.638] <TB3> INFO: 1397760 events read in total (61014ms).
[15:24:43.685] <TB3> INFO: Test took 61931ms.
[15:24:59.331] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 26.133980 .. 56.925974
[15:24:59.575] <TB3> INFO: Expecting 208000 events.
[15:25:09.296] <TB3> INFO: 208000 events read in total (9130ms).
[15:25:09.297] <TB3> INFO: Test took 9964ms.
[15:25:09.343] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 16 .. 66 (-1/-1) hits flags = 528 (plus default)
[15:25:09.357] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:25:09.357] <TB3> INFO: run 1 of 1
[15:25:09.635] <TB3> INFO: Expecting 1697280 events.
[15:25:37.234] <TB3> INFO: 630632 events read in total (27007ms).
[15:26:04.394] <TB3> INFO: 1261112 events read in total (54167ms).
[15:26:24.241] <TB3> INFO: 1697280 events read in total (74014ms).
[15:26:24.293] <TB3> INFO: Test took 74937ms.
[15:26:41.687] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[15:26:41.687] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[15:26:41.701] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:26:41.701] <TB3> INFO: run 1 of 1
[15:26:41.982] <TB3> INFO: Expecting 1364480 events.
[15:27:10.518] <TB3> INFO: 668808 events read in total (27945ms).
[15:27:39.137] <TB3> INFO: 1336792 events read in total (56564ms).
[15:27:40.852] <TB3> INFO: 1364480 events read in total (58280ms).
[15:27:40.885] <TB3> INFO: Test took 59184ms.
[15:27:55.280] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C0.dat
[15:27:55.280] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C1.dat
[15:27:55.280] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C2.dat
[15:27:55.280] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C3.dat
[15:27:55.281] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C4.dat
[15:27:55.281] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C5.dat
[15:27:55.281] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C6.dat
[15:27:55.281] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C7.dat
[15:27:55.281] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C8.dat
[15:27:55.281] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C9.dat
[15:27:55.281] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C10.dat
[15:27:55.282] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C11.dat
[15:27:55.282] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C12.dat
[15:27:55.282] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C13.dat
[15:27:55.282] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C14.dat
[15:27:55.282] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C15.dat
[15:27:55.282] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C0.dat
[15:27:55.292] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C1.dat
[15:27:55.297] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C2.dat
[15:27:55.302] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C3.dat
[15:27:55.307] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C4.dat
[15:27:55.312] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C5.dat
[15:27:55.316] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C6.dat
[15:27:55.322] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C7.dat
[15:27:55.327] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C8.dat
[15:27:55.333] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C9.dat
[15:27:55.340] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C10.dat
[15:27:55.346] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C11.dat
[15:27:55.353] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C12.dat
[15:27:55.359] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C13.dat
[15:27:55.365] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C14.dat
[15:27:55.371] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C15.dat
[15:27:55.376] <TB3> INFO: PixTestTrim::trimTest() done
[15:27:55.376] <TB3> INFO: vtrim: 132 155 116 135 132 122 147 133 131 140 120 103 125 114 137 124
[15:27:55.376] <TB3> INFO: vthrcomp: 131 139 124 131 117 120 120 121 131 125 128 125 134 126 126 116
[15:27:55.376] <TB3> INFO: vcal mean: 35.15 35.78 34.97 35.17 34.91 35.01 35.20 34.96 35.15 35.17 35.36 35.37 34.97 34.99 35.91 35.14
[15:27:55.376] <TB3> INFO: vcal RMS: 1.50 1.99 1.06 1.27 1.07 1.02 1.40 1.12 1.28 1.25 1.65 1.56 1.10 1.16 2.39 1.28
[15:27:55.376] <TB3> INFO: bits mean: 9.07 8.40 9.14 9.21 9.68 9.23 9.59 9.58 8.78 9.26 9.30 8.66 9.29 8.94 10.14 8.97
[15:27:55.376] <TB3> INFO: bits RMS: 2.78 2.52 2.80 2.61 2.58 2.57 2.55 2.60 2.73 2.59 2.83 3.12 2.67 3.02 2.51 2.81
[15:27:55.383] <TB3> INFO: ----------------------------------------------------------------------
[15:27:55.383] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[15:27:55.383] <TB3> INFO: ----------------------------------------------------------------------
[15:27:55.386] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[15:27:55.398] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[15:27:55.398] <TB3> INFO: run 1 of 1
[15:27:55.637] <TB3> INFO: Expecting 4160000 events.
[15:28:28.412] <TB3> INFO: 770685 events read in total (32184ms).
[15:29:00.516] <TB3> INFO: 1534390 events read in total (64288ms).
[15:29:32.492] <TB3> INFO: 2290320 events read in total (96265ms).
[15:30:04.265] <TB3> INFO: 3043200 events read in total (128037ms).
[15:30:36.105] <TB3> INFO: 3793705 events read in total (159877ms).
[15:30:52.305] <TB3> INFO: 4160000 events read in total (176077ms).
[15:30:52.441] <TB3> INFO: Test took 177043ms.
[15:31:18.180] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[15:31:18.194] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[15:31:18.194] <TB3> INFO: run 1 of 1
[15:31:18.438] <TB3> INFO: Expecting 5324800 events.
[15:31:49.445] <TB3> INFO: 685415 events read in total (30415ms).
[15:32:19.881] <TB3> INFO: 1366570 events read in total (60851ms).
[15:32:50.078] <TB3> INFO: 2046240 events read in total (91048ms).
[15:33:20.445] <TB3> INFO: 2723140 events read in total (121415ms).
[15:33:50.505] <TB3> INFO: 3397855 events read in total (151475ms).
[15:34:20.455] <TB3> INFO: 4071465 events read in total (181425ms).
[15:34:50.663] <TB3> INFO: 4744245 events read in total (211633ms).
[15:35:16.339] <TB3> INFO: 5324800 events read in total (237309ms).
[15:35:16.447] <TB3> INFO: Test took 238253ms.
[15:35:44.835] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 222 (-1/-1) hits flags = 528 (plus default)
[15:35:44.850] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[15:35:44.850] <TB3> INFO: run 1 of 1
[15:35:45.087] <TB3> INFO: Expecting 4638400 events.
[15:36:16.707] <TB3> INFO: 715650 events read in total (31028ms).
[15:36:47.536] <TB3> INFO: 1426650 events read in total (61857ms).
[15:37:18.322] <TB3> INFO: 2134130 events read in total (92643ms).
[15:37:48.910] <TB3> INFO: 2837595 events read in total (123231ms).
[15:38:19.570] <TB3> INFO: 3539980 events read in total (153891ms).
[15:38:50.735] <TB3> INFO: 4240890 events read in total (185056ms).
[15:39:08.047] <TB3> INFO: 4638400 events read in total (202368ms).
[15:39:08.137] <TB3> INFO: Test took 203287ms.
[15:39:34.764] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 223 (-1/-1) hits flags = 528 (plus default)
[15:39:34.777] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[15:39:34.777] <TB3> INFO: run 1 of 1
[15:39:35.045] <TB3> INFO: Expecting 4659200 events.
[15:40:06.636] <TB3> INFO: 714705 events read in total (30999ms).
[15:40:37.868] <TB3> INFO: 1424845 events read in total (62231ms).
[15:41:08.855] <TB3> INFO: 2131330 events read in total (93218ms).
[15:41:39.828] <TB3> INFO: 2834110 events read in total (124191ms).
[15:42:10.189] <TB3> INFO: 3535720 events read in total (154552ms).
[15:42:40.679] <TB3> INFO: 4235685 events read in total (185042ms).
[15:42:59.011] <TB3> INFO: 4659200 events read in total (203374ms).
[15:42:59.099] <TB3> INFO: Test took 204321ms.
[15:43:25.812] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 220 (-1/-1) hits flags = 528 (plus default)
[15:43:25.825] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[15:43:25.825] <TB3> INFO: run 1 of 1
[15:43:26.064] <TB3> INFO: Expecting 4596800 events.
[15:43:57.635] <TB3> INFO: 718235 events read in total (30979ms).
[15:44:28.371] <TB3> INFO: 1431780 events read in total (61715ms).
[15:44:59.064] <TB3> INFO: 2141445 events read in total (92409ms).
[15:45:29.771] <TB3> INFO: 2847125 events read in total (123115ms).
[15:46:00.550] <TB3> INFO: 3551405 events read in total (153894ms).
[15:46:31.645] <TB3> INFO: 4254760 events read in total (184989ms).
[15:46:46.926] <TB3> INFO: 4596800 events read in total (200270ms).
[15:46:47.008] <TB3> INFO: Test took 201183ms.
[15:47:13.491] <TB3> INFO: PixTestTrim::trimBitTest() done
[15:47:13.493] <TB3> INFO: PixTestTrim::doTest() done, duration: 2623 seconds
[15:47:13.493] <TB3> INFO: Decoding statistics:
[15:47:13.493] <TB3> INFO: General information:
[15:47:13.493] <TB3> INFO: 16bit words read: 0
[15:47:13.493] <TB3> INFO: valid events total: 0
[15:47:13.493] <TB3> INFO: empty events: 0
[15:47:13.493] <TB3> INFO: valid events with pixels: 0
[15:47:13.493] <TB3> INFO: valid pixel hits: 0
[15:47:13.493] <TB3> INFO: Event errors: 0
[15:47:13.493] <TB3> INFO: start marker: 0
[15:47:13.493] <TB3> INFO: stop marker: 0
[15:47:13.493] <TB3> INFO: overflow: 0
[15:47:13.493] <TB3> INFO: invalid 5bit words: 0
[15:47:13.493] <TB3> INFO: invalid XOR eye diagram: 0
[15:47:13.493] <TB3> INFO: frame (failed synchr.): 0
[15:47:13.493] <TB3> INFO: idle data (no TBM trl): 0
[15:47:13.493] <TB3> INFO: no data (only TBM hdr): 0
[15:47:13.493] <TB3> INFO: TBM errors: 0
[15:47:13.493] <TB3> INFO: flawed TBM headers: 0
[15:47:13.493] <TB3> INFO: flawed TBM trailers: 0
[15:47:13.493] <TB3> INFO: event ID mismatches: 0
[15:47:13.493] <TB3> INFO: ROC errors: 0
[15:47:13.493] <TB3> INFO: missing ROC header(s): 0
[15:47:13.493] <TB3> INFO: misplaced readback start: 0
[15:47:13.493] <TB3> INFO: Pixel decoding errors: 0
[15:47:13.493] <TB3> INFO: pixel data incomplete: 0
[15:47:13.493] <TB3> INFO: pixel address: 0
[15:47:13.493] <TB3> INFO: pulse height fill bit: 0
[15:47:13.493] <TB3> INFO: buffer corruption: 0
[15:47:14.088] <TB3> INFO: ######################################################################
[15:47:14.088] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[15:47:14.088] <TB3> INFO: ######################################################################
[15:47:14.342] <TB3> INFO: Expecting 41600 events.
[15:47:17.862] <TB3> INFO: 41600 events read in total (2928ms).
[15:47:17.862] <TB3> INFO: Test took 3773ms.
[15:47:18.308] <TB3> INFO: Expecting 41600 events.
[15:47:21.903] <TB3> INFO: 41600 events read in total (3003ms).
[15:47:21.905] <TB3> INFO: Test took 3839ms.
[15:47:22.196] <TB3> INFO: Expecting 41600 events.
[15:47:25.730] <TB3> INFO: 41600 events read in total (2943ms).
[15:47:25.731] <TB3> INFO: Test took 3802ms.
[15:47:26.020] <TB3> INFO: Expecting 41600 events.
[15:47:29.614] <TB3> INFO: 41600 events read in total (3002ms).
[15:47:29.616] <TB3> INFO: Test took 3861ms.
[15:47:29.906] <TB3> INFO: Expecting 41600 events.
[15:47:33.454] <TB3> INFO: 41600 events read in total (2956ms).
[15:47:33.455] <TB3> INFO: Test took 3814ms.
[15:47:33.744] <TB3> INFO: Expecting 41600 events.
[15:47:37.342] <TB3> INFO: 41600 events read in total (3006ms).
[15:47:37.343] <TB3> INFO: Test took 3864ms.
[15:47:37.633] <TB3> INFO: Expecting 41600 events.
[15:47:41.186] <TB3> INFO: 41600 events read in total (2961ms).
[15:47:41.187] <TB3> INFO: Test took 3819ms.
[15:47:41.478] <TB3> INFO: Expecting 41600 events.
[15:47:45.052] <TB3> INFO: 41600 events read in total (2983ms).
[15:47:45.053] <TB3> INFO: Test took 3842ms.
[15:47:45.343] <TB3> INFO: Expecting 41600 events.
[15:47:49.077] <TB3> INFO: 41600 events read in total (3143ms).
[15:47:49.078] <TB3> INFO: Test took 4001ms.
[15:47:49.367] <TB3> INFO: Expecting 41600 events.
[15:47:52.902] <TB3> INFO: 41600 events read in total (2943ms).
[15:47:52.903] <TB3> INFO: Test took 3801ms.
[15:47:53.192] <TB3> INFO: Expecting 41600 events.
[15:47:56.720] <TB3> INFO: 41600 events read in total (2936ms).
[15:47:56.721] <TB3> INFO: Test took 3794ms.
[15:47:57.010] <TB3> INFO: Expecting 41600 events.
[15:48:00.525] <TB3> INFO: 41600 events read in total (2924ms).
[15:48:00.526] <TB3> INFO: Test took 3781ms.
[15:48:00.815] <TB3> INFO: Expecting 41600 events.
[15:48:04.426] <TB3> INFO: 41600 events read in total (3019ms).
[15:48:04.427] <TB3> INFO: Test took 3877ms.
[15:48:04.718] <TB3> INFO: Expecting 41600 events.
[15:48:08.248] <TB3> INFO: 41600 events read in total (2938ms).
[15:48:08.249] <TB3> INFO: Test took 3797ms.
[15:48:08.540] <TB3> INFO: Expecting 41600 events.
[15:48:12.112] <TB3> INFO: 41600 events read in total (2981ms).
[15:48:12.113] <TB3> INFO: Test took 3839ms.
[15:48:12.426] <TB3> INFO: Expecting 41600 events.
[15:48:15.980] <TB3> INFO: 41600 events read in total (2962ms).
[15:48:15.981] <TB3> INFO: Test took 3843ms.
[15:48:16.271] <TB3> INFO: Expecting 41600 events.
[15:48:19.906] <TB3> INFO: 41600 events read in total (3043ms).
[15:48:19.907] <TB3> INFO: Test took 3902ms.
[15:48:20.197] <TB3> INFO: Expecting 41600 events.
[15:48:23.739] <TB3> INFO: 41600 events read in total (2950ms).
[15:48:23.740] <TB3> INFO: Test took 3808ms.
[15:48:24.048] <TB3> INFO: Expecting 41600 events.
[15:48:27.665] <TB3> INFO: 41600 events read in total (3025ms).
[15:48:27.666] <TB3> INFO: Test took 3902ms.
[15:48:27.957] <TB3> INFO: Expecting 41600 events.
[15:48:31.450] <TB3> INFO: 41600 events read in total (2901ms).
[15:48:31.451] <TB3> INFO: Test took 3761ms.
[15:48:31.741] <TB3> INFO: Expecting 41600 events.
[15:48:35.417] <TB3> INFO: 41600 events read in total (3084ms).
[15:48:35.419] <TB3> INFO: Test took 3943ms.
[15:48:35.756] <TB3> INFO: Expecting 41600 events.
[15:48:39.297] <TB3> INFO: 41600 events read in total (2949ms).
[15:48:39.298] <TB3> INFO: Test took 3850ms.
[15:48:39.590] <TB3> INFO: Expecting 41600 events.
[15:48:43.139] <TB3> INFO: 41600 events read in total (2958ms).
[15:48:43.140] <TB3> INFO: Test took 3816ms.
[15:48:43.433] <TB3> INFO: Expecting 41600 events.
[15:48:46.961] <TB3> INFO: 41600 events read in total (2936ms).
[15:48:46.962] <TB3> INFO: Test took 3797ms.
[15:48:47.254] <TB3> INFO: Expecting 41600 events.
[15:48:50.817] <TB3> INFO: 41600 events read in total (2971ms).
[15:48:50.818] <TB3> INFO: Test took 3829ms.
[15:48:51.124] <TB3> INFO: Expecting 41600 events.
[15:48:54.654] <TB3> INFO: 41600 events read in total (2938ms).
[15:48:54.655] <TB3> INFO: Test took 3807ms.
[15:48:54.949] <TB3> INFO: Expecting 2560 events.
[15:48:55.842] <TB3> INFO: 2560 events read in total (301ms).
[15:48:55.842] <TB3> INFO: Test took 1171ms.
[15:48:56.151] <TB3> INFO: Expecting 2560 events.
[15:48:57.042] <TB3> INFO: 2560 events read in total (300ms).
[15:48:57.042] <TB3> INFO: Test took 1199ms.
[15:48:57.349] <TB3> INFO: Expecting 2560 events.
[15:48:58.235] <TB3> INFO: 2560 events read in total (294ms).
[15:48:58.235] <TB3> INFO: Test took 1192ms.
[15:48:58.543] <TB3> INFO: Expecting 2560 events.
[15:48:59.434] <TB3> INFO: 2560 events read in total (300ms).
[15:48:59.435] <TB3> INFO: Test took 1199ms.
[15:48:59.747] <TB3> INFO: Expecting 2560 events.
[15:49:00.632] <TB3> INFO: 2560 events read in total (293ms).
[15:49:00.632] <TB3> INFO: Test took 1197ms.
[15:49:00.940] <TB3> INFO: Expecting 2560 events.
[15:49:01.826] <TB3> INFO: 2560 events read in total (295ms).
[15:49:01.826] <TB3> INFO: Test took 1194ms.
[15:49:02.135] <TB3> INFO: Expecting 2560 events.
[15:49:03.026] <TB3> INFO: 2560 events read in total (300ms).
[15:49:03.026] <TB3> INFO: Test took 1199ms.
[15:49:03.334] <TB3> INFO: Expecting 2560 events.
[15:49:04.213] <TB3> INFO: 2560 events read in total (287ms).
[15:49:04.213] <TB3> INFO: Test took 1187ms.
[15:49:04.522] <TB3> INFO: Expecting 2560 events.
[15:49:05.402] <TB3> INFO: 2560 events read in total (289ms).
[15:49:05.402] <TB3> INFO: Test took 1188ms.
[15:49:05.710] <TB3> INFO: Expecting 2560 events.
[15:49:06.598] <TB3> INFO: 2560 events read in total (296ms).
[15:49:06.598] <TB3> INFO: Test took 1195ms.
[15:49:06.905] <TB3> INFO: Expecting 2560 events.
[15:49:07.786] <TB3> INFO: 2560 events read in total (289ms).
[15:49:07.786] <TB3> INFO: Test took 1187ms.
[15:49:08.094] <TB3> INFO: Expecting 2560 events.
[15:49:08.975] <TB3> INFO: 2560 events read in total (290ms).
[15:49:08.975] <TB3> INFO: Test took 1187ms.
[15:49:09.283] <TB3> INFO: Expecting 2560 events.
[15:49:10.177] <TB3> INFO: 2560 events read in total (302ms).
[15:49:10.177] <TB3> INFO: Test took 1201ms.
[15:49:10.485] <TB3> INFO: Expecting 2560 events.
[15:49:11.371] <TB3> INFO: 2560 events read in total (294ms).
[15:49:11.371] <TB3> INFO: Test took 1193ms.
[15:49:11.679] <TB3> INFO: Expecting 2560 events.
[15:49:12.565] <TB3> INFO: 2560 events read in total (295ms).
[15:49:12.565] <TB3> INFO: Test took 1193ms.
[15:49:12.874] <TB3> INFO: Expecting 2560 events.
[15:49:13.758] <TB3> INFO: 2560 events read in total (292ms).
[15:49:13.758] <TB3> INFO: Test took 1193ms.
[15:49:13.762] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:49:14.067] <TB3> INFO: Expecting 655360 events.
[15:49:28.851] <TB3> INFO: 655360 events read in total (14192ms).
[15:49:28.863] <TB3> INFO: Expecting 655360 events.
[15:49:43.445] <TB3> INFO: 655360 events read in total (14178ms).
[15:49:43.461] <TB3> INFO: Expecting 655360 events.
[15:49:57.958] <TB3> INFO: 655360 events read in total (14094ms).
[15:49:57.983] <TB3> INFO: Expecting 655360 events.
[15:50:12.482] <TB3> INFO: 655360 events read in total (14092ms).
[15:50:12.510] <TB3> INFO: Expecting 655360 events.
[15:50:27.029] <TB3> INFO: 655360 events read in total (14116ms).
[15:50:27.059] <TB3> INFO: Expecting 655360 events.
[15:50:41.691] <TB3> INFO: 655360 events read in total (14229ms).
[15:50:41.726] <TB3> INFO: Expecting 655360 events.
[15:50:56.227] <TB3> INFO: 655360 events read in total (14098ms).
[15:50:56.276] <TB3> INFO: Expecting 655360 events.
[15:51:10.923] <TB3> INFO: 655360 events read in total (14244ms).
[15:51:10.978] <TB3> INFO: Expecting 655360 events.
[15:51:25.473] <TB3> INFO: 655360 events read in total (14092ms).
[15:51:25.520] <TB3> INFO: Expecting 655360 events.
[15:51:39.963] <TB3> INFO: 655360 events read in total (14039ms).
[15:51:40.017] <TB3> INFO: Expecting 655360 events.
[15:51:54.515] <TB3> INFO: 655360 events read in total (14095ms).
[15:51:54.584] <TB3> INFO: Expecting 655360 events.
[15:52:09.151] <TB3> INFO: 655360 events read in total (14163ms).
[15:52:09.241] <TB3> INFO: Expecting 655360 events.
[15:52:23.869] <TB3> INFO: 655360 events read in total (14225ms).
[15:52:23.948] <TB3> INFO: Expecting 655360 events.
[15:52:38.643] <TB3> INFO: 655360 events read in total (14292ms).
[15:52:38.742] <TB3> INFO: Expecting 655360 events.
[15:52:53.289] <TB3> INFO: 655360 events read in total (14144ms).
[15:52:53.381] <TB3> INFO: Expecting 655360 events.
[15:53:07.896] <TB3> INFO: 655360 events read in total (14112ms).
[15:53:08.028] <TB3> INFO: Test took 234266ms.
[15:53:08.123] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:53:08.381] <TB3> INFO: Expecting 655360 events.
[15:53:22.941] <TB3> INFO: 655360 events read in total (13969ms).
[15:53:22.957] <TB3> INFO: Expecting 655360 events.
[15:53:37.220] <TB3> INFO: 655360 events read in total (13860ms).
[15:53:37.240] <TB3> INFO: Expecting 655360 events.
[15:53:51.609] <TB3> INFO: 655360 events read in total (13966ms).
[15:53:51.633] <TB3> INFO: Expecting 655360 events.
[15:54:06.080] <TB3> INFO: 655360 events read in total (14045ms).
[15:54:06.106] <TB3> INFO: Expecting 655360 events.
[15:54:20.283] <TB3> INFO: 655360 events read in total (13774ms).
[15:54:20.314] <TB3> INFO: Expecting 655360 events.
[15:54:34.689] <TB3> INFO: 655360 events read in total (13972ms).
[15:54:34.723] <TB3> INFO: Expecting 655360 events.
[15:54:49.089] <TB3> INFO: 655360 events read in total (13962ms).
[15:54:49.127] <TB3> INFO: Expecting 655360 events.
[15:55:03.304] <TB3> INFO: 655360 events read in total (13774ms).
[15:55:03.347] <TB3> INFO: Expecting 655360 events.
[15:55:17.793] <TB3> INFO: 655360 events read in total (14042ms).
[15:55:17.839] <TB3> INFO: Expecting 655360 events.
[15:55:32.310] <TB3> INFO: 655360 events read in total (14067ms).
[15:55:32.361] <TB3> INFO: Expecting 655360 events.
[15:55:46.911] <TB3> INFO: 655360 events read in total (14147ms).
[15:55:46.978] <TB3> INFO: Expecting 655360 events.
[15:56:01.513] <TB3> INFO: 655360 events read in total (14132ms).
[15:56:01.588] <TB3> INFO: Expecting 655360 events.
[15:56:15.958] <TB3> INFO: 655360 events read in total (13967ms).
[15:56:16.041] <TB3> INFO: Expecting 655360 events.
[15:56:30.710] <TB3> INFO: 655360 events read in total (14267ms).
[15:56:30.796] <TB3> INFO: Expecting 655360 events.
[15:56:45.770] <TB3> INFO: 655360 events read in total (14571ms).
[15:56:45.863] <TB3> INFO: Expecting 655360 events.
[15:57:00.874] <TB3> INFO: 655360 events read in total (14608ms).
[15:57:00.974] <TB3> INFO: Test took 232851ms.
[15:57:01.145] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.151] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[15:57:01.157] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[15:57:01.163] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.169] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.175] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[15:57:01.180] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[15:57:01.186] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[15:57:01.192] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[15:57:01.197] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[15:57:01.203] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.209] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.217] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.225] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.233] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.242] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.250] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[15:57:01.258] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[15:57:01.265] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.274] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[15:57:01.282] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[15:57:01.290] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[15:57:01.297] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[15:57:01.303] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[15:57:01.308] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.314] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.319] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[15:57:01.325] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[15:57:01.331] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[15:57:01.336] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[15:57:01.341] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[15:57:01.347] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[15:57:01.352] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.358] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[15:57:01.364] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.369] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[15:57:01.375] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.380] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[15:57:01.417] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C0.dat
[15:57:01.417] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C1.dat
[15:57:01.417] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C2.dat
[15:57:01.417] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C3.dat
[15:57:01.418] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C4.dat
[15:57:01.418] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C5.dat
[15:57:01.418] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C6.dat
[15:57:01.418] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C7.dat
[15:57:01.418] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C8.dat
[15:57:01.419] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C9.dat
[15:57:01.419] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C10.dat
[15:57:01.419] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C11.dat
[15:57:01.419] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C12.dat
[15:57:01.420] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C13.dat
[15:57:01.420] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C14.dat
[15:57:01.420] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C15.dat
[15:57:01.667] <TB3> INFO: Expecting 41600 events.
[15:57:04.905] <TB3> INFO: 41600 events read in total (2647ms).
[15:57:04.906] <TB3> INFO: Test took 3482ms.
[15:57:05.367] <TB3> INFO: Expecting 41600 events.
[15:57:08.419] <TB3> INFO: 41600 events read in total (2460ms).
[15:57:08.420] <TB3> INFO: Test took 3297ms.
[15:57:08.878] <TB3> INFO: Expecting 41600 events.
[15:57:12.057] <TB3> INFO: 41600 events read in total (2587ms).
[15:57:12.058] <TB3> INFO: Test took 3424ms.
[15:57:12.277] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:12.367] <TB3> INFO: Expecting 2560 events.
[15:57:13.260] <TB3> INFO: 2560 events read in total (301ms).
[15:57:13.260] <TB3> INFO: Test took 983ms.
[15:57:13.264] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:13.567] <TB3> INFO: Expecting 2560 events.
[15:57:14.452] <TB3> INFO: 2560 events read in total (293ms).
[15:57:14.453] <TB3> INFO: Test took 1189ms.
[15:57:14.457] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:14.760] <TB3> INFO: Expecting 2560 events.
[15:57:15.644] <TB3> INFO: 2560 events read in total (292ms).
[15:57:15.644] <TB3> INFO: Test took 1188ms.
[15:57:15.646] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:15.953] <TB3> INFO: Expecting 2560 events.
[15:57:16.850] <TB3> INFO: 2560 events read in total (305ms).
[15:57:16.850] <TB3> INFO: Test took 1204ms.
[15:57:16.854] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:17.159] <TB3> INFO: Expecting 2560 events.
[15:57:18.045] <TB3> INFO: 2560 events read in total (294ms).
[15:57:18.045] <TB3> INFO: Test took 1191ms.
[15:57:18.047] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:18.354] <TB3> INFO: Expecting 2560 events.
[15:57:19.238] <TB3> INFO: 2560 events read in total (293ms).
[15:57:19.239] <TB3> INFO: Test took 1192ms.
[15:57:19.243] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:19.547] <TB3> INFO: Expecting 2560 events.
[15:57:20.433] <TB3> INFO: 2560 events read in total (294ms).
[15:57:20.434] <TB3> INFO: Test took 1191ms.
[15:57:20.437] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:20.742] <TB3> INFO: Expecting 2560 events.
[15:57:21.637] <TB3> INFO: 2560 events read in total (304ms).
[15:57:21.639] <TB3> INFO: Test took 1202ms.
[15:57:21.643] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:21.945] <TB3> INFO: Expecting 2560 events.
[15:57:22.837] <TB3> INFO: 2560 events read in total (300ms).
[15:57:22.838] <TB3> INFO: Test took 1195ms.
[15:57:22.840] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:23.147] <TB3> INFO: Expecting 2560 events.
[15:57:24.032] <TB3> INFO: 2560 events read in total (294ms).
[15:57:24.032] <TB3> INFO: Test took 1192ms.
[15:57:24.035] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:24.341] <TB3> INFO: Expecting 2560 events.
[15:57:25.229] <TB3> INFO: 2560 events read in total (296ms).
[15:57:25.230] <TB3> INFO: Test took 1195ms.
[15:57:25.233] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:25.537] <TB3> INFO: Expecting 2560 events.
[15:57:26.427] <TB3> INFO: 2560 events read in total (298ms).
[15:57:26.428] <TB3> INFO: Test took 1195ms.
[15:57:26.430] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:26.736] <TB3> INFO: Expecting 2560 events.
[15:57:27.624] <TB3> INFO: 2560 events read in total (296ms).
[15:57:27.624] <TB3> INFO: Test took 1194ms.
[15:57:27.628] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:27.932] <TB3> INFO: Expecting 2560 events.
[15:57:28.822] <TB3> INFO: 2560 events read in total (298ms).
[15:57:28.822] <TB3> INFO: Test took 1194ms.
[15:57:28.824] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:29.131] <TB3> INFO: Expecting 2560 events.
[15:57:30.018] <TB3> INFO: 2560 events read in total (295ms).
[15:57:30.019] <TB3> INFO: Test took 1195ms.
[15:57:30.021] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:30.326] <TB3> INFO: Expecting 2560 events.
[15:57:31.215] <TB3> INFO: 2560 events read in total (298ms).
[15:57:31.216] <TB3> INFO: Test took 1195ms.
[15:57:31.219] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:31.524] <TB3> INFO: Expecting 2560 events.
[15:57:32.408] <TB3> INFO: 2560 events read in total (290ms).
[15:57:32.408] <TB3> INFO: Test took 1189ms.
[15:57:32.412] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:32.716] <TB3> INFO: Expecting 2560 events.
[15:57:33.605] <TB3> INFO: 2560 events read in total (297ms).
[15:57:33.605] <TB3> INFO: Test took 1193ms.
[15:57:33.610] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:33.914] <TB3> INFO: Expecting 2560 events.
[15:57:34.803] <TB3> INFO: 2560 events read in total (298ms).
[15:57:34.804] <TB3> INFO: Test took 1195ms.
[15:57:34.807] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:35.111] <TB3> INFO: Expecting 2560 events.
[15:57:35.999] <TB3> INFO: 2560 events read in total (296ms).
[15:57:35.000] <TB3> INFO: Test took 1194ms.
[15:57:35.002] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:36.308] <TB3> INFO: Expecting 2560 events.
[15:57:37.192] <TB3> INFO: 2560 events read in total (292ms).
[15:57:37.192] <TB3> INFO: Test took 1190ms.
[15:57:37.196] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:37.499] <TB3> INFO: Expecting 2560 events.
[15:57:38.394] <TB3> INFO: 2560 events read in total (303ms).
[15:57:38.395] <TB3> INFO: Test took 1199ms.
[15:57:38.400] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:38.703] <TB3> INFO: Expecting 2560 events.
[15:57:39.587] <TB3> INFO: 2560 events read in total (292ms).
[15:57:39.587] <TB3> INFO: Test took 1187ms.
[15:57:39.590] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:39.895] <TB3> INFO: Expecting 2560 events.
[15:57:40.781] <TB3> INFO: 2560 events read in total (294ms).
[15:57:40.782] <TB3> INFO: Test took 1192ms.
[15:57:40.785] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:41.091] <TB3> INFO: Expecting 2560 events.
[15:57:41.977] <TB3> INFO: 2560 events read in total (294ms).
[15:57:41.978] <TB3> INFO: Test took 1193ms.
[15:57:41.982] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:42.286] <TB3> INFO: Expecting 2560 events.
[15:57:43.179] <TB3> INFO: 2560 events read in total (301ms).
[15:57:43.179] <TB3> INFO: Test took 1197ms.
[15:57:43.183] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:43.487] <TB3> INFO: Expecting 2560 events.
[15:57:44.380] <TB3> INFO: 2560 events read in total (302ms).
[15:57:44.380] <TB3> INFO: Test took 1197ms.
[15:57:44.384] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:44.687] <TB3> INFO: Expecting 2560 events.
[15:57:45.582] <TB3> INFO: 2560 events read in total (303ms).
[15:57:45.582] <TB3> INFO: Test took 1198ms.
[15:57:45.585] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:45.891] <TB3> INFO: Expecting 2560 events.
[15:57:46.782] <TB3> INFO: 2560 events read in total (299ms).
[15:57:46.782] <TB3> INFO: Test took 1198ms.
[15:57:46.786] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:47.091] <TB3> INFO: Expecting 2560 events.
[15:57:47.979] <TB3> INFO: 2560 events read in total (296ms).
[15:57:47.979] <TB3> INFO: Test took 1194ms.
[15:57:47.983] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:48.290] <TB3> INFO: Expecting 2560 events.
[15:57:49.178] <TB3> INFO: 2560 events read in total (296ms).
[15:57:49.179] <TB3> INFO: Test took 1196ms.
[15:57:49.182] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:57:49.486] <TB3> INFO: Expecting 2560 events.
[15:57:50.379] <TB3> INFO: 2560 events read in total (301ms).
[15:57:50.380] <TB3> INFO: Test took 1198ms.
[15:57:50.868] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 636 seconds
[15:57:50.868] <TB3> INFO: PH scale (per ROC): 38 29 34 55 51 36 41 48 54 33 35 48 39 50 45 52
[15:57:50.868] <TB3> INFO: PH offset (per ROC): 113 96 102 127 125 95 116 122 118 97 101 130 112 125 107 124
[15:57:50.878] <TB3> INFO: Decoding statistics:
[15:57:50.878] <TB3> INFO: General information:
[15:57:50.878] <TB3> INFO: 16bit words read: 127888
[15:57:50.878] <TB3> INFO: valid events total: 20480
[15:57:50.878] <TB3> INFO: empty events: 17976
[15:57:50.878] <TB3> INFO: valid events with pixels: 2504
[15:57:50.878] <TB3> INFO: valid pixel hits: 2504
[15:57:50.878] <TB3> INFO: Event errors: 0
[15:57:50.878] <TB3> INFO: start marker: 0
[15:57:50.878] <TB3> INFO: stop marker: 0
[15:57:50.878] <TB3> INFO: overflow: 0
[15:57:50.878] <TB3> INFO: invalid 5bit words: 0
[15:57:50.878] <TB3> INFO: invalid XOR eye diagram: 0
[15:57:50.878] <TB3> INFO: frame (failed synchr.): 0
[15:57:50.878] <TB3> INFO: idle data (no TBM trl): 0
[15:57:50.878] <TB3> INFO: no data (only TBM hdr): 0
[15:57:50.878] <TB3> INFO: TBM errors: 0
[15:57:50.878] <TB3> INFO: flawed TBM headers: 0
[15:57:50.878] <TB3> INFO: flawed TBM trailers: 0
[15:57:50.878] <TB3> INFO: event ID mismatches: 0
[15:57:50.878] <TB3> INFO: ROC errors: 0
[15:57:50.878] <TB3> INFO: missing ROC header(s): 0
[15:57:50.878] <TB3> INFO: misplaced readback start: 0
[15:57:50.878] <TB3> INFO: Pixel decoding errors: 0
[15:57:50.878] <TB3> INFO: pixel data incomplete: 0
[15:57:50.878] <TB3> INFO: pixel address: 0
[15:57:50.878] <TB3> INFO: pulse height fill bit: 0
[15:57:50.878] <TB3> INFO: buffer corruption: 0
[15:57:51.045] <TB3> INFO: ######################################################################
[15:57:51.045] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[15:57:51.045] <TB3> INFO: ######################################################################
[15:57:51.059] <TB3> INFO: scanning low vcal = 10
[15:57:51.297] <TB3> INFO: Expecting 41600 events.
[15:57:54.890] <TB3> INFO: 41600 events read in total (3001ms).
[15:57:54.890] <TB3> INFO: Test took 3831ms.
[15:57:54.892] <TB3> INFO: scanning low vcal = 20
[15:57:55.189] <TB3> INFO: Expecting 41600 events.
[15:57:58.778] <TB3> INFO: 41600 events read in total (2997ms).
[15:57:58.779] <TB3> INFO: Test took 3887ms.
[15:57:58.781] <TB3> INFO: scanning low vcal = 30
[15:57:59.071] <TB3> INFO: Expecting 41600 events.
[15:58:02.753] <TB3> INFO: 41600 events read in total (3090ms).
[15:58:02.754] <TB3> INFO: Test took 3972ms.
[15:58:02.758] <TB3> INFO: scanning low vcal = 40
[15:58:03.034] <TB3> INFO: Expecting 41600 events.
[15:58:06.989] <TB3> INFO: 41600 events read in total (3362ms).
[15:58:06.991] <TB3> INFO: Test took 4233ms.
[15:58:06.994] <TB3> INFO: scanning low vcal = 50
[15:58:07.271] <TB3> INFO: Expecting 41600 events.
[15:58:11.255] <TB3> INFO: 41600 events read in total (3392ms).
[15:58:11.256] <TB3> INFO: Test took 4262ms.
[15:58:11.259] <TB3> INFO: scanning low vcal = 60
[15:58:11.536] <TB3> INFO: Expecting 41600 events.
[15:58:15.532] <TB3> INFO: 41600 events read in total (3403ms).
[15:58:15.533] <TB3> INFO: Test took 4274ms.
[15:58:15.536] <TB3> INFO: scanning low vcal = 70
[15:58:15.814] <TB3> INFO: Expecting 41600 events.
[15:58:19.803] <TB3> INFO: 41600 events read in total (3398ms).
[15:58:19.804] <TB3> INFO: Test took 4268ms.
[15:58:19.807] <TB3> INFO: scanning low vcal = 80
[15:58:20.085] <TB3> INFO: Expecting 41600 events.
[15:58:24.059] <TB3> INFO: 41600 events read in total (3383ms).
[15:58:24.060] <TB3> INFO: Test took 4252ms.
[15:58:24.063] <TB3> INFO: scanning low vcal = 90
[15:58:24.340] <TB3> INFO: Expecting 41600 events.
[15:58:28.331] <TB3> INFO: 41600 events read in total (3399ms).
[15:58:28.332] <TB3> INFO: Test took 4269ms.
[15:58:28.336] <TB3> INFO: scanning low vcal = 100
[15:58:28.612] <TB3> INFO: Expecting 41600 events.
[15:58:32.624] <TB3> INFO: 41600 events read in total (3420ms).
[15:58:32.625] <TB3> INFO: Test took 4289ms.
[15:58:32.628] <TB3> INFO: scanning low vcal = 110
[15:58:32.905] <TB3> INFO: Expecting 41600 events.
[15:58:36.895] <TB3> INFO: 41600 events read in total (3398ms).
[15:58:36.895] <TB3> INFO: Test took 4266ms.
[15:58:36.899] <TB3> INFO: scanning low vcal = 120
[15:58:37.176] <TB3> INFO: Expecting 41600 events.
[15:58:41.160] <TB3> INFO: 41600 events read in total (3392ms).
[15:58:41.161] <TB3> INFO: Test took 4262ms.
[15:58:41.165] <TB3> INFO: scanning low vcal = 130
[15:58:41.442] <TB3> INFO: Expecting 41600 events.
[15:58:45.382] <TB3> INFO: 41600 events read in total (3349ms).
[15:58:45.383] <TB3> INFO: Test took 4218ms.
[15:58:45.387] <TB3> INFO: scanning low vcal = 140
[15:58:45.663] <TB3> INFO: Expecting 41600 events.
[15:58:49.628] <TB3> INFO: 41600 events read in total (3373ms).
[15:58:49.628] <TB3> INFO: Test took 4241ms.
[15:58:49.632] <TB3> INFO: scanning low vcal = 150
[15:58:49.908] <TB3> INFO: Expecting 41600 events.
[15:58:53.868] <TB3> INFO: 41600 events read in total (3368ms).
[15:58:53.869] <TB3> INFO: Test took 4236ms.
[15:58:53.872] <TB3> INFO: scanning low vcal = 160
[15:58:54.148] <TB3> INFO: Expecting 41600 events.
[15:58:58.105] <TB3> INFO: 41600 events read in total (3365ms).
[15:58:58.106] <TB3> INFO: Test took 4233ms.
[15:58:58.109] <TB3> INFO: scanning low vcal = 170
[15:58:58.385] <TB3> INFO: Expecting 41600 events.
[15:59:02.345] <TB3> INFO: 41600 events read in total (3368ms).
[15:59:02.345] <TB3> INFO: Test took 4236ms.
[15:59:02.351] <TB3> INFO: scanning low vcal = 180
[15:59:02.625] <TB3> INFO: Expecting 41600 events.
[15:59:06.588] <TB3> INFO: 41600 events read in total (3371ms).
[15:59:06.589] <TB3> INFO: Test took 4238ms.
[15:59:06.593] <TB3> INFO: scanning low vcal = 190
[15:59:06.869] <TB3> INFO: Expecting 41600 events.
[15:59:10.863] <TB3> INFO: 41600 events read in total (3402ms).
[15:59:10.864] <TB3> INFO: Test took 4271ms.
[15:59:10.869] <TB3> INFO: scanning low vcal = 200
[15:59:11.144] <TB3> INFO: Expecting 41600 events.
[15:59:15.174] <TB3> INFO: 41600 events read in total (3438ms).
[15:59:15.175] <TB3> INFO: Test took 4306ms.
[15:59:15.178] <TB3> INFO: scanning low vcal = 210
[15:59:15.455] <TB3> INFO: Expecting 41600 events.
[15:59:19.505] <TB3> INFO: 41600 events read in total (3458ms).
[15:59:19.506] <TB3> INFO: Test took 4328ms.
[15:59:19.511] <TB3> INFO: scanning low vcal = 220
[15:59:19.794] <TB3> INFO: Expecting 41600 events.
[15:59:23.764] <TB3> INFO: 41600 events read in total (3378ms).
[15:59:23.765] <TB3> INFO: Test took 4254ms.
[15:59:23.770] <TB3> INFO: scanning low vcal = 230
[15:59:24.045] <TB3> INFO: Expecting 41600 events.
[15:59:28.021] <TB3> INFO: 41600 events read in total (3385ms).
[15:59:28.022] <TB3> INFO: Test took 4252ms.
[15:59:28.025] <TB3> INFO: scanning low vcal = 240
[15:59:28.301] <TB3> INFO: Expecting 41600 events.
[15:59:32.338] <TB3> INFO: 41600 events read in total (3445ms).
[15:59:32.339] <TB3> INFO: Test took 4314ms.
[15:59:32.344] <TB3> INFO: scanning low vcal = 250
[15:59:32.619] <TB3> INFO: Expecting 41600 events.
[15:59:36.643] <TB3> INFO: 41600 events read in total (3433ms).
[15:59:36.644] <TB3> INFO: Test took 4300ms.
[15:59:36.649] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[15:59:36.925] <TB3> INFO: Expecting 41600 events.
[15:59:40.929] <TB3> INFO: 41600 events read in total (3411ms).
[15:59:40.930] <TB3> INFO: Test took 4281ms.
[15:59:40.933] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[15:59:41.217] <TB3> INFO: Expecting 41600 events.
[15:59:45.195] <TB3> INFO: 41600 events read in total (3386ms).
[15:59:45.196] <TB3> INFO: Test took 4263ms.
[15:59:45.201] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[15:59:45.476] <TB3> INFO: Expecting 41600 events.
[15:59:49.464] <TB3> INFO: 41600 events read in total (3396ms).
[15:59:49.465] <TB3> INFO: Test took 4264ms.
[15:59:49.469] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[15:59:49.745] <TB3> INFO: Expecting 41600 events.
[15:59:53.705] <TB3> INFO: 41600 events read in total (3368ms).
[15:59:53.706] <TB3> INFO: Test took 4237ms.
[15:59:53.711] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[15:59:53.986] <TB3> INFO: Expecting 41600 events.
[15:59:57.964] <TB3> INFO: 41600 events read in total (3387ms).
[15:59:57.965] <TB3> INFO: Test took 4253ms.
[15:59:58.412] <TB3> INFO: PixTestGainPedestal::measure() done
[16:00:39.135] <TB3> INFO: PixTestGainPedestal::fit() done
[16:00:39.135] <TB3> INFO: non-linearity mean: 0.936 1.009 0.942 0.985 0.984 0.925 0.931 0.978 0.987 0.991 0.937 0.979 0.915 0.984 0.979 0.982
[16:00:39.135] <TB3> INFO: non-linearity RMS: 0.084 0.186 0.095 0.002 0.003 0.135 0.092 0.004 0.002 0.165 0.124 0.004 0.119 0.003 0.011 0.004
[16:00:39.135] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C0.dat
[16:00:39.158] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C1.dat
[16:00:39.181] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C2.dat
[16:00:39.200] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C3.dat
[16:00:39.213] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C4.dat
[16:00:39.229] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C5.dat
[16:00:39.251] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C6.dat
[16:00:39.264] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C7.dat
[16:00:39.279] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C8.dat
[16:00:39.293] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C9.dat
[16:00:39.307] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C10.dat
[16:00:39.327] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C11.dat
[16:00:39.346] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C12.dat
[16:00:39.360] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C13.dat
[16:00:39.374] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C14.dat
[16:00:39.396] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C15.dat
[16:00:39.418] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 168 seconds
[16:00:39.419] <TB3> INFO: Decoding statistics:
[16:00:39.419] <TB3> INFO: General information:
[16:00:39.419] <TB3> INFO: 16bit words read: 3281534
[16:00:39.419] <TB3> INFO: valid events total: 332800
[16:00:39.419] <TB3> INFO: empty events: 2609
[16:00:39.419] <TB3> INFO: valid events with pixels: 330191
[16:00:39.419] <TB3> INFO: valid pixel hits: 642367
[16:00:39.419] <TB3> INFO: Event errors: 0
[16:00:39.419] <TB3> INFO: start marker: 0
[16:00:39.419] <TB3> INFO: stop marker: 0
[16:00:39.419] <TB3> INFO: overflow: 0
[16:00:39.419] <TB3> INFO: invalid 5bit words: 0
[16:00:39.419] <TB3> INFO: invalid XOR eye diagram: 0
[16:00:39.419] <TB3> INFO: frame (failed synchr.): 0
[16:00:39.419] <TB3> INFO: idle data (no TBM trl): 0
[16:00:39.419] <TB3> INFO: no data (only TBM hdr): 0
[16:00:39.419] <TB3> INFO: TBM errors: 0
[16:00:39.419] <TB3> INFO: flawed TBM headers: 0
[16:00:39.419] <TB3> INFO: flawed TBM trailers: 0
[16:00:39.419] <TB3> INFO: event ID mismatches: 0
[16:00:39.419] <TB3> INFO: ROC errors: 0
[16:00:39.419] <TB3> INFO: missing ROC header(s): 0
[16:00:39.419] <TB3> INFO: misplaced readback start: 0
[16:00:39.419] <TB3> INFO: Pixel decoding errors: 0
[16:00:39.419] <TB3> INFO: pixel data incomplete: 0
[16:00:39.419] <TB3> INFO: pixel address: 0
[16:00:39.419] <TB3> INFO: pulse height fill bit: 0
[16:00:39.419] <TB3> INFO: buffer corruption: 0
[16:00:39.443] <TB3> INFO: Decoding statistics:
[16:00:39.443] <TB3> INFO: General information:
[16:00:39.443] <TB3> INFO: 16bit words read: 3410958
[16:00:39.443] <TB3> INFO: valid events total: 353536
[16:00:39.443] <TB3> INFO: empty events: 20841
[16:00:39.443] <TB3> INFO: valid events with pixels: 332695
[16:00:39.443] <TB3> INFO: valid pixel hits: 644871
[16:00:39.443] <TB3> INFO: Event errors: 0
[16:00:39.443] <TB3> INFO: start marker: 0
[16:00:39.443] <TB3> INFO: stop marker: 0
[16:00:39.443] <TB3> INFO: overflow: 0
[16:00:39.443] <TB3> INFO: invalid 5bit words: 0
[16:00:39.443] <TB3> INFO: invalid XOR eye diagram: 0
[16:00:39.443] <TB3> INFO: frame (failed synchr.): 0
[16:00:39.443] <TB3> INFO: idle data (no TBM trl): 0
[16:00:39.443] <TB3> INFO: no data (only TBM hdr): 0
[16:00:39.443] <TB3> INFO: TBM errors: 0
[16:00:39.443] <TB3> INFO: flawed TBM headers: 0
[16:00:39.443] <TB3> INFO: flawed TBM trailers: 0
[16:00:39.443] <TB3> INFO: event ID mismatches: 0
[16:00:39.443] <TB3> INFO: ROC errors: 0
[16:00:39.443] <TB3> INFO: missing ROC header(s): 0
[16:00:39.443] <TB3> INFO: misplaced readback start: 0
[16:00:39.443] <TB3> INFO: Pixel decoding errors: 0
[16:00:39.444] <TB3> INFO: pixel data incomplete: 0
[16:00:39.444] <TB3> INFO: pixel address: 0
[16:00:39.444] <TB3> INFO: pulse height fill bit: 0
[16:00:39.444] <TB3> INFO: buffer corruption: 0
[16:00:39.444] <TB3> INFO: enter test to run
[16:00:39.444] <TB3> INFO: test: trim80 no parameter change
[16:00:39.444] <TB3> INFO: running: trim80
[16:00:39.446] <TB3> INFO: ######################################################################
[16:00:39.446] <TB3> INFO: PixTestTrim80::doTest()
[16:00:39.446] <TB3> INFO: ######################################################################
[16:00:39.447] <TB3> INFO: ----------------------------------------------------------------------
[16:00:39.447] <TB3> INFO: PixTestTrim80::trimTest() ntrig = 8, vcal = 80
[16:00:39.447] <TB3> INFO: ----------------------------------------------------------------------
[16:00:39.498] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[16:00:39.498] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[16:00:39.511] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[16:00:39.511] <TB3> INFO: run 1 of 1
[16:00:39.754] <TB3> INFO: Expecting 5025280 events.
[16:01:07.908] <TB3> INFO: 684456 events read in total (27562ms).
[16:01:34.896] <TB3> INFO: 1363992 events read in total (54550ms).
[16:02:02.401] <TB3> INFO: 2040888 events read in total (82055ms).
[16:02:29.516] <TB3> INFO: 2716112 events read in total (109170ms).
[16:02:56.799] <TB3> INFO: 3391648 events read in total (136453ms).
[16:03:24.316] <TB3> INFO: 4065632 events read in total (163970ms).
[16:03:51.639] <TB3> INFO: 4740152 events read in total (191293ms).
[16:04:03.432] <TB3> INFO: 5025280 events read in total (203086ms).
[16:04:03.504] <TB3> INFO: Test took 203992ms.
[16:04:24.261] <TB3> INFO: ROC 0 VthrComp = 82
[16:04:24.261] <TB3> INFO: ROC 1 VthrComp = 92
[16:04:24.261] <TB3> INFO: ROC 2 VthrComp = 74
[16:04:24.261] <TB3> INFO: ROC 3 VthrComp = 82
[16:04:24.261] <TB3> INFO: ROC 4 VthrComp = 71
[16:04:24.261] <TB3> INFO: ROC 5 VthrComp = 73
[16:04:24.262] <TB3> INFO: ROC 6 VthrComp = 74
[16:04:24.262] <TB3> INFO: ROC 7 VthrComp = 74
[16:04:24.262] <TB3> INFO: ROC 8 VthrComp = 84
[16:04:24.262] <TB3> INFO: ROC 9 VthrComp = 77
[16:04:24.262] <TB3> INFO: ROC 10 VthrComp = 82
[16:04:24.262] <TB3> INFO: ROC 11 VthrComp = 77
[16:04:24.262] <TB3> INFO: ROC 12 VthrComp = 83
[16:04:24.262] <TB3> INFO: ROC 13 VthrComp = 78
[16:04:24.262] <TB3> INFO: ROC 14 VthrComp = 83
[16:04:24.263] <TB3> INFO: ROC 15 VthrComp = 74
[16:04:24.500] <TB3> INFO: Expecting 41600 events.
[16:04:27.948] <TB3> INFO: 41600 events read in total (2856ms).
[16:04:27.949] <TB3> INFO: Test took 3684ms.
[16:04:27.961] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[16:04:27.961] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[16:04:27.976] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[16:04:27.976] <TB3> INFO: run 1 of 1
[16:04:28.254] <TB3> INFO: Expecting 5025280 events.
[16:04:56.237] <TB3> INFO: 688416 events read in total (27391ms).
[16:05:24.017] <TB3> INFO: 1373816 events read in total (55171ms).
[16:05:51.139] <TB3> INFO: 2057352 events read in total (82293ms).
[16:06:18.911] <TB3> INFO: 2736888 events read in total (110065ms).
[16:06:46.350] <TB3> INFO: 3413744 events read in total (137504ms).
[16:07:13.345] <TB3> INFO: 4088944 events read in total (164499ms).
[16:07:40.579] <TB3> INFO: 4763936 events read in total (191733ms).
[16:07:51.392] <TB3> INFO: 5025280 events read in total (202546ms).
[16:07:51.468] <TB3> INFO: Test took 203492ms.
[16:08:12.001] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 110.607 for pixel 0/65 mean/min/max = 92.7691/74.736/110.802
[16:08:12.001] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 110.121 for pixel 26/7 mean/min/max = 92.881/75.544/110.218
[16:08:12.002] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 109.986 for pixel 8/79 mean/min/max = 93.7496/77.4534/110.046
[16:08:12.003] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 107.577 for pixel 0/68 mean/min/max = 91.2004/74.8233/107.578
[16:08:13.004] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 106.641 for pixel 0/7 mean/min/max = 89.9644/73.1704/106.758
[16:08:13.004] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 110.07 for pixel 50/12 mean/min/max = 93.7692/77.4182/110.12
[16:08:13.005] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 111.874 for pixel 7/0 mean/min/max = 94.4691/76.9334/112.005
[16:08:13.006] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 108.897 for pixel 14/77 mean/min/max = 93.2034/77.2029/109.204
[16:08:13.006] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 107.232 for pixel 0/78 mean/min/max = 91.6679/75.7062/107.63
[16:08:13.007] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 109.275 for pixel 0/20 mean/min/max = 94.1173/78.7562/109.479
[16:08:13.008] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 110.298 for pixel 0/11 mean/min/max = 92.6677/74.8802/110.455
[16:08:13.008] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 112.35 for pixel 6/53 mean/min/max = 95.1321/77.8024/112.462
[16:08:13.009] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 107.319 for pixel 18/23 mean/min/max = 91.4105/75.3119/107.509
[16:08:13.009] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 110.129 for pixel 11/22 mean/min/max = 93.7624/77.3122/110.213
[16:08:13.010] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 116.703 for pixel 0/6 mean/min/max = 95.1232/73.5075/116.739
[16:08:13.010] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 110.661 for pixel 2/9 mean/min/max = 94.4069/78.0427/110.771
[16:08:13.011] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:08:13.100] <TB3> INFO: Expecting 411648 events.
[16:08:22.595] <TB3> INFO: 411648 events read in total (8903ms).
[16:08:22.604] <TB3> INFO: Expecting 411648 events.
[16:08:31.957] <TB3> INFO: 411648 events read in total (8950ms).
[16:08:31.971] <TB3> INFO: Expecting 411648 events.
[16:08:41.390] <TB3> INFO: 411648 events read in total (9016ms).
[16:08:41.407] <TB3> INFO: Expecting 411648 events.
[16:08:50.710] <TB3> INFO: 411648 events read in total (8900ms).
[16:08:50.730] <TB3> INFO: Expecting 411648 events.
[16:09:00.106] <TB3> INFO: 411648 events read in total (8973ms).
[16:09:00.126] <TB3> INFO: Expecting 411648 events.
[16:09:09.479] <TB3> INFO: 411648 events read in total (8949ms).
[16:09:09.501] <TB3> INFO: Expecting 411648 events.
[16:09:18.835] <TB3> INFO: 411648 events read in total (8931ms).
[16:09:18.863] <TB3> INFO: Expecting 411648 events.
[16:09:28.185] <TB3> INFO: 411648 events read in total (8919ms).
[16:09:28.215] <TB3> INFO: Expecting 411648 events.
[16:09:37.583] <TB3> INFO: 411648 events read in total (8965ms).
[16:09:37.613] <TB3> INFO: Expecting 411648 events.
[16:09:46.839] <TB3> INFO: 411648 events read in total (8822ms).
[16:09:46.873] <TB3> INFO: Expecting 411648 events.
[16:09:56.100] <TB3> INFO: 411648 events read in total (8824ms).
[16:09:56.135] <TB3> INFO: Expecting 411648 events.
[16:10:05.667] <TB3> INFO: 411648 events read in total (9129ms).
[16:10:05.706] <TB3> INFO: Expecting 411648 events.
[16:10:14.944] <TB3> INFO: 411648 events read in total (8835ms).
[16:10:14.986] <TB3> INFO: Expecting 411648 events.
[16:10:24.239] <TB3> INFO: 411648 events read in total (8850ms).
[16:10:24.314] <TB3> INFO: Expecting 411648 events.
[16:10:33.718] <TB3> INFO: 411648 events read in total (9001ms).
[16:10:33.783] <TB3> INFO: Expecting 411648 events.
[16:10:43.035] <TB3> INFO: 411648 events read in total (8849ms).
[16:10:43.100] <TB3> INFO: Test took 150089ms.
[16:10:44.774] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[16:10:44.788] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[16:10:44.788] <TB3> INFO: run 1 of 1
[16:10:45.065] <TB3> INFO: Expecting 5025280 events.
[16:11:12.679] <TB3> INFO: 669920 events read in total (27023ms).
[16:11:40.149] <TB3> INFO: 1337376 events read in total (54493ms).
[16:12:07.347] <TB3> INFO: 2003864 events read in total (81691ms).
[16:12:34.302] <TB3> INFO: 2667936 events read in total (108646ms).
[16:13:01.041] <TB3> INFO: 3327176 events read in total (135385ms).
[16:13:28.250] <TB3> INFO: 3984840 events read in total (162594ms).
[16:13:56.388] <TB3> INFO: 4640256 events read in total (190732ms).
[16:14:12.198] <TB3> INFO: 5025280 events read in total (206542ms).
[16:14:12.262] <TB3> INFO: Test took 207474ms.
[16:14:46.264] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 50.930683 .. 107.282786
[16:14:47.119] <TB3> INFO: Expecting 208000 events.
[16:15:30.741] <TB3> INFO: 208000 events read in total (42934ms).
[16:15:30.743] <TB3> INFO: Test took 44477ms.
[16:15:30.840] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 40 .. 117 (-1/-1) hits flags = 528 (plus default)
[16:15:30.857] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[16:15:30.858] <TB3> INFO: run 1 of 1
[16:15:31.318] <TB3> INFO: Expecting 2595840 events.
[16:15:59.997] <TB3> INFO: 678064 events read in total (28085ms).
[16:17:14.595] <TB3> INFO: 1355600 events read in total (102683ms).
[16:18:33.003] <TB3> INFO: 2029048 events read in total (181091ms).
[16:18:56.861] <TB3> INFO: 2595840 events read in total (204949ms).
[16:18:56.923] <TB3> INFO: Test took 206065ms.
[16:19:40.927] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 59.144113 .. 97.197614
[16:19:41.169] <TB3> INFO: Expecting 208000 events.
[16:20:09.975] <TB3> INFO: 208000 events read in total (28108ms).
[16:20:09.976] <TB3> INFO: Test took 29048ms.
[16:20:10.058] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 49 .. 107 (-1/-1) hits flags = 528 (plus default)
[16:20:10.073] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[16:20:10.073] <TB3> INFO: run 1 of 1
[16:20:10.351] <TB3> INFO: Expecting 1963520 events.
[16:21:09.417] <TB3> INFO: 680032 events read in total (58475ms).
[16:21:51.909] <TB3> INFO: 1358712 events read in total (100966ms).
[16:23:10.022] <TB3> INFO: 1963520 events read in total (179079ms).
[16:23:10.071] <TB3> INFO: Test took 179999ms.
[16:23:33.515] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 63.099121 .. 91.568935
[16:23:33.800] <TB3> INFO: Expecting 208000 events.
[16:26:10.939] <TB3> CRITICAL: <USBInterface.libftd2xx.cc/FillBuffer:L266> Requested to read 4096b, but read 3911b - 185b missing!

[16:26:11.186] <TB3> INFO: Expecting 208000 events.
[16:26:20.890] <TB3> INFO: 208000 events read in total (9112ms).
[16:26:20.891] <TB3> INFO: Test took 9942ms.
[16:26:20.939] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 53 .. 101 (-1/-1) hits flags = 528 (plus default)
[16:26:20.953] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[16:26:20.953] <TB3> INFO: run 1 of 1
[16:26:21.231] <TB3> INFO: Expecting 1630720 events.
[16:26:51.966] <TB3> INFO: 690488 events read in total (30144ms).
[16:27:20.837] <TB3> INFO: 1380160 events read in total (59015ms).
[16:27:31.285] <TB3> INFO: 1630720 events read in total (69463ms).
[16:27:31.314] <TB3> INFO: Test took 70362ms.
[16:27:46.881] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 65.150223 .. 86.588637
[16:27:47.120] <TB3> INFO: Expecting 208000 events.
[16:27:56.930] <TB3> INFO: 208000 events read in total (9218ms).
[16:27:56.931] <TB3> INFO: Test took 10049ms.
[16:27:56.994] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 55 .. 96 (-1/-1) hits flags = 528 (plus default)
[16:27:57.008] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[16:27:57.008] <TB3> INFO: run 1 of 1
[16:27:57.286] <TB3> INFO: Expecting 1397760 events.
[16:28:26.465] <TB3> INFO: 707520 events read in total (28586ms).
[16:28:54.772] <TB3> INFO: 1397760 events read in total (56893ms).
[16:28:54.818] <TB3> INFO: Test took 57811ms.
[16:29:12.208] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 60 .. 100
[16:29:12.208] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 60 .. 100 (-1/-1) hits flags = 528 (plus default)
[16:29:12.222] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[16:29:12.222] <TB3> INFO: run 1 of 1
[16:29:12.458] <TB3> INFO: Expecting 1364480 events.
[16:29:41.005] <TB3> INFO: 667792 events read in total (27955ms).
[16:30:10.805] <TB3> INFO: 1335048 events read in total (57755ms).
[16:30:12.671] <TB3> INFO: 1364480 events read in total (59621ms).
[16:30:12.708] <TB3> INFO: Test took 60487ms.
[16:30:28.717] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C0.dat
[16:30:28.718] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C1.dat
[16:30:28.718] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C2.dat
[16:30:28.718] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C3.dat
[16:30:28.718] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C4.dat
[16:30:28.718] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C5.dat
[16:30:28.718] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C6.dat
[16:30:28.718] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C7.dat
[16:30:28.719] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C8.dat
[16:30:28.719] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C9.dat
[16:30:28.719] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C10.dat
[16:30:28.719] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C11.dat
[16:30:28.719] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C12.dat
[16:30:28.719] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C13.dat
[16:30:28.719] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C14.dat
[16:30:28.719] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C15.dat
[16:30:28.720] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C0.dat
[16:30:28.728] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C1.dat
[16:30:28.735] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C2.dat
[16:30:28.740] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C3.dat
[16:30:28.745] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C4.dat
[16:30:28.750] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C5.dat
[16:30:28.754] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C6.dat
[16:30:28.759] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C7.dat
[16:30:28.764] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C8.dat
[16:30:28.769] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C9.dat
[16:30:28.773] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C10.dat
[16:30:28.778] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C11.dat
[16:30:28.783] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C12.dat
[16:30:28.788] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C13.dat
[16:30:28.792] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C14.dat
[16:30:28.797] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1089_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C15.dat
[16:30:28.802] <TB3> INFO: PixTestTrim80::trimTest() done
[16:30:28.802] <TB3> INFO: vtrim: 98 109 97 92 82 106 116 100 92 95 93 97 96 109 107 104
[16:30:28.802] <TB3> INFO: vthrcomp: 82 92 74 82 71 73 74 74 84 77 82 77 83 78 83 74
[16:30:28.802] <TB3> INFO: vcal mean: 79.86 79.89 79.84 79.88 79.83 79.88 79.86 79.88 79.84 79.90 79.83 79.83 79.89 79.89 79.85 79.86
[16:30:28.802] <TB3> INFO: vcal RMS: 1.91 0.81 0.71 0.78 0.73 0.74 0.78 0.77 0.77 0.74 0.81 0.78 0.75 0.77 0.90 0.78
[16:30:28.802] <TB3> INFO: bits mean: 9.56 9.68 9.18 10.13 10.04 9.77 9.74 9.34 9.54 8.65 9.52 9.18 10.10 9.66 9.88 9.46
[16:30:28.802] <TB3> INFO: bits RMS: 2.60 2.40 2.39 2.40 2.72 2.12 2.16 2.37 2.60 2.41 2.59 2.29 2.34 2.21 2.47 2.20
[16:30:28.809] <TB3> INFO: ----------------------------------------------------------------------
[16:30:28.809] <TB3> INFO: PixTestTrim80::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[16:30:28.809] <TB3> INFO: ----------------------------------------------------------------------
[16:30:28.812] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[16:30:28.825] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:30:28.825] <TB3> INFO: run 1 of 1
[16:30:29.091] <TB3> INFO: Expecting 4160000 events.
[16:31:02.117] <TB3> INFO: 770275 events read in total (32434ms).
[16:31:34.205] <TB3> INFO: 1534000 events read in total (64522ms).
[16:32:06.137] <TB3> INFO: 2289865 events read in total (96454ms).
[16:32:37.955] <TB3> INFO: 3042685 events read in total (128272ms).
[16:33:09.751] <TB3> INFO: 3793115 events read in total (160068ms).
[16:33:25.334] <TB3> INFO: 4160000 events read in total (175651ms).
[16:33:25.426] <TB3> INFO: Test took 176602ms.
[16:33:50.779] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 232 (-1/-1) hits flags = 528 (plus default)
[16:33:50.793] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:33:50.793] <TB3> INFO: run 1 of 1
[16:33:51.036] <TB3> INFO: Expecting 4846400 events.
[16:34:22.747] <TB3> INFO: 704915 events read in total (31120ms).
[16:34:54.271] <TB3> INFO: 1405785 events read in total (62644ms).
[16:35:24.981] <TB3> INFO: 2103230 events read in total (93354ms).
[16:35:55.586] <TB3> INFO: 2797160 events read in total (123959ms).
[16:36:26.241] <TB3> INFO: 3490020 events read in total (154614ms).
[16:36:56.762] <TB3> INFO: 4180915 events read in total (185135ms).
[16:37:26.160] <TB3> INFO: 4846400 events read in total (214533ms).
[16:37:26.272] <TB3> INFO: Test took 215479ms.
[16:37:56.604] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 220 (-1/-1) hits flags = 528 (plus default)
[16:37:56.617] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:37:56.618] <TB3> INFO: run 1 of 1
[16:37:56.854] <TB3> INFO: Expecting 4596800 events.
[16:38:29.083] <TB3> INFO: 717935 events read in total (31637ms).
[16:39:00.021] <TB3> INFO: 1430890 events read in total (62575ms).
[16:39:31.036] <TB3> INFO: 2140115 events read in total (93590ms).
[16:40:01.706] <TB3> INFO: 2845435 events read in total (124260ms).
[16:40:32.473] <TB3> INFO: 3549845 events read in total (155027ms).
[16:41:03.699] <TB3> INFO: 4252785 events read in total (186253ms).
[16:41:18.550] <TB3> INFO: 4596800 events read in total (201104ms).
[16:41:18.644] <TB3> INFO: Test took 202026ms.
[16:41:51.989] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 219 (-1/-1) hits flags = 528 (plus default)
[16:41:52.003] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:41:52.003] <TB3> INFO: run 1 of 1
[16:41:52.329] <TB3> INFO: Expecting 4576000 events.
[16:42:23.759] <TB3> INFO: 719230 events read in total (30838ms).
[16:42:54.709] <TB3> INFO: 1433655 events read in total (61788ms).
[16:43:26.148] <TB3> INFO: 2144280 events read in total (93227ms).
[16:43:57.137] <TB3> INFO: 2850975 events read in total (124217ms).
[16:44:28.336] <TB3> INFO: 3556290 events read in total (155415ms).
[16:44:59.197] <TB3> INFO: 4260745 events read in total (186276ms).
[16:45:12.787] <TB3> INFO: 4576000 events read in total (199866ms).
[16:45:12.901] <TB3> INFO: Test took 200897ms.
[16:45:39.481] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 221 (-1/-1) hits flags = 528 (plus default)
[16:45:39.496] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:45:39.496] <TB3> INFO: run 1 of 1
[16:45:39.791] <TB3> INFO: Expecting 4617600 events.
[16:46:11.144] <TB3> INFO: 717215 events read in total (30761ms).
[16:46:40.608] <TB3> INFO: 1429510 events read in total (60225ms).
[16:47:10.110] <TB3> INFO: 2137875 events read in total (89727ms).
[16:47:39.654] <TB3> INFO: 2842220 events read in total (119271ms).
[16:48:09.541] <TB3> INFO: 3545675 events read in total (149158ms).
[16:48:39.261] <TB3> INFO: 4247830 events read in total (178878ms).
[16:48:54.877] <TB3> INFO: 4617600 events read in total (194494ms).
[16:48:54.959] <TB3> INFO: Test took 195463ms.
[16:49:19.606] <TB3> INFO: PixTestTrim80::trimBitTest() done
[16:49:19.607] <TB3> INFO: PixTestTrim80::doTest() done, duration: 2920 seconds
[16:49:20.221] <TB3> INFO: enter test to run
[16:49:20.221] <TB3> INFO: test: exit no parameter change
[16:49:20.409] <TB3> QUIET: Connection to board 126 closed.
[16:49:20.410] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud