Test Date: 2016-10-23 14:52
Analysis date: 2016-10-24 13:58
Logfile
LogfileView
[09:52:03.623] <TB3> INFO: *** Welcome to pxar ***
[09:52:03.623] <TB3> INFO: *** Today: 2016/10/24
[09:52:03.629] <TB3> INFO: *** Version: c8ba-dirty
[09:52:03.629] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C15.dat
[09:52:03.630] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//tbmParameters_C1b.dat
[09:52:03.630] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//defaultMaskFile.dat
[09:52:03.630] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters_C15.dat
[09:52:03.700] <TB3> INFO: clk: 4
[09:52:03.700] <TB3> INFO: ctr: 4
[09:52:03.700] <TB3> INFO: sda: 19
[09:52:03.700] <TB3> INFO: tin: 9
[09:52:03.700] <TB3> INFO: level: 15
[09:52:03.700] <TB3> INFO: triggerdelay: 0
[09:52:03.700] <TB3> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[09:52:03.700] <TB3> INFO: Log level: INFO
[09:52:03.707] <TB3> INFO: Found DTB DTB_WWVASW
[09:52:03.715] <TB3> QUIET: Connection to board DTB_WWVASW opened.
[09:52:03.717] <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:
------------------------------------------------------
[09:52:03.719] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[09:52:05.209] <TB3> INFO: DUT info:
[09:52:05.209] <TB3> INFO: The DUT currently contains the following objects:
[09:52:05.209] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[09:52:05.209] <TB3> INFO: TBM Core alpha (0): 7 registers set
[09:52:05.210] <TB3> INFO: TBM Core beta (1): 7 registers set
[09:52:05.210] <TB3> INFO: TBM Core alpha (2): 7 registers set
[09:52:05.210] <TB3> INFO: TBM Core beta (3): 7 registers set
[09:52:05.210] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[09:52:05.210] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.210] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:52:05.611] <TB3> INFO: enter 'restricted' command line mode
[09:52:05.611] <TB3> INFO: enter test to run
[09:52:05.611] <TB3> INFO: test: pretest no parameter change
[09:52:05.611] <TB3> INFO: running: pretest
[09:52:05.617] <TB3> INFO: ######################################################################
[09:52:05.617] <TB3> INFO: PixTestPretest::doTest()
[09:52:05.617] <TB3> INFO: ######################################################################
[09:52:05.618] <TB3> INFO: ----------------------------------------------------------------------
[09:52:05.618] <TB3> INFO: PixTestPretest::programROC()
[09:52:05.618] <TB3> INFO: ----------------------------------------------------------------------
[09:52:23.632] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[09:52:23.632] <TB3> INFO: IA differences per ROC: 20.1 18.5 18.5 16.1 17.7 20.1 20.1 20.1 19.3 20.9 20.1 18.5 20.9 20.1 19.3 19.3
[09:52:23.693] <TB3> INFO: ----------------------------------------------------------------------
[09:52:23.693] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[09:52:23.693] <TB3> INFO: ----------------------------------------------------------------------
[09:52:44.957] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 384.3 mA = 24.0187 mA/ROC
[09:52:44.957] <TB3> INFO: i(loss) [mA/ROC]: 19.3 18.5 20.1 18.5 18.5 18.5 19.3 19.3 20.1 18.5 17.7 18.5 18.5 18.5 18.5 18.5
[09:52:44.988] <TB3> INFO: ----------------------------------------------------------------------
[09:52:44.988] <TB3> INFO: PixTestPretest::findTiming()
[09:52:44.988] <TB3> INFO: ----------------------------------------------------------------------
[09:52:44.988] <TB3> INFO: PixTestCmd::init()
[09:52:45.544] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!

[09:53:16.499] <TB3> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[09:53:16.499] <TB3> INFO: (success/tries = 100/100), width = 4
[09:53:18.011] <TB3> INFO: ----------------------------------------------------------------------
[09:53:18.011] <TB3> INFO: PixTestPretest::findWorkingPixel()
[09:53:18.011] <TB3> INFO: ----------------------------------------------------------------------
[09:53:18.104] <TB3> INFO: Expecting 231680 events.
[09:53:27.990] <TB3> INFO: 231680 events read in total (9294ms).
[09:53:27.998] <TB3> INFO: Test took 9983ms.
[09:53:28.243] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[09:53:28.275] <TB3> INFO: ----------------------------------------------------------------------
[09:53:28.275] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[09:53:28.275] <TB3> INFO: ----------------------------------------------------------------------
[09:53:28.369] <TB3> INFO: Expecting 231680 events.
[09:53:38.488] <TB3> INFO: 231680 events read in total (9528ms).
[09:53:38.497] <TB3> INFO: Test took 10217ms.
[09:53:38.760] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[09:53:38.760] <TB3> INFO: CalDel: 80 83 93 101 85 107 95 76 78 88 80 102 92 100 99 84
[09:53:38.760] <TB3> INFO: VthrComp: 55 51 56 52 51 51 51 51 51 51 53 51 51 51 52 51
[09:53:38.763] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C0.dat
[09:53:38.764] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C1.dat
[09:53:38.764] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C2.dat
[09:53:38.764] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C3.dat
[09:53:38.764] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C4.dat
[09:53:38.764] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C5.dat
[09:53:38.764] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C6.dat
[09:53:38.765] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C7.dat
[09:53:38.765] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C8.dat
[09:53:38.765] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C9.dat
[09:53:38.765] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C10.dat
[09:53:38.765] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C11.dat
[09:53:38.765] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C12.dat
[09:53:38.766] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C13.dat
[09:53:38.766] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C14.dat
[09:53:38.766] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters_C15.dat
[09:53:38.766] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//tbmParameters_C0a.dat
[09:53:38.766] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//tbmParameters_C0b.dat
[09:53:38.766] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//tbmParameters_C1a.dat
[09:53:38.767] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//tbmParameters_C1b.dat
[09:53:38.767] <TB3> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[09:53:38.845] <TB3> INFO: enter test to run
[09:53:38.845] <TB3> INFO: test: FullTest no parameter change
[09:53:38.845] <TB3> INFO: running: fulltest
[09:53:38.845] <TB3> INFO: ######################################################################
[09:53:38.845] <TB3> INFO: PixTestFullTest::doTest()
[09:53:38.845] <TB3> INFO: ######################################################################
[09:53:38.847] <TB3> INFO: ######################################################################
[09:53:38.847] <TB3> INFO: PixTestAlive::doTest()
[09:53:38.847] <TB3> INFO: ######################################################################
[09:53:38.848] <TB3> INFO: ----------------------------------------------------------------------
[09:53:38.848] <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)
[09:53:38.848] <TB3> INFO: ----------------------------------------------------------------------
[09:53:39.156] <TB3> INFO: Expecting 41600 events.
[09:53:42.667] <TB3> INFO: 41600 events read in total (2919ms).
[09:53:42.667] <TB3> INFO: Test took 3817ms.
[09:53:42.894] <TB3> INFO: PixTestAlive::aliveTest() done
[09:53:42.894] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0
[09:53:42.896] <TB3> INFO: ----------------------------------------------------------------------
[09:53:42.896] <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)
[09:53:42.896] <TB3> INFO: ----------------------------------------------------------------------
[09:53:43.142] <TB3> INFO: Expecting 41600 events.
[09:53:46.113] <TB3> INFO: 41600 events read in total (2379ms).
[09:53:46.113] <TB3> INFO: Test took 3215ms.
[09:53:46.114] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[09:53:46.354] <TB3> INFO: PixTestAlive::maskTest() done
[09:53:46.354] <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
[09:53:46.356] <TB3> INFO: ----------------------------------------------------------------------
[09:53:46.356] <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)
[09:53:46.356] <TB3> INFO: ----------------------------------------------------------------------
[09:53:46.640] <TB3> INFO: Expecting 41600 events.
[09:53:50.192] <TB3> INFO: 41600 events read in total (2960ms).
[09:53:50.193] <TB3> INFO: Test took 3835ms.
[09:53:50.422] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[09:53:50.422] <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
[09:53:50.422] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[09:53:50.422] <TB3> INFO: Decoding statistics:
[09:53:50.423] <TB3> INFO: General information:
[09:53:50.423] <TB3> INFO: 16bit words read: 0
[09:53:50.423] <TB3> INFO: valid events total: 0
[09:53:50.423] <TB3> INFO: empty events: 0
[09:53:50.423] <TB3> INFO: valid events with pixels: 0
[09:53:50.423] <TB3> INFO: valid pixel hits: 0
[09:53:50.423] <TB3> INFO: Event errors: 0
[09:53:50.423] <TB3> INFO: start marker: 0
[09:53:50.423] <TB3> INFO: stop marker: 0
[09:53:50.423] <TB3> INFO: overflow: 0
[09:53:50.423] <TB3> INFO: invalid 5bit words: 0
[09:53:50.423] <TB3> INFO: invalid XOR eye diagram: 0
[09:53:50.423] <TB3> INFO: frame (failed synchr.): 0
[09:53:50.423] <TB3> INFO: idle data (no TBM trl): 0
[09:53:50.423] <TB3> INFO: no data (only TBM hdr): 0
[09:53:50.423] <TB3> INFO: TBM errors: 0
[09:53:50.423] <TB3> INFO: flawed TBM headers: 0
[09:53:50.423] <TB3> INFO: flawed TBM trailers: 0
[09:53:50.423] <TB3> INFO: event ID mismatches: 0
[09:53:50.423] <TB3> INFO: ROC errors: 0
[09:53:50.423] <TB3> INFO: missing ROC header(s): 0
[09:53:50.423] <TB3> INFO: misplaced readback start: 0
[09:53:50.423] <TB3> INFO: Pixel decoding errors: 0
[09:53:50.423] <TB3> INFO: pixel data incomplete: 0
[09:53:50.423] <TB3> INFO: pixel address: 0
[09:53:50.423] <TB3> INFO: pulse height fill bit: 0
[09:53:50.423] <TB3> INFO: buffer corruption: 0
[09:53:50.429] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C15.dat
[09:53:50.430] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr_C15.dat
[09:53:50.430] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[09:53:50.430] <TB3> INFO: ######################################################################
[09:53:50.430] <TB3> INFO: PixTestReadback::doTest()
[09:53:50.430] <TB3> INFO: ######################################################################
[09:53:50.430] <TB3> INFO: ----------------------------------------------------------------------
[09:53:50.430] <TB3> INFO: PixTestReadback::CalibrateVd()
[09:53:50.430] <TB3> INFO: ----------------------------------------------------------------------
[09:54:00.383] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C0.dat
[09:54:00.383] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C1.dat
[09:54:00.383] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C2.dat
[09:54:00.383] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C3.dat
[09:54:00.383] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C4.dat
[09:54:00.383] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C5.dat
[09:54:00.383] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C6.dat
[09:54:00.383] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C7.dat
[09:54:00.383] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C8.dat
[09:54:00.384] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C9.dat
[09:54:00.384] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C10.dat
[09:54:00.384] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C11.dat
[09:54:00.384] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C12.dat
[09:54:00.384] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C13.dat
[09:54:00.384] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C14.dat
[09:54:00.384] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C15.dat
[09:54:00.415] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[09:54:00.415] <TB3> INFO: ----------------------------------------------------------------------
[09:54:00.415] <TB3> INFO: PixTestReadback::CalibrateVa()
[09:54:00.415] <TB3> INFO: ----------------------------------------------------------------------
[09:54:10.328] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C0.dat
[09:54:10.328] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C1.dat
[09:54:10.328] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C2.dat
[09:54:10.328] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C3.dat
[09:54:10.328] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C4.dat
[09:54:10.328] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C5.dat
[09:54:10.328] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C6.dat
[09:54:10.329] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C7.dat
[09:54:10.329] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C8.dat
[09:54:10.329] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C9.dat
[09:54:10.329] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C10.dat
[09:54:10.329] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C11.dat
[09:54:10.329] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C12.dat
[09:54:10.329] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C13.dat
[09:54:10.329] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C14.dat
[09:54:10.329] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C15.dat
[09:54:10.360] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[09:54:10.360] <TB3> INFO: ----------------------------------------------------------------------
[09:54:10.360] <TB3> INFO: PixTestReadback::readbackVbg()
[09:54:10.360] <TB3> INFO: ----------------------------------------------------------------------
[09:54:18.009] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[09:54:18.009] <TB3> INFO: ----------------------------------------------------------------------
[09:54:18.009] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[09:54:18.009] <TB3> INFO: ----------------------------------------------------------------------
[09:54:18.010] <TB3> INFO: Vbg will be calibrated using Vd calibration
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 157.7calibrated Vbg = 1.21685 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 155.2calibrated Vbg = 1.21673 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 155.4calibrated Vbg = 1.20854 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 157.9calibrated Vbg = 1.21204 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 154calibrated Vbg = 1.21122 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 151.5calibrated Vbg = 1.21472 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 158.8calibrated Vbg = 1.22175 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 158.5calibrated Vbg = 1.21594 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 154.6calibrated Vbg = 1.20977 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 160calibrated Vbg = 1.20208 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 162.9calibrated Vbg = 1.20746 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 151.4calibrated Vbg = 1.19992 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 154.7calibrated Vbg = 1.21138 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 155.7calibrated Vbg = 1.20849 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 159calibrated Vbg = 1.21299 :::*/*/*/*/
[09:54:18.010] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 153.5calibrated Vbg = 1.21634 :::*/*/*/*/
[09:54:18.013] <TB3> INFO: ----------------------------------------------------------------------
[09:54:18.013] <TB3> INFO: PixTestReadback::CalibrateIa()
[09:54:18.013] <TB3> INFO: ----------------------------------------------------------------------
[09:56:58.488] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C0.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C1.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C2.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C3.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C4.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C5.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C6.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C7.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C8.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C9.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C10.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C11.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C12.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C13.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C14.dat
[09:56:58.489] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//readbackCal_C15.dat
[09:56:58.517] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[09:56:58.519] <TB3> INFO: PixTestReadback::doTest() done
[09:56:58.519] <TB3> INFO: Decoding statistics:
[09:56:58.519] <TB3> INFO: General information:
[09:56:58.519] <TB3> INFO: 16bit words read: 1536
[09:56:58.519] <TB3> INFO: valid events total: 256
[09:56:58.519] <TB3> INFO: empty events: 256
[09:56:58.519] <TB3> INFO: valid events with pixels: 0
[09:56:58.519] <TB3> INFO: valid pixel hits: 0
[09:56:58.519] <TB3> INFO: Event errors: 0
[09:56:58.519] <TB3> INFO: start marker: 0
[09:56:58.519] <TB3> INFO: stop marker: 0
[09:56:58.519] <TB3> INFO: overflow: 0
[09:56:58.519] <TB3> INFO: invalid 5bit words: 0
[09:56:58.519] <TB3> INFO: invalid XOR eye diagram: 0
[09:56:58.519] <TB3> INFO: frame (failed synchr.): 0
[09:56:58.519] <TB3> INFO: idle data (no TBM trl): 0
[09:56:58.519] <TB3> INFO: no data (only TBM hdr): 0
[09:56:58.519] <TB3> INFO: TBM errors: 0
[09:56:58.519] <TB3> INFO: flawed TBM headers: 0
[09:56:58.519] <TB3> INFO: flawed TBM trailers: 0
[09:56:58.519] <TB3> INFO: event ID mismatches: 0
[09:56:58.519] <TB3> INFO: ROC errors: 0
[09:56:58.519] <TB3> INFO: missing ROC header(s): 0
[09:56:58.519] <TB3> INFO: misplaced readback start: 0
[09:56:58.519] <TB3> INFO: Pixel decoding errors: 0
[09:56:58.519] <TB3> INFO: pixel data incomplete: 0
[09:56:58.519] <TB3> INFO: pixel address: 0
[09:56:58.519] <TB3> INFO: pulse height fill bit: 0
[09:56:58.519] <TB3> INFO: buffer corruption: 0
[09:56:58.566] <TB3> INFO: ######################################################################
[09:56:58.566] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[09:56:58.566] <TB3> INFO: ######################################################################
[09:56:58.568] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[09:56:58.606] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[09:56:58.606] <TB3> INFO: run 1 of 1
[09:56:58.842] <TB3> INFO: Expecting 3120000 events.
[09:57:31.170] <TB3> INFO: 668275 events read in total (31736ms).
[09:57:43.355] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (244) != TBM ID (129)

[09:57:43.504] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 244 244 129 244 244 244 244 244

[09:57:43.504] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (245)

[09:57:43.505] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[09:57:43.505] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f8 80b1 4810 4810 e022 c000

[09:57:43.505] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f2 8000 4c00 4c00 e022 c000

[09:57:43.505] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f3 8040 4c10 4c11 e022 c000

[09:57:43.505] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c11 e022 c000

[09:57:43.505] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f5 80c0 4c10 4c10 e022 c000

[09:57:43.505] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f6 8000 4810 4810 e022 c000

[09:57:43.505] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f7 8040 4810 4810 e022 c000

[09:58:02.461] <TB3> INFO: 1330665 events read in total (63027ms).
[09:58:14.565] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (106) != TBM ID (129)

[09:58:14.714] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 106 106 129 106 106 106 106 106

[09:58:14.715] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (107)

[09:58:14.717] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[09:58:14.717] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06e 8000 4811 4811 e022 c000

[09:58:14.717] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a068 80b1 4c00 4c00 e022 c000

[09:58:14.717] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a069 80c0 4810 4810 e022 c000

[09:58:14.717] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c11 e022 c000

[09:58:14.717] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06b 8040 4c11 4c11 e022 c000

[09:58:14.717] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06c 80b1 4811 4811 e022 c000

[09:58:14.717] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06d 80c0 4c11 4c11 e022 c000

[09:58:33.625] <TB3> INFO: 1989145 events read in total (94191ms).
[09:58:45.739] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (154) != TBM ID (129)

[09:58:45.889] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 154 154 129 154 154 154 154 154

[09:58:45.889] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (155)

[09:58:45.889] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[09:58:45.889] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09e 8000 4811 4811 e022 c000

[09:58:45.889] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a098 80b1 4c10 4c10 e022 c000

[09:58:45.889] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a099 80c0 4c10 4c10 e022 c000

[09:58:45.889] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c11 e022 c000

[09:58:45.889] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09b 8040 4811 4811 e022 c000

[09:58:45.889] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09c 80b1 4811 4811 e022 c000

[09:58:45.889] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09d 80c0 4810 4810 e022 c000

[09:59:04.600] <TB3> INFO: 2647460 events read in total (125166ms).
[09:59:13.375] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (37) != TBM ID (129)

[09:59:13.518] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 37 37 129 37 37 37 37 37

[09:59:13.518] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (38)

[09:59:13.518] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[09:59:13.518] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a029 80c0 4c10 a82 23e1 4810 a82 23ef e022 c000

[09:59:13.519] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a023 8040 4c10 a82 23e5 4c11 a82 23ef e022 c000

[09:59:13.519] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a024 80b1 4810 a82 23e4 4810 a82 23ef e022 c000

[09:59:13.519] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c11 23e3 4c10 a82 23ef e022 c000

[09:59:13.519] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a026 8000 4c10 a82 23e1 4810 a82 23ef e022 c000

[09:59:13.519] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a027 8040 4810 a82 23e1 4810 a82 23ef e022 c000

[09:59:13.519] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a028 80b1 4811 a82 23e5 4811 a82 23ef e022 c000

[09:59:26.627] <TB3> INFO: 3120000 events read in total (147193ms).
[09:59:26.694] <TB3> INFO: Test took 148090ms.
[09:59:47.749] <TB3> INFO: PixTestBBMap::doTest() done with 1 decoding errors: , duration: 169 seconds
[09:59:47.749] <TB3> INFO: number of dead bumps (per ROC): 1 0 1 0 0 1 1 1 0 0 0 0 0 10 0 0
[09:59:47.749] <TB3> INFO: separation cut (per ROC): 108 106 109 94 103 106 104 106 109 109 112 111 106 107 105 105
[09:59:47.749] <TB3> INFO: Decoding statistics:
[09:59:47.749] <TB3> INFO: General information:
[09:59:47.749] <TB3> INFO: 16bit words read: 0
[09:59:47.749] <TB3> INFO: valid events total: 0
[09:59:47.749] <TB3> INFO: empty events: 0
[09:59:47.749] <TB3> INFO: valid events with pixels: 0
[09:59:47.749] <TB3> INFO: valid pixel hits: 0
[09:59:47.749] <TB3> INFO: Event errors: 0
[09:59:47.749] <TB3> INFO: start marker: 0
[09:59:47.749] <TB3> INFO: stop marker: 0
[09:59:47.749] <TB3> INFO: overflow: 0
[09:59:47.749] <TB3> INFO: invalid 5bit words: 0
[09:59:47.749] <TB3> INFO: invalid XOR eye diagram: 0
[09:59:47.749] <TB3> INFO: frame (failed synchr.): 0
[09:59:47.749] <TB3> INFO: idle data (no TBM trl): 0
[09:59:47.749] <TB3> INFO: no data (only TBM hdr): 0
[09:59:47.749] <TB3> INFO: TBM errors: 0
[09:59:47.749] <TB3> INFO: flawed TBM headers: 0
[09:59:47.749] <TB3> INFO: flawed TBM trailers: 0
[09:59:47.749] <TB3> INFO: event ID mismatches: 0
[09:59:47.749] <TB3> INFO: ROC errors: 0
[09:59:47.749] <TB3> INFO: missing ROC header(s): 0
[09:59:47.749] <TB3> INFO: misplaced readback start: 0
[09:59:47.749] <TB3> INFO: Pixel decoding errors: 0
[09:59:47.749] <TB3> INFO: pixel data incomplete: 0
[09:59:47.749] <TB3> INFO: pixel address: 0
[09:59:47.749] <TB3> INFO: pulse height fill bit: 0
[09:59:47.749] <TB3> INFO: buffer corruption: 0
[09:59:47.785] <TB3> INFO: ######################################################################
[09:59:47.785] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[09:59:47.785] <TB3> INFO: ######################################################################
[09:59:47.786] <TB3> INFO: ----------------------------------------------------------------------
[09:59:47.786] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[09:59:47.786] <TB3> INFO: ----------------------------------------------------------------------
[09:59:47.786] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[09:59:47.800] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[09:59:47.801] <TB3> INFO: run 1 of 1
[09:59:48.096] <TB3> INFO: Expecting 36608000 events.
[10:00:12.901] <TB3> INFO: 710600 events read in total (24214ms).
[10:00:36.785] <TB3> INFO: 1398850 events read in total (48098ms).
[10:01:00.397] <TB3> INFO: 2088150 events read in total (71710ms).
[10:01:24.269] <TB3> INFO: 2774200 events read in total (95582ms).
[10:01:48.236] <TB3> INFO: 3462450 events read in total (119549ms).
[10:02:12.065] <TB3> INFO: 4147350 events read in total (143378ms).
[10:02:35.917] <TB3> INFO: 4834900 events read in total (167230ms).
[10:02:59.693] <TB3> INFO: 5519500 events read in total (191006ms).
[10:03:23.397] <TB3> INFO: 6204350 events read in total (214710ms).
[10:03:47.415] <TB3> INFO: 6889500 events read in total (238728ms).
[10:04:11.835] <TB3> INFO: 7574100 events read in total (263148ms).
[10:04:35.435] <TB3> INFO: 8256850 events read in total (286748ms).
[10:04:59.320] <TB3> INFO: 8939600 events read in total (310633ms).
[10:05:23.139] <TB3> INFO: 9623400 events read in total (334452ms).
[10:05:47.140] <TB3> INFO: 10306200 events read in total (358453ms).
[10:06:10.949] <TB3> INFO: 10989700 events read in total (382262ms).
[10:06:34.618] <TB3> INFO: 11672400 events read in total (405931ms).
[10:06:58.508] <TB3> INFO: 12353550 events read in total (429821ms).
[10:07:22.199] <TB3> INFO: 13035300 events read in total (453512ms).
[10:07:45.899] <TB3> INFO: 13718000 events read in total (477212ms).
[10:08:09.861] <TB3> INFO: 14398250 events read in total (501174ms).
[10:08:33.864] <TB3> INFO: 15081050 events read in total (525177ms).
[10:08:57.580] <TB3> INFO: 15760450 events read in total (548893ms).
[10:09:21.346] <TB3> INFO: 16440850 events read in total (572659ms).
[10:09:45.381] <TB3> INFO: 17120650 events read in total (596694ms).
[10:10:09.285] <TB3> INFO: 17800800 events read in total (620598ms).
[10:10:32.976] <TB3> INFO: 18478550 events read in total (644289ms).
[10:10:56.490] <TB3> INFO: 19156650 events read in total (667803ms).
[10:11:20.078] <TB3> INFO: 19832150 events read in total (691391ms).
[10:11:44.061] <TB3> INFO: 20509800 events read in total (715374ms).
[10:12:08.154] <TB3> INFO: 21186800 events read in total (739467ms).
[10:12:32.134] <TB3> INFO: 21864200 events read in total (763447ms).
[10:12:55.909] <TB3> INFO: 22539700 events read in total (787222ms).
[10:13:19.394] <TB3> INFO: 23217300 events read in total (810707ms).
[10:13:43.449] <TB3> INFO: 23892500 events read in total (834762ms).
[10:14:07.003] <TB3> INFO: 24567750 events read in total (858316ms).
[10:14:30.495] <TB3> INFO: 25243450 events read in total (881808ms).
[10:14:54.216] <TB3> INFO: 25919100 events read in total (905529ms).
[10:15:18.103] <TB3> INFO: 26592800 events read in total (929416ms).
[10:15:42.085] <TB3> INFO: 27268350 events read in total (953398ms).
[10:16:05.848] <TB3> INFO: 27941850 events read in total (977161ms).
[10:16:29.710] <TB3> INFO: 28615950 events read in total (1001023ms).
[10:16:53.666] <TB3> INFO: 29291000 events read in total (1024979ms).
[10:17:17.642] <TB3> INFO: 29963300 events read in total (1048955ms).
[10:17:41.676] <TB3> INFO: 30638600 events read in total (1072989ms).
[10:18:04.848] <TB3> INFO: 31312250 events read in total (1096161ms).
[10:18:28.866] <TB3> INFO: 31986650 events read in total (1120179ms).
[10:18:52.939] <TB3> INFO: 32662050 events read in total (1144252ms).
[10:19:17.175] <TB3> INFO: 33339200 events read in total (1168488ms).
[10:19:41.162] <TB3> INFO: 34017900 events read in total (1192475ms).
[10:20:05.160] <TB3> INFO: 34695950 events read in total (1216473ms).
[10:20:28.923] <TB3> INFO: 35372800 events read in total (1240236ms).
[10:20:53.233] <TB3> INFO: 36052650 events read in total (1264546ms).
[10:21:12.422] <TB3> INFO: 36608000 events read in total (1283735ms).
[10:21:12.490] <TB3> INFO: Test took 1284689ms.
[10:21:12.826] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:14.287] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:15.674] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:17.112] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:18.530] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:19.922] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:21.310] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:22.732] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:24.127] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:25.531] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:26.932] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:28.311] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:29.746] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:31.157] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:32.549] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:33.995] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[10:21:35.416] <TB3> INFO: PixTestScurves::scurves() done
[10:21:35.416] <TB3> INFO: Vcal mean: 133.33 123.57 140.00 130.95 125.29 125.11 118.99 121.93 124.67 128.59 134.28 133.68 127.67 116.19 131.01 125.29
[10:21:35.416] <TB3> INFO: Vcal RMS: 6.45 6.53 8.21 9.19 6.50 6.06 5.91 5.98 5.93 5.74 6.33 6.49 6.06 6.02 6.38 6.44
[10:21:35.416] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1307 seconds
[10:21:35.416] <TB3> INFO: Decoding statistics:
[10:21:35.416] <TB3> INFO: General information:
[10:21:35.416] <TB3> INFO: 16bit words read: 0
[10:21:35.416] <TB3> INFO: valid events total: 0
[10:21:35.416] <TB3> INFO: empty events: 0
[10:21:35.416] <TB3> INFO: valid events with pixels: 0
[10:21:35.416] <TB3> INFO: valid pixel hits: 0
[10:21:35.416] <TB3> INFO: Event errors: 0
[10:21:35.416] <TB3> INFO: start marker: 0
[10:21:35.416] <TB3> INFO: stop marker: 0
[10:21:35.416] <TB3> INFO: overflow: 0
[10:21:35.416] <TB3> INFO: invalid 5bit words: 0
[10:21:35.416] <TB3> INFO: invalid XOR eye diagram: 0
[10:21:35.416] <TB3> INFO: frame (failed synchr.): 0
[10:21:35.416] <TB3> INFO: idle data (no TBM trl): 0
[10:21:35.416] <TB3> INFO: no data (only TBM hdr): 0
[10:21:35.416] <TB3> INFO: TBM errors: 0
[10:21:35.416] <TB3> INFO: flawed TBM headers: 0
[10:21:35.416] <TB3> INFO: flawed TBM trailers: 0
[10:21:35.417] <TB3> INFO: event ID mismatches: 0
[10:21:35.417] <TB3> INFO: ROC errors: 0
[10:21:35.417] <TB3> INFO: missing ROC header(s): 0
[10:21:35.417] <TB3> INFO: misplaced readback start: 0
[10:21:35.417] <TB3> INFO: Pixel decoding errors: 0
[10:21:35.417] <TB3> INFO: pixel data incomplete: 0
[10:21:35.417] <TB3> INFO: pixel address: 0
[10:21:35.417] <TB3> INFO: pulse height fill bit: 0
[10:21:35.417] <TB3> INFO: buffer corruption: 0
[10:21:35.482] <TB3> INFO: ######################################################################
[10:21:35.482] <TB3> INFO: PixTestTrim::doTest()
[10:21:35.482] <TB3> INFO: ######################################################################
[10:21:35.483] <TB3> INFO: ----------------------------------------------------------------------
[10:21:35.483] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[10:21:35.483] <TB3> INFO: ----------------------------------------------------------------------
[10:21:35.551] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[10:21:35.551] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[10:21:35.565] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[10:21:35.565] <TB3> INFO: run 1 of 1
[10:21:35.860] <TB3> INFO: Expecting 5025280 events.
[10:22:07.728] <TB3> INFO: 830416 events read in total (31266ms).
[10:22:38.969] <TB3> INFO: 1658352 events read in total (62507ms).
[10:23:09.936] <TB3> INFO: 2484088 events read in total (93474ms).
[10:23:40.779] <TB3> INFO: 3306240 events read in total (124317ms).
[10:24:11.762] <TB3> INFO: 4124736 events read in total (155300ms).
[10:24:43.167] <TB3> INFO: 4943336 events read in total (186705ms).
[10:24:46.609] <TB3> INFO: 5025280 events read in total (190147ms).
[10:24:46.675] <TB3> INFO: Test took 191110ms.
[10:25:00.865] <TB3> INFO: ROC 0 VthrComp = 133
[10:25:00.865] <TB3> INFO: ROC 1 VthrComp = 122
[10:25:00.866] <TB3> INFO: ROC 2 VthrComp = 129
[10:25:00.866] <TB3> INFO: ROC 3 VthrComp = 118
[10:25:00.866] <TB3> INFO: ROC 4 VthrComp = 126
[10:25:00.866] <TB3> INFO: ROC 5 VthrComp = 120
[10:25:00.866] <TB3> INFO: ROC 6 VthrComp = 116
[10:25:00.866] <TB3> INFO: ROC 7 VthrComp = 126
[10:25:00.866] <TB3> INFO: ROC 8 VthrComp = 130
[10:25:00.866] <TB3> INFO: ROC 9 VthrComp = 130
[10:25:00.866] <TB3> INFO: ROC 10 VthrComp = 126
[10:25:00.866] <TB3> INFO: ROC 11 VthrComp = 130
[10:25:00.866] <TB3> INFO: ROC 12 VthrComp = 128
[10:25:00.866] <TB3> INFO: ROC 13 VthrComp = 116
[10:25:00.867] <TB3> INFO: ROC 14 VthrComp = 118
[10:25:00.867] <TB3> INFO: ROC 15 VthrComp = 120
[10:25:01.104] <TB3> INFO: Expecting 41600 events.
[10:25:04.605] <TB3> INFO: 41600 events read in total (2909ms).
[10:25:04.606] <TB3> INFO: Test took 3738ms.
[10:25:04.619] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[10:25:04.619] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[10:25:04.633] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[10:25:04.633] <TB3> INFO: run 1 of 1
[10:25:04.911] <TB3> INFO: Expecting 5025280 events.
[10:25:31.980] <TB3> INFO: 592792 events read in total (26477ms).
[10:25:58.378] <TB3> INFO: 1184168 events read in total (52875ms).
[10:26:24.545] <TB3> INFO: 1775336 events read in total (79042ms).
[10:26:50.589] <TB3> INFO: 2366248 events read in total (105086ms).
[10:27:16.637] <TB3> INFO: 2955112 events read in total (131134ms).
[10:27:43.508] <TB3> INFO: 3542416 events read in total (158005ms).
[10:28:09.369] <TB3> INFO: 4128320 events read in total (183866ms).
[10:28:35.870] <TB3> INFO: 4714416 events read in total (210367ms).
[10:28:50.263] <TB3> INFO: 5025280 events read in total (224760ms).
[10:28:50.338] <TB3> INFO: Test took 225704ms.
[10:29:11.488] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 65.5467 for pixel 18/14 mean/min/max = 48.7192/31.7942/65.6442
[10:29:11.489] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 62.3896 for pixel 15/78 mean/min/max = 47.263/31.9211/62.6049
[10:29:11.489] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 75.7603 for pixel 0/76 mean/min/max = 53.8533/31.873/75.8336
[10:29:11.490] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 70.6809 for pixel 23/7 mean/min/max = 50.929/30.9142/70.9438
[10:29:11.490] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 60.7386 for pixel 9/0 mean/min/max = 45.3956/29.951/60.8401
[10:29:11.491] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 62.6903 for pixel 49/9 mean/min/max = 47.8544/32.7428/62.9659
[10:29:11.491] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 63.4632 for pixel 7/3 mean/min/max = 47.2971/30.9994/63.5948
[10:29:11.492] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 58.37 for pixel 36/5 mean/min/max = 45.2426/31.9922/58.4931
[10:29:11.492] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 59.7098 for pixel 35/9 mean/min/max = 46.6524/33.3846/59.9203
[10:29:11.492] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 61.8525 for pixel 25/7 mean/min/max = 46.311/30.699/61.9231
[10:29:11.493] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 64.3889 for pixel 51/23 mean/min/max = 48.8101/32.9154/64.7048
[10:29:11.493] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 62.68 for pixel 42/2 mean/min/max = 47.7553/32.8088/62.7019
[10:29:11.494] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 61.4161 for pixel 11/4 mean/min/max = 46.6814/31.8966/61.4662
[10:29:11.494] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 59.9145 for pixel 3/21 mean/min/max = 46.2435/32.3572/60.1298
[10:29:11.495] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 66.4476 for pixel 0/14 mean/min/max = 49.9256/32.7988/67.0525
[10:29:11.495] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 62.4824 for pixel 6/4 mean/min/max = 47.6877/32.8496/62.5257
[10:29:11.495] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[10:29:11.584] <TB3> INFO: Expecting 411648 events.
[10:29:21.376] <TB3> INFO: 411648 events read in total (9200ms).
[10:29:21.384] <TB3> INFO: Expecting 411648 events.
[10:29:30.870] <TB3> INFO: 411648 events read in total (9083ms).
[10:29:30.883] <TB3> INFO: Expecting 411648 events.
[10:29:40.351] <TB3> INFO: 411648 events read in total (9065ms).
[10:29:40.363] <TB3> INFO: Expecting 411648 events.
[10:29:49.958] <TB3> INFO: 411648 events read in total (9192ms).
[10:29:49.979] <TB3> INFO: Expecting 411648 events.
[10:29:59.430] <TB3> INFO: 411648 events read in total (9048ms).
[10:29:59.455] <TB3> INFO: Expecting 411648 events.
[10:30:08.987] <TB3> INFO: 411648 events read in total (9129ms).
[10:30:09.008] <TB3> INFO: Expecting 411648 events.
[10:30:18.596] <TB3> INFO: 411648 events read in total (9185ms).
[10:30:18.629] <TB3> INFO: Expecting 411648 events.
[10:30:28.259] <TB3> INFO: 411648 events read in total (9227ms).
[10:30:28.296] <TB3> INFO: Expecting 411648 events.
[10:30:37.896] <TB3> INFO: 411648 events read in total (9197ms).
[10:30:37.926] <TB3> INFO: Expecting 411648 events.
[10:30:47.505] <TB3> INFO: 411648 events read in total (9176ms).
[10:30:47.551] <TB3> INFO: Expecting 411648 events.
[10:30:57.158] <TB3> INFO: 411648 events read in total (9204ms).
[10:30:57.193] <TB3> INFO: Expecting 411648 events.
[10:31:06.751] <TB3> INFO: 411648 events read in total (9155ms).
[10:31:06.789] <TB3> INFO: Expecting 411648 events.
[10:31:16.354] <TB3> INFO: 411648 events read in total (9163ms).
[10:31:16.395] <TB3> INFO: Expecting 411648 events.
[10:31:25.947] <TB3> INFO: 411648 events read in total (9149ms).
[10:31:25.989] <TB3> INFO: Expecting 411648 events.
[10:31:35.475] <TB3> INFO: 411648 events read in total (9082ms).
[10:31:35.540] <TB3> INFO: Expecting 411648 events.
[10:31:44.815] <TB3> INFO: 411648 events read in total (8872ms).
[10:31:44.868] <TB3> INFO: Test took 153373ms.
[10:31:45.494] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[10:31:45.508] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[10:31:45.508] <TB3> INFO: run 1 of 1
[10:31:45.746] <TB3> INFO: Expecting 5025280 events.
[10:32:13.240] <TB3> INFO: 592624 events read in total (26903ms).
[10:32:40.131] <TB3> INFO: 1184232 events read in total (53794ms).
[10:33:06.832] <TB3> INFO: 1777168 events read in total (80496ms).
[10:33:33.806] <TB3> INFO: 2367616 events read in total (107469ms).
[10:34:00.657] <TB3> INFO: 2958808 events read in total (134320ms).
[10:34:28.042] <TB3> INFO: 3553192 events read in total (161705ms).
[10:34:54.882] <TB3> INFO: 4149192 events read in total (188545ms).
[10:35:22.066] <TB3> INFO: 4740336 events read in total (215730ms).
[10:35:35.892] <TB3> INFO: 5025280 events read in total (229555ms).
[10:35:36.045] <TB3> INFO: Test took 230538ms.
[10:35:54.693] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 5.186133 .. 146.744855
[10:35:54.930] <TB3> INFO: Expecting 208000 events.
[10:36:04.574] <TB3> INFO: 208000 events read in total (9053ms).
[10:36:04.576] <TB3> INFO: Test took 9882ms.
[10:36:04.654] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 5 .. 156 (-1/-1) hits flags = 528 (plus default)
[10:36:04.668] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[10:36:04.668] <TB3> INFO: run 1 of 1
[10:36:04.964] <TB3> INFO: Expecting 5058560 events.
[10:36:31.941] <TB3> INFO: 579992 events read in total (26386ms).
[10:36:58.748] <TB3> INFO: 1159840 events read in total (53194ms).
[10:37:24.875] <TB3> INFO: 1739192 events read in total (79321ms).
[10:37:51.787] <TB3> INFO: 2318440 events read in total (106232ms).
[10:38:18.348] <TB3> INFO: 2898000 events read in total (132793ms).
[10:38:45.245] <TB3> INFO: 3476360 events read in total (159690ms).
[10:39:12.099] <TB3> INFO: 4055304 events read in total (186544ms).
[10:39:39.424] <TB3> INFO: 4632856 events read in total (213869ms).
[10:39:59.129] <TB3> INFO: 5058560 events read in total (233575ms).
[10:39:59.238] <TB3> INFO: Test took 234572ms.
[10:40:20.742] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 26.597129 .. 47.229634
[10:40:20.980] <TB3> INFO: Expecting 208000 events.
[10:40:30.744] <TB3> INFO: 208000 events read in total (9172ms).
[10:40:30.745] <TB3> INFO: Test took 10002ms.
[10:40:30.792] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 57 (-1/-1) hits flags = 528 (plus default)
[10:40:30.806] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[10:40:30.806] <TB3> INFO: run 1 of 1
[10:40:31.084] <TB3> INFO: Expecting 1397760 events.
[10:41:00.105] <TB3> INFO: 659032 events read in total (28429ms).
[10:41:28.728] <TB3> INFO: 1315048 events read in total (57053ms).
[10:41:32.904] <TB3> INFO: 1397760 events read in total (61229ms).
[10:41:32.951] <TB3> INFO: Test took 62146ms.
[10:41:45.176] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 27.220263 .. 54.398499
[10:41:45.418] <TB3> INFO: Expecting 208000 events.
[10:41:55.502] <TB3> INFO: 208000 events read in total (9492ms).
[10:41:55.502] <TB3> INFO: Test took 10324ms.
[10:41:55.549] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 17 .. 64 (-1/-1) hits flags = 528 (plus default)
[10:41:55.562] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[10:41:55.562] <TB3> INFO: run 1 of 1
[10:41:55.858] <TB3> INFO: Expecting 1597440 events.
[10:42:24.179] <TB3> INFO: 632480 events read in total (27729ms).
[10:42:53.045] <TB3> INFO: 1263960 events read in total (56596ms).
[10:43:08.467] <TB3> INFO: 1597440 events read in total (72017ms).
[10:43:08.518] <TB3> INFO: Test took 72957ms.
[10:43:21.341] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 26.388534 .. 61.598537
[10:43:21.581] <TB3> INFO: Expecting 208000 events.
[10:43:31.490] <TB3> INFO: 208000 events read in total (9317ms).
[10:43:31.492] <TB3> INFO: Test took 10149ms.
[10:43:31.572] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 16 .. 71 (-1/-1) hits flags = 528 (plus default)
[10:43:31.586] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[10:43:31.586] <TB3> INFO: run 1 of 1
[10:43:31.884] <TB3> INFO: Expecting 1863680 events.
[10:44:00.313] <TB3> INFO: 619816 events read in total (27837ms).
[10:44:27.963] <TB3> INFO: 1239416 events read in total (55488ms).
[10:44:55.865] <TB3> INFO: 1858840 events read in total (83390ms).
[10:44:56.499] <TB3> INFO: 1863680 events read in total (84023ms).
[10:44:56.537] <TB3> INFO: Test took 84951ms.
[10:45:10.395] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[10:45:10.395] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[10:45:10.408] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[10:45:10.408] <TB3> INFO: run 1 of 1
[10:45:10.644] <TB3> INFO: Expecting 1364480 events.
[10:45:40.470] <TB3> INFO: 667832 events read in total (29235ms).
[10:46:09.491] <TB3> INFO: 1335472 events read in total (58256ms).
[10:46:11.294] <TB3> INFO: 1364480 events read in total (60060ms).
[10:46:11.339] <TB3> INFO: Test took 60932ms.
[10:46:23.408] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C0.dat
[10:46:23.408] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C1.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C2.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C3.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C4.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C5.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C6.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C7.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C8.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C9.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C10.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C11.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C12.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C13.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C14.dat
[10:46:23.409] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C15.dat
[10:46:23.409] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C0.dat
[10:46:23.414] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C1.dat
[10:46:23.419] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C2.dat
[10:46:23.423] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C3.dat
[10:46:23.428] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C4.dat
[10:46:23.433] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C5.dat
[10:46:23.438] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C6.dat
[10:46:23.442] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C7.dat
[10:46:23.447] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C8.dat
[10:46:23.452] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C9.dat
[10:46:23.457] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C10.dat
[10:46:23.462] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C11.dat
[10:46:23.466] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C12.dat
[10:46:23.471] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C13.dat
[10:46:23.476] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C14.dat
[10:46:23.481] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//trimParameters35_C15.dat
[10:46:23.485] <TB3> INFO: PixTestTrim::trimTest() done
[10:46:23.485] <TB3> INFO: vtrim: 155 123 155 144 124 144 139 140 138 146 128 132 134 119 116 130
[10:46:23.486] <TB3> INFO: vthrcomp: 133 122 129 118 126 120 116 126 130 130 126 130 128 116 118 120
[10:46:23.486] <TB3> INFO: vcal mean: 35.61 35.20 35.74 39.08 34.94 35.02 34.98 34.80 35.00 35.15 35.47 35.75 35.11 35.02 36.47 35.28
[10:46:23.486] <TB3> INFO: vcal RMS: 1.68 1.38 2.05 4.26 1.20 1.12 1.11 1.08 1.02 1.45 1.67 1.90 1.28 1.01 2.60 1.48
[10:46:23.486] <TB3> INFO: bits mean: 9.49 9.38 8.11 11.02 9.89 9.59 9.94 9.71 9.44 10.06 9.01 9.64 9.66 9.48 9.30 9.38
[10:46:23.486] <TB3> INFO: bits RMS: 2.69 2.73 3.03 2.37 2.81 2.47 2.51 2.67 2.52 2.67 2.83 2.65 2.63 2.65 2.93 2.60
[10:46:23.493] <TB3> INFO: ----------------------------------------------------------------------
[10:46:23.493] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[10:46:23.493] <TB3> INFO: ----------------------------------------------------------------------
[10:46:23.496] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[10:46:23.508] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[10:46:23.508] <TB3> INFO: run 1 of 1
[10:46:23.744] <TB3> INFO: Expecting 4160000 events.
[10:46:58.390] <TB3> INFO: 778940 events read in total (34054ms).
[10:47:32.149] <TB3> INFO: 1549280 events read in total (67813ms).
[10:48:05.982] <TB3> INFO: 2314280 events read in total (101647ms).
[10:48:38.921] <TB3> INFO: 3075840 events read in total (134585ms).
[10:49:12.104] <TB3> INFO: 3834215 events read in total (167768ms).
[10:49:26.445] <TB3> INFO: 4160000 events read in total (182109ms).
[10:49:26.511] <TB3> INFO: Test took 183002ms.
[10:49:47.869] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[10:49:47.880] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[10:49:47.880] <TB3> INFO: run 1 of 1
[10:49:48.120] <TB3> INFO: Expecting 5324800 events.
[10:50:20.184] <TB3> INFO: 690730 events read in total (31472ms).
[10:50:51.834] <TB3> INFO: 1376740 events read in total (63122ms).
[10:51:23.199] <TB3> INFO: 2061320 events read in total (94487ms).
[10:51:54.590] <TB3> INFO: 2743850 events read in total (125878ms).
[10:52:25.861] <TB3> INFO: 3424110 events read in total (157149ms).
[10:52:58.111] <TB3> INFO: 4103305 events read in total (189399ms).
[10:53:28.938] <TB3> INFO: 4780670 events read in total (220226ms).
[10:53:53.853] <TB3> INFO: 5324800 events read in total (245141ms).
[10:53:53.978] <TB3> INFO: Test took 246098ms.
[10:54:21.374] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[10:54:21.387] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[10:54:21.387] <TB3> INFO: run 1 of 1
[10:54:21.631] <TB3> INFO: Expecting 5324800 events.
[10:54:53.887] <TB3> INFO: 690945 events read in total (31665ms).
[10:55:25.279] <TB3> INFO: 1377150 events read in total (63057ms).
[10:55:56.523] <TB3> INFO: 2062040 events read in total (94301ms).
[10:56:27.667] <TB3> INFO: 2745000 events read in total (125445ms).
[10:56:58.536] <TB3> INFO: 3425605 events read in total (156314ms).
[10:57:29.609] <TB3> INFO: 4105010 events read in total (187387ms).
[10:58:00.591] <TB3> INFO: 4782875 events read in total (218369ms).
[10:58:25.584] <TB3> INFO: 5324800 events read in total (243362ms).
[10:58:25.684] <TB3> INFO: Test took 244297ms.
[10:58:52.887] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[10:58:52.899] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[10:58:52.899] <TB3> INFO: run 1 of 1
[10:58:53.135] <TB3> INFO: Expecting 5324800 events.
[10:59:25.237] <TB3> INFO: 691130 events read in total (31511ms).
[10:59:56.854] <TB3> INFO: 1377670 events read in total (63128ms).
[11:00:28.303] <TB3> INFO: 2062880 events read in total (94577ms).
[11:00:59.845] <TB3> INFO: 2745605 events read in total (126119ms).
[11:01:31.083] <TB3> INFO: 3426355 events read in total (157357ms).
[11:02:02.528] <TB3> INFO: 4105900 events read in total (188802ms).
[11:02:33.743] <TB3> INFO: 4783650 events read in total (220017ms).
[11:02:58.501] <TB3> INFO: 5324800 events read in total (244776ms).
[11:02:58.603] <TB3> INFO: Test took 245703ms.
[11:03:28.050] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 221 (-1/-1) hits flags = 528 (plus default)
[11:03:28.063] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:03:28.063] <TB3> INFO: run 1 of 1
[11:03:28.299] <TB3> INFO: Expecting 4617600 events.
[11:04:01.625] <TB3> INFO: 723955 events read in total (32734ms).
[11:04:33.685] <TB3> INFO: 1442135 events read in total (64794ms).
[11:05:06.135] <TB3> INFO: 2157625 events read in total (97244ms).
[11:05:37.001] <TB3> INFO: 2870020 events read in total (129110ms).
[11:06:10.132] <TB3> INFO: 3579715 events read in total (161241ms).
[11:06:42.129] <TB3> INFO: 4288070 events read in total (193238ms).
[11:06:57.150] <TB3> INFO: 4617600 events read in total (208259ms).
[11:06:57.271] <TB3> INFO: Test took 209208ms.
[11:07:22.041] <TB3> INFO: PixTestTrim::trimBitTest() done
[11:07:22.042] <TB3> INFO: PixTestTrim::doTest() done, duration: 2746 seconds
[11:07:22.042] <TB3> INFO: Decoding statistics:
[11:07:22.042] <TB3> INFO: General information:
[11:07:22.042] <TB3> INFO: 16bit words read: 0
[11:07:22.042] <TB3> INFO: valid events total: 0
[11:07:22.042] <TB3> INFO: empty events: 0
[11:07:22.042] <TB3> INFO: valid events with pixels: 0
[11:07:22.042] <TB3> INFO: valid pixel hits: 0
[11:07:22.042] <TB3> INFO: Event errors: 0
[11:07:22.042] <TB3> INFO: start marker: 0
[11:07:22.042] <TB3> INFO: stop marker: 0
[11:07:22.042] <TB3> INFO: overflow: 0
[11:07:22.042] <TB3> INFO: invalid 5bit words: 0
[11:07:22.042] <TB3> INFO: invalid XOR eye diagram: 0
[11:07:22.042] <TB3> INFO: frame (failed synchr.): 0
[11:07:22.042] <TB3> INFO: idle data (no TBM trl): 0
[11:07:22.042] <TB3> INFO: no data (only TBM hdr): 0
[11:07:22.042] <TB3> INFO: TBM errors: 0
[11:07:22.042] <TB3> INFO: flawed TBM headers: 0
[11:07:22.042] <TB3> INFO: flawed TBM trailers: 0
[11:07:22.042] <TB3> INFO: event ID mismatches: 0
[11:07:22.042] <TB3> INFO: ROC errors: 0
[11:07:22.042] <TB3> INFO: missing ROC header(s): 0
[11:07:22.042] <TB3> INFO: misplaced readback start: 0
[11:07:22.042] <TB3> INFO: Pixel decoding errors: 0
[11:07:22.042] <TB3> INFO: pixel data incomplete: 0
[11:07:22.042] <TB3> INFO: pixel address: 0
[11:07:22.042] <TB3> INFO: pulse height fill bit: 0
[11:07:22.042] <TB3> INFO: buffer corruption: 0
[11:07:22.638] <TB3> INFO: ######################################################################
[11:07:22.638] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[11:07:22.638] <TB3> INFO: ######################################################################
[11:07:22.874] <TB3> INFO: Expecting 41600 events.
[11:07:26.349] <TB3> INFO: 41600 events read in total (2883ms).
[11:07:26.350] <TB3> INFO: Test took 3711ms.
[11:07:26.788] <TB3> INFO: Expecting 41600 events.
[11:07:30.375] <TB3> INFO: 41600 events read in total (2996ms).
[11:07:30.376] <TB3> INFO: Test took 3824ms.
[11:07:30.667] <TB3> INFO: Expecting 41600 events.
[11:07:34.299] <TB3> INFO: 41600 events read in total (3041ms).
[11:07:34.300] <TB3> INFO: Test took 3900ms.
[11:07:34.588] <TB3> INFO: Expecting 41600 events.
[11:07:38.249] <TB3> INFO: 41600 events read in total (3069ms).
[11:07:38.250] <TB3> INFO: Test took 3927ms.
[11:07:38.539] <TB3> INFO: Expecting 41600 events.
[11:07:42.147] <TB3> INFO: 41600 events read in total (3016ms).
[11:07:42.148] <TB3> INFO: Test took 3874ms.
[11:07:42.440] <TB3> INFO: Expecting 41600 events.
[11:07:45.958] <TB3> INFO: 41600 events read in total (2926ms).
[11:07:45.959] <TB3> INFO: Test took 3784ms.
[11:07:46.247] <TB3> INFO: Expecting 41600 events.
[11:07:49.888] <TB3> INFO: 41600 events read in total (3049ms).
[11:07:49.889] <TB3> INFO: Test took 3907ms.
[11:07:50.178] <TB3> INFO: Expecting 41600 events.
[11:07:53.681] <TB3> INFO: 41600 events read in total (2911ms).
[11:07:53.682] <TB3> INFO: Test took 3769ms.
[11:07:54.012] <TB3> INFO: Expecting 41600 events.
[11:07:57.643] <TB3> INFO: 41600 events read in total (3040ms).
[11:07:57.644] <TB3> INFO: Test took 3937ms.
[11:07:57.932] <TB3> INFO: Expecting 41600 events.
[11:08:01.517] <TB3> INFO: 41600 events read in total (2993ms).
[11:08:01.518] <TB3> INFO: Test took 3850ms.
[11:08:01.811] <TB3> INFO: Expecting 41600 events.
[11:08:05.366] <TB3> INFO: 41600 events read in total (2963ms).
[11:08:05.367] <TB3> INFO: Test took 3821ms.
[11:08:05.655] <TB3> INFO: Expecting 41600 events.
[11:08:09.155] <TB3> INFO: 41600 events read in total (2908ms).
[11:08:09.156] <TB3> INFO: Test took 3766ms.
[11:08:09.445] <TB3> INFO: Expecting 41600 events.
[11:08:13.104] <TB3> INFO: 41600 events read in total (3067ms).
[11:08:13.105] <TB3> INFO: Test took 3925ms.
[11:08:13.422] <TB3> INFO: Expecting 41600 events.
[11:08:16.960] <TB3> INFO: 41600 events read in total (2946ms).
[11:08:16.960] <TB3> INFO: Test took 3832ms.
[11:08:17.253] <TB3> INFO: Expecting 41600 events.
[11:08:20.871] <TB3> INFO: 41600 events read in total (3026ms).
[11:08:20.872] <TB3> INFO: Test took 3884ms.
[11:08:21.160] <TB3> INFO: Expecting 41600 events.
[11:08:24.702] <TB3> INFO: 41600 events read in total (2950ms).
[11:08:24.703] <TB3> INFO: Test took 3808ms.
[11:08:24.991] <TB3> INFO: Expecting 41600 events.
[11:08:28.540] <TB3> INFO: 41600 events read in total (2957ms).
[11:08:28.541] <TB3> INFO: Test took 3815ms.
[11:08:28.830] <TB3> INFO: Expecting 41600 events.
[11:08:32.351] <TB3> INFO: 41600 events read in total (2929ms).
[11:08:32.351] <TB3> INFO: Test took 3786ms.
[11:08:32.640] <TB3> INFO: Expecting 41600 events.
[11:08:36.197] <TB3> INFO: 41600 events read in total (2965ms).
[11:08:36.198] <TB3> INFO: Test took 3823ms.
[11:08:36.487] <TB3> INFO: Expecting 41600 events.
[11:08:40.189] <TB3> INFO: 41600 events read in total (3110ms).
[11:08:40.190] <TB3> INFO: Test took 3968ms.
[11:08:40.519] <TB3> INFO: Expecting 41600 events.
[11:08:44.171] <TB3> INFO: 41600 events read in total (3061ms).
[11:08:44.172] <TB3> INFO: Test took 3954ms.
[11:08:44.465] <TB3> INFO: Expecting 41600 events.
[11:08:48.107] <TB3> INFO: 41600 events read in total (3051ms).
[11:08:48.108] <TB3> INFO: Test took 3908ms.
[11:08:48.397] <TB3> INFO: Expecting 41600 events.
[11:08:52.133] <TB3> INFO: 41600 events read in total (3145ms).
[11:08:52.134] <TB3> INFO: Test took 4003ms.
[11:08:52.422] <TB3> INFO: Expecting 41600 events.
[11:08:55.937] <TB3> INFO: 41600 events read in total (2923ms).
[11:08:55.938] <TB3> INFO: Test took 3780ms.
[11:08:56.243] <TB3> INFO: Expecting 41600 events.
[11:08:59.864] <TB3> INFO: 41600 events read in total (3029ms).
[11:08:59.865] <TB3> INFO: Test took 3904ms.
[11:09:00.157] <TB3> INFO: Expecting 41600 events.
[11:09:03.815] <TB3> INFO: 41600 events read in total (3066ms).
[11:09:03.816] <TB3> INFO: Test took 3924ms.
[11:09:04.104] <TB3> INFO: Expecting 41600 events.
[11:09:07.678] <TB3> INFO: 41600 events read in total (2982ms).
[11:09:07.679] <TB3> INFO: Test took 3840ms.
[11:09:08.011] <TB3> INFO: Expecting 41600 events.
[11:09:11.682] <TB3> INFO: 41600 events read in total (3080ms).
[11:09:11.682] <TB3> INFO: Test took 3976ms.
[11:09:12.003] <TB3> INFO: Expecting 41600 events.
[11:09:15.833] <TB3> INFO: 41600 events read in total (3238ms).
[11:09:15.834] <TB3> INFO: Test took 4127ms.
[11:09:16.128] <TB3> INFO: Expecting 2560 events.
[11:09:17.022] <TB3> INFO: 2560 events read in total (303ms).
[11:09:17.022] <TB3> INFO: Test took 1171ms.
[11:09:17.329] <TB3> INFO: Expecting 2560 events.
[11:09:18.218] <TB3> INFO: 2560 events read in total (297ms).
[11:09:18.218] <TB3> INFO: Test took 1195ms.
[11:09:18.526] <TB3> INFO: Expecting 2560 events.
[11:09:19.415] <TB3> INFO: 2560 events read in total (298ms).
[11:09:19.415] <TB3> INFO: Test took 1197ms.
[11:09:19.723] <TB3> INFO: Expecting 2560 events.
[11:09:20.616] <TB3> INFO: 2560 events read in total (301ms).
[11:09:20.617] <TB3> INFO: Test took 1201ms.
[11:09:20.924] <TB3> INFO: Expecting 2560 events.
[11:09:21.804] <TB3> INFO: 2560 events read in total (289ms).
[11:09:21.805] <TB3> INFO: Test took 1188ms.
[11:09:22.113] <TB3> INFO: Expecting 2560 events.
[11:09:22.995] <TB3> INFO: 2560 events read in total (291ms).
[11:09:22.995] <TB3> INFO: Test took 1190ms.
[11:09:23.303] <TB3> INFO: Expecting 2560 events.
[11:09:24.187] <TB3> INFO: 2560 events read in total (292ms).
[11:09:24.187] <TB3> INFO: Test took 1191ms.
[11:09:24.496] <TB3> INFO: Expecting 2560 events.
[11:09:25.381] <TB3> INFO: 2560 events read in total (294ms).
[11:09:25.381] <TB3> INFO: Test took 1193ms.
[11:09:25.689] <TB3> INFO: Expecting 2560 events.
[11:09:26.570] <TB3> INFO: 2560 events read in total (290ms).
[11:09:26.570] <TB3> INFO: Test took 1189ms.
[11:09:26.878] <TB3> INFO: Expecting 2560 events.
[11:09:27.760] <TB3> INFO: 2560 events read in total (291ms).
[11:09:27.762] <TB3> INFO: Test took 1191ms.
[11:09:28.068] <TB3> INFO: Expecting 2560 events.
[11:09:28.948] <TB3> INFO: 2560 events read in total (288ms).
[11:09:28.949] <TB3> INFO: Test took 1187ms.
[11:09:29.257] <TB3> INFO: Expecting 2560 events.
[11:09:30.136] <TB3> INFO: 2560 events read in total (288ms).
[11:09:30.136] <TB3> INFO: Test took 1187ms.
[11:09:30.444] <TB3> INFO: Expecting 2560 events.
[11:09:31.335] <TB3> INFO: 2560 events read in total (299ms).
[11:09:31.335] <TB3> INFO: Test took 1198ms.
[11:09:31.642] <TB3> INFO: Expecting 2560 events.
[11:09:32.532] <TB3> INFO: 2560 events read in total (298ms).
[11:09:32.532] <TB3> INFO: Test took 1196ms.
[11:09:32.840] <TB3> INFO: Expecting 2560 events.
[11:09:33.725] <TB3> INFO: 2560 events read in total (293ms).
[11:09:33.725] <TB3> INFO: Test took 1193ms.
[11:09:34.032] <TB3> INFO: Expecting 2560 events.
[11:09:34.916] <TB3> INFO: 2560 events read in total (293ms).
[11:09:34.917] <TB3> INFO: Test took 1192ms.
[11:09:34.920] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:09:35.226] <TB3> INFO: Expecting 655360 events.
[11:09:50.353] <TB3> INFO: 655360 events read in total (14534ms).
[11:09:50.366] <TB3> INFO: Expecting 655360 events.
[11:10:05.200] <TB3> INFO: 655360 events read in total (14431ms).
[11:10:05.218] <TB3> INFO: Expecting 655360 events.
[11:10:20.023] <TB3> INFO: 655360 events read in total (14402ms).
[11:10:20.051] <TB3> INFO: Expecting 655360 events.
[11:10:34.924] <TB3> INFO: 655360 events read in total (14470ms).
[11:10:34.949] <TB3> INFO: Expecting 655360 events.
[11:10:49.845] <TB3> INFO: 655360 events read in total (14493ms).
[11:10:49.876] <TB3> INFO: Expecting 655360 events.
[11:11:04.966] <TB3> INFO: 655360 events read in total (14687ms).
[11:11:05.018] <TB3> INFO: Expecting 655360 events.
[11:11:19.950] <TB3> INFO: 655360 events read in total (14529ms).
[11:11:19.990] <TB3> INFO: Expecting 655360 events.
[11:11:34.729] <TB3> INFO: 655360 events read in total (14336ms).
[11:11:34.770] <TB3> INFO: Expecting 655360 events.
[11:11:49.616] <TB3> INFO: 655360 events read in total (14443ms).
[11:11:49.702] <TB3> INFO: Expecting 655360 events.
[11:12:04.396] <TB3> INFO: 655360 events read in total (14291ms).
[11:12:04.448] <TB3> INFO: Expecting 655360 events.
[11:12:19.467] <TB3> INFO: 655360 events read in total (14616ms).
[11:12:19.534] <TB3> INFO: Expecting 655360 events.
[11:12:34.386] <TB3> INFO: 655360 events read in total (14449ms).
[11:12:34.454] <TB3> INFO: Expecting 655360 events.
[11:12:49.372] <TB3> INFO: 655360 events read in total (14515ms).
[11:12:49.576] <TB3> INFO: Expecting 655360 events.
[11:13:04.444] <TB3> INFO: 655360 events read in total (14465ms).
[11:13:04.571] <TB3> INFO: Expecting 655360 events.
[11:13:19.392] <TB3> INFO: 655360 events read in total (14418ms).
[11:13:19.484] <TB3> INFO: Expecting 655360 events.
[11:13:34.296] <TB3> INFO: 655360 events read in total (14409ms).
[11:13:34.458] <TB3> INFO: Test took 239538ms.
[11:13:34.560] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:13:34.810] <TB3> INFO: Expecting 655360 events.
[11:13:49.624] <TB3> INFO: 655360 events read in total (14223ms).
[11:13:49.635] <TB3> INFO: Expecting 655360 events.
[11:14:04.532] <TB3> INFO: 655360 events read in total (14494ms).
[11:14:04.547] <TB3> INFO: Expecting 655360 events.
[11:14:19.398] <TB3> INFO: 655360 events read in total (14448ms).
[11:14:19.418] <TB3> INFO: Expecting 655360 events.
[11:14:34.385] <TB3> INFO: 655360 events read in total (14564ms).
[11:14:34.420] <TB3> INFO: Expecting 655360 events.
[11:14:49.315] <TB3> INFO: 655360 events read in total (14492ms).
[11:14:49.344] <TB3> INFO: Expecting 655360 events.
[11:15:04.317] <TB3> INFO: 655360 events read in total (14570ms).
[11:15:04.370] <TB3> INFO: Expecting 655360 events.
[11:15:19.384] <TB3> INFO: 655360 events read in total (14611ms).
[11:15:19.425] <TB3> INFO: Expecting 655360 events.
[11:15:34.305] <TB3> INFO: 655360 events read in total (14477ms).
[11:15:34.348] <TB3> INFO: Expecting 655360 events.
[11:15:48.975] <TB3> INFO: 655360 events read in total (14224ms).
[11:15:49.034] <TB3> INFO: Expecting 655360 events.
[11:16:03.817] <TB3> INFO: 655360 events read in total (14380ms).
[11:16:03.869] <TB3> INFO: Expecting 655360 events.
[11:16:18.771] <TB3> INFO: 655360 events read in total (14499ms).
[11:16:18.841] <TB3> INFO: Expecting 655360 events.
[11:16:33.472] <TB3> INFO: 655360 events read in total (14228ms).
[11:16:33.536] <TB3> INFO: Expecting 655360 events.
[11:16:48.617] <TB3> INFO: 655360 events read in total (14678ms).
[11:16:48.827] <TB3> INFO: Expecting 655360 events.
[11:17:03.687] <TB3> INFO: 655360 events read in total (14457ms).
[11:17:03.772] <TB3> INFO: Expecting 655360 events.
[11:17:18.398] <TB3> INFO: 655360 events read in total (14223ms).
[11:17:18.490] <TB3> INFO: Expecting 655360 events.
[11:17:32.859] <TB3> INFO: 655360 events read in total (13966ms).
[11:17:33.092] <TB3> INFO: Test took 238532ms.
[11:17:33.263] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.269] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[11:17:33.275] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[11:17:33.280] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[11:17:33.286] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[11:17:33.292] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[11:17:33.298] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[11:17:33.304] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[11:17:33.310] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.316] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[11:17:33.322] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[11:17:33.328] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[11:17:33.334] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[11:17:33.340] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[11:17:33.346] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[11:17:33.351] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.357] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.363] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[11:17:33.369] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[11:17:33.375] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[11:17:33.381] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[11:17:33.386] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[11:17:33.392] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[11:17:33.398] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[11:17:33.404] <TB3> INFO: safety margin for low PH: adding 8, margin is now 28
[11:17:33.410] <TB3> INFO: safety margin for low PH: adding 9, margin is now 29
[11:17:33.416] <TB3> INFO: safety margin for low PH: adding 10, margin is now 30
[11:17:33.421] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.427] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.433] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.439] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.445] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.451] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.456] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.462] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.468] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[11:17:33.474] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[11:17:33.480] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[11:17:33.485] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[11:17:33.492] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.497] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.503] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.510] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[11:17:33.516] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[11:17:33.521] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[11:17:33.527] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[11:17:33.533] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[11:17:33.539] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[11:17:33.574] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C0.dat
[11:17:33.574] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C1.dat
[11:17:33.574] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C2.dat
[11:17:33.574] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C3.dat
[11:17:33.574] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C4.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C5.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C6.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C7.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C8.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C9.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C10.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C11.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C12.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C13.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C14.dat
[11:17:33.575] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//dacParameters35_C15.dat
[11:17:33.816] <TB3> INFO: Expecting 41600 events.
[11:17:37.072] <TB3> INFO: 41600 events read in total (2664ms).
[11:17:37.073] <TB3> INFO: Test took 3495ms.
[11:17:37.523] <TB3> INFO: Expecting 41600 events.
[11:17:40.588] <TB3> INFO: 41600 events read in total (2474ms).
[11:17:40.589] <TB3> INFO: Test took 3305ms.
[11:17:41.039] <TB3> INFO: Expecting 41600 events.
[11:17:44.189] <TB3> INFO: 41600 events read in total (2558ms).
[11:17:44.190] <TB3> INFO: Test took 3390ms.
[11:17:44.407] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:44.496] <TB3> INFO: Expecting 2560 events.
[11:17:45.384] <TB3> INFO: 2560 events read in total (296ms).
[11:17:45.384] <TB3> INFO: Test took 977ms.
[11:17:45.386] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:45.692] <TB3> INFO: Expecting 2560 events.
[11:17:46.585] <TB3> INFO: 2560 events read in total (301ms).
[11:17:46.586] <TB3> INFO: Test took 1200ms.
[11:17:46.588] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:46.894] <TB3> INFO: Expecting 2560 events.
[11:17:47.781] <TB3> INFO: 2560 events read in total (295ms).
[11:17:47.781] <TB3> INFO: Test took 1193ms.
[11:17:47.783] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:48.089] <TB3> INFO: Expecting 2560 events.
[11:17:48.976] <TB3> INFO: 2560 events read in total (295ms).
[11:17:48.976] <TB3> INFO: Test took 1193ms.
[11:17:48.978] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:49.284] <TB3> INFO: Expecting 2560 events.
[11:17:50.171] <TB3> INFO: 2560 events read in total (295ms).
[11:17:50.171] <TB3> INFO: Test took 1193ms.
[11:17:50.173] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:50.479] <TB3> INFO: Expecting 2560 events.
[11:17:51.367] <TB3> INFO: 2560 events read in total (296ms).
[11:17:51.367] <TB3> INFO: Test took 1194ms.
[11:17:51.370] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:51.676] <TB3> INFO: Expecting 2560 events.
[11:17:52.562] <TB3> INFO: 2560 events read in total (295ms).
[11:17:52.562] <TB3> INFO: Test took 1192ms.
[11:17:52.565] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:52.871] <TB3> INFO: Expecting 2560 events.
[11:17:53.763] <TB3> INFO: 2560 events read in total (300ms).
[11:17:53.763] <TB3> INFO: Test took 1198ms.
[11:17:53.765] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:54.072] <TB3> INFO: Expecting 2560 events.
[11:17:54.955] <TB3> INFO: 2560 events read in total (291ms).
[11:17:54.955] <TB3> INFO: Test took 1190ms.
[11:17:54.957] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:55.263] <TB3> INFO: Expecting 2560 events.
[11:17:56.152] <TB3> INFO: 2560 events read in total (297ms).
[11:17:56.152] <TB3> INFO: Test took 1195ms.
[11:17:56.154] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:56.460] <TB3> INFO: Expecting 2560 events.
[11:17:57.343] <TB3> INFO: 2560 events read in total (291ms).
[11:17:57.343] <TB3> INFO: Test took 1189ms.
[11:17:57.346] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:57.652] <TB3> INFO: Expecting 2560 events.
[11:17:58.535] <TB3> INFO: 2560 events read in total (292ms).
[11:17:58.535] <TB3> INFO: Test took 1189ms.
[11:17:58.537] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:17:58.844] <TB3> INFO: Expecting 2560 events.
[11:17:59.726] <TB3> INFO: 2560 events read in total (291ms).
[11:17:59.726] <TB3> INFO: Test took 1189ms.
[11:17:59.728] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:00.035] <TB3> INFO: Expecting 2560 events.
[11:18:00.917] <TB3> INFO: 2560 events read in total (290ms).
[11:18:00.917] <TB3> INFO: Test took 1189ms.
[11:18:00.919] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:01.226] <TB3> INFO: Expecting 2560 events.
[11:18:02.109] <TB3> INFO: 2560 events read in total (291ms).
[11:18:02.109] <TB3> INFO: Test took 1190ms.
[11:18:02.111] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:02.417] <TB3> INFO: Expecting 2560 events.
[11:18:03.301] <TB3> INFO: 2560 events read in total (292ms).
[11:18:03.302] <TB3> INFO: Test took 1191ms.
[11:18:03.304] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:03.610] <TB3> INFO: Expecting 2560 events.
[11:18:04.491] <TB3> INFO: 2560 events read in total (290ms).
[11:18:04.491] <TB3> INFO: Test took 1187ms.
[11:18:04.494] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:04.800] <TB3> INFO: Expecting 2560 events.
[11:18:05.683] <TB3> INFO: 2560 events read in total (291ms).
[11:18:05.683] <TB3> INFO: Test took 1189ms.
[11:18:05.686] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:05.992] <TB3> INFO: Expecting 2560 events.
[11:18:06.872] <TB3> INFO: 2560 events read in total (288ms).
[11:18:06.873] <TB3> INFO: Test took 1188ms.
[11:18:06.874] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:07.181] <TB3> INFO: Expecting 2560 events.
[11:18:08.069] <TB3> INFO: 2560 events read in total (296ms).
[11:18:08.070] <TB3> INFO: Test took 1196ms.
[11:18:08.073] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:08.378] <TB3> INFO: Expecting 2560 events.
[11:18:09.267] <TB3> INFO: 2560 events read in total (298ms).
[11:18:09.267] <TB3> INFO: Test took 1194ms.
[11:18:09.269] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:09.575] <TB3> INFO: Expecting 2560 events.
[11:18:10.463] <TB3> INFO: 2560 events read in total (296ms).
[11:18:10.463] <TB3> INFO: Test took 1194ms.
[11:18:10.465] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:10.772] <TB3> INFO: Expecting 2560 events.
[11:18:11.656] <TB3> INFO: 2560 events read in total (292ms).
[11:18:11.656] <TB3> INFO: Test took 1191ms.
[11:18:11.658] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:11.965] <TB3> INFO: Expecting 2560 events.
[11:18:12.847] <TB3> INFO: 2560 events read in total (291ms).
[11:18:12.847] <TB3> INFO: Test took 1189ms.
[11:18:12.850] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:13.157] <TB3> INFO: Expecting 2560 events.
[11:18:14.043] <TB3> INFO: 2560 events read in total (295ms).
[11:18:14.043] <TB3> INFO: Test took 1194ms.
[11:18:14.046] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:14.352] <TB3> INFO: Expecting 2560 events.
[11:18:15.240] <TB3> INFO: 2560 events read in total (297ms).
[11:18:15.240] <TB3> INFO: Test took 1195ms.
[11:18:15.243] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:15.548] <TB3> INFO: Expecting 2560 events.
[11:18:16.441] <TB3> INFO: 2560 events read in total (301ms).
[11:18:16.441] <TB3> INFO: Test took 1198ms.
[11:18:16.444] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:16.750] <TB3> INFO: Expecting 2560 events.
[11:18:17.638] <TB3> INFO: 2560 events read in total (296ms).
[11:18:17.638] <TB3> INFO: Test took 1195ms.
[11:18:17.640] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:17.947] <TB3> INFO: Expecting 2560 events.
[11:18:18.836] <TB3> INFO: 2560 events read in total (297ms).
[11:18:18.836] <TB3> INFO: Test took 1196ms.
[11:18:18.838] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:19.145] <TB3> INFO: Expecting 2560 events.
[11:18:20.031] <TB3> INFO: 2560 events read in total (295ms).
[11:18:20.031] <TB3> INFO: Test took 1193ms.
[11:18:20.033] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:20.339] <TB3> INFO: Expecting 2560 events.
[11:18:21.227] <TB3> INFO: 2560 events read in total (296ms).
[11:18:21.227] <TB3> INFO: Test took 1194ms.
[11:18:21.230] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:18:21.536] <TB3> INFO: Expecting 2560 events.
[11:18:22.430] <TB3> INFO: 2560 events read in total (302ms).
[11:18:22.430] <TB3> INFO: Test took 1200ms.
[11:18:22.891] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 660 seconds
[11:18:22.891] <TB3> INFO: PH scale (per ROC): 31 34 45 29 54 43 46 53 46 31 33 48 35 50 27 37
[11:18:22.891] <TB3> INFO: PH offset (per ROC): 97 79 99 80 127 108 119 117 102 100 93 106 100 133 109 90
[11:18:22.898] <TB3> INFO: Decoding statistics:
[11:18:22.898] <TB3> INFO: General information:
[11:18:22.898] <TB3> INFO: 16bit words read: 127882
[11:18:22.898] <TB3> INFO: valid events total: 20480
[11:18:22.899] <TB3> INFO: empty events: 17979
[11:18:22.899] <TB3> INFO: valid events with pixels: 2501
[11:18:22.899] <TB3> INFO: valid pixel hits: 2501
[11:18:22.899] <TB3> INFO: Event errors: 0
[11:18:22.899] <TB3> INFO: start marker: 0
[11:18:22.899] <TB3> INFO: stop marker: 0
[11:18:22.899] <TB3> INFO: overflow: 0
[11:18:22.899] <TB3> INFO: invalid 5bit words: 0
[11:18:22.899] <TB3> INFO: invalid XOR eye diagram: 0
[11:18:22.899] <TB3> INFO: frame (failed synchr.): 0
[11:18:22.899] <TB3> INFO: idle data (no TBM trl): 0
[11:18:22.899] <TB3> INFO: no data (only TBM hdr): 0
[11:18:22.899] <TB3> INFO: TBM errors: 0
[11:18:22.899] <TB3> INFO: flawed TBM headers: 0
[11:18:22.899] <TB3> INFO: flawed TBM trailers: 0
[11:18:22.899] <TB3> INFO: event ID mismatches: 0
[11:18:22.899] <TB3> INFO: ROC errors: 0
[11:18:22.899] <TB3> INFO: missing ROC header(s): 0
[11:18:22.899] <TB3> INFO: misplaced readback start: 0
[11:18:22.899] <TB3> INFO: Pixel decoding errors: 0
[11:18:22.899] <TB3> INFO: pixel data incomplete: 0
[11:18:22.899] <TB3> INFO: pixel address: 0
[11:18:22.899] <TB3> INFO: pulse height fill bit: 0
[11:18:22.899] <TB3> INFO: buffer corruption: 0
[11:18:23.148] <TB3> INFO: ######################################################################
[11:18:23.148] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[11:18:23.148] <TB3> INFO: ######################################################################
[11:18:23.165] <TB3> INFO: scanning low vcal = 10
[11:18:23.478] <TB3> INFO: Expecting 41600 events.
[11:18:27.063] <TB3> INFO: 41600 events read in total (2993ms).
[11:18:27.063] <TB3> INFO: Test took 3898ms.
[11:18:27.065] <TB3> INFO: scanning low vcal = 20
[11:18:27.364] <TB3> INFO: Expecting 41600 events.
[11:18:30.996] <TB3> INFO: 41600 events read in total (3040ms).
[11:18:30.996] <TB3> INFO: Test took 3931ms.
[11:18:30.998] <TB3> INFO: scanning low vcal = 30
[11:18:31.290] <TB3> INFO: Expecting 41600 events.
[11:18:34.001] <TB3> INFO: 41600 events read in total (3119ms).
[11:18:34.002] <TB3> INFO: Test took 4004ms.
[11:18:35.005] <TB3> INFO: scanning low vcal = 40
[11:18:35.281] <TB3> INFO: Expecting 41600 events.
[11:18:39.303] <TB3> INFO: 41600 events read in total (3430ms).
[11:18:39.304] <TB3> INFO: Test took 4299ms.
[11:18:39.307] <TB3> INFO: scanning low vcal = 50
[11:18:39.584] <TB3> INFO: Expecting 41600 events.
[11:18:43.616] <TB3> INFO: 41600 events read in total (3439ms).
[11:18:43.617] <TB3> INFO: Test took 4310ms.
[11:18:43.620] <TB3> INFO: scanning low vcal = 60
[11:18:43.897] <TB3> INFO: Expecting 41600 events.
[11:18:47.937] <TB3> INFO: 41600 events read in total (3449ms).
[11:18:47.937] <TB3> INFO: Test took 4317ms.
[11:18:47.940] <TB3> INFO: scanning low vcal = 70
[11:18:48.217] <TB3> INFO: Expecting 41600 events.
[11:18:52.299] <TB3> INFO: 41600 events read in total (3490ms).
[11:18:52.300] <TB3> INFO: Test took 4360ms.
[11:18:52.302] <TB3> INFO: scanning low vcal = 80
[11:18:52.579] <TB3> INFO: Expecting 41600 events.
[11:18:56.628] <TB3> INFO: 41600 events read in total (3457ms).
[11:18:56.629] <TB3> INFO: Test took 4327ms.
[11:18:56.632] <TB3> INFO: scanning low vcal = 90
[11:18:56.948] <TB3> INFO: Expecting 41600 events.
[11:19:00.986] <TB3> INFO: 41600 events read in total (3446ms).
[11:19:00.987] <TB3> INFO: Test took 4355ms.
[11:19:00.991] <TB3> INFO: scanning low vcal = 100
[11:19:01.267] <TB3> INFO: Expecting 41600 events.
[11:19:05.339] <TB3> INFO: 41600 events read in total (3481ms).
[11:19:05.340] <TB3> INFO: Test took 4349ms.
[11:19:05.343] <TB3> INFO: scanning low vcal = 110
[11:19:05.659] <TB3> INFO: Expecting 41600 events.
[11:19:09.689] <TB3> INFO: 41600 events read in total (3438ms).
[11:19:09.689] <TB3> INFO: Test took 4346ms.
[11:19:09.692] <TB3> INFO: scanning low vcal = 120
[11:19:10.006] <TB3> INFO: Expecting 41600 events.
[11:19:14.019] <TB3> INFO: 41600 events read in total (3422ms).
[11:19:14.020] <TB3> INFO: Test took 4327ms.
[11:19:14.023] <TB3> INFO: scanning low vcal = 130
[11:19:14.299] <TB3> INFO: Expecting 41600 events.
[11:19:18.351] <TB3> INFO: 41600 events read in total (3460ms).
[11:19:18.352] <TB3> INFO: Test took 4329ms.
[11:19:18.355] <TB3> INFO: scanning low vcal = 140
[11:19:18.632] <TB3> INFO: Expecting 41600 events.
[11:19:22.698] <TB3> INFO: 41600 events read in total (3475ms).
[11:19:22.699] <TB3> INFO: Test took 4344ms.
[11:19:22.702] <TB3> INFO: scanning low vcal = 150
[11:19:23.016] <TB3> INFO: Expecting 41600 events.
[11:19:27.040] <TB3> INFO: 41600 events read in total (3432ms).
[11:19:27.040] <TB3> INFO: Test took 4338ms.
[11:19:27.043] <TB3> INFO: scanning low vcal = 160
[11:19:27.320] <TB3> INFO: Expecting 41600 events.
[11:19:31.309] <TB3> INFO: 41600 events read in total (3398ms).
[11:19:31.310] <TB3> INFO: Test took 4267ms.
[11:19:31.313] <TB3> INFO: scanning low vcal = 170
[11:19:31.626] <TB3> INFO: Expecting 41600 events.
[11:19:35.624] <TB3> INFO: 41600 events read in total (3406ms).
[11:19:35.625] <TB3> INFO: Test took 4312ms.
[11:19:35.630] <TB3> INFO: scanning low vcal = 180
[11:19:35.948] <TB3> INFO: Expecting 41600 events.
[11:19:39.970] <TB3> INFO: 41600 events read in total (3430ms).
[11:19:39.971] <TB3> INFO: Test took 4340ms.
[11:19:39.974] <TB3> INFO: scanning low vcal = 190
[11:19:40.250] <TB3> INFO: Expecting 41600 events.
[11:19:44.323] <TB3> INFO: 41600 events read in total (3481ms).
[11:19:44.324] <TB3> INFO: Test took 4350ms.
[11:19:44.327] <TB3> INFO: scanning low vcal = 200
[11:19:44.644] <TB3> INFO: Expecting 41600 events.
[11:19:48.716] <TB3> INFO: 41600 events read in total (3480ms).
[11:19:48.717] <TB3> INFO: Test took 4390ms.
[11:19:48.720] <TB3> INFO: scanning low vcal = 210
[11:19:49.037] <TB3> INFO: Expecting 41600 events.
[11:19:53.052] <TB3> INFO: 41600 events read in total (3424ms).
[11:19:53.053] <TB3> INFO: Test took 4333ms.
[11:19:53.056] <TB3> INFO: scanning low vcal = 220
[11:19:53.373] <TB3> INFO: Expecting 41600 events.
[11:19:57.439] <TB3> INFO: 41600 events read in total (3474ms).
[11:19:57.440] <TB3> INFO: Test took 4384ms.
[11:19:57.443] <TB3> INFO: scanning low vcal = 230
[11:19:57.757] <TB3> INFO: Expecting 41600 events.
[11:20:01.781] <TB3> INFO: 41600 events read in total (3432ms).
[11:20:01.781] <TB3> INFO: Test took 4338ms.
[11:20:01.784] <TB3> INFO: scanning low vcal = 240
[11:20:02.061] <TB3> INFO: Expecting 41600 events.
[11:20:06.130] <TB3> INFO: 41600 events read in total (3478ms).
[11:20:06.131] <TB3> INFO: Test took 4347ms.
[11:20:06.134] <TB3> INFO: scanning low vcal = 250
[11:20:06.456] <TB3> INFO: Expecting 41600 events.
[11:20:10.546] <TB3> INFO: 41600 events read in total (3499ms).
[11:20:10.547] <TB3> INFO: Test took 4413ms.
[11:20:10.551] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[11:20:10.869] <TB3> INFO: Expecting 41600 events.
[11:20:14.883] <TB3> INFO: 41600 events read in total (3423ms).
[11:20:14.884] <TB3> INFO: Test took 4333ms.
[11:20:14.887] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[11:20:15.163] <TB3> INFO: Expecting 41600 events.
[11:20:19.164] <TB3> INFO: 41600 events read in total (3409ms).
[11:20:19.165] <TB3> INFO: Test took 4278ms.
[11:20:19.168] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[11:20:19.500] <TB3> INFO: Expecting 41600 events.
[11:20:23.543] <TB3> INFO: 41600 events read in total (3451ms).
[11:20:23.544] <TB3> INFO: Test took 4376ms.
[11:20:23.547] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[11:20:23.862] <TB3> INFO: Expecting 41600 events.
[11:20:27.881] <TB3> INFO: 41600 events read in total (3427ms).
[11:20:27.882] <TB3> INFO: Test took 4335ms.
[11:20:27.885] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[11:20:28.201] <TB3> INFO: Expecting 41600 events.
[11:20:32.240] <TB3> INFO: 41600 events read in total (3447ms).
[11:20:32.241] <TB3> INFO: Test took 4356ms.
[11:20:32.981] <TB3> INFO: PixTestGainPedestal::measure() done
[11:21:05.613] <TB3> INFO: PixTestGainPedestal::fit() done
[11:21:05.613] <TB3> INFO: non-linearity mean: 0.971 1.006 0.958 1.015 0.979 0.964 0.969 0.978 0.931 1.023 0.937 0.976 0.954 0.984 0.935 0.937
[11:21:05.613] <TB3> INFO: non-linearity RMS: 0.192 0.158 0.040 0.160 0.004 0.034 0.012 0.006 0.091 0.186 0.138 0.021 0.054 0.003 0.111 0.084
[11:21:05.613] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C0.dat
[11:21:05.627] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C1.dat
[11:21:05.641] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C2.dat
[11:21:05.654] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C3.dat
[11:21:05.668] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C4.dat
[11:21:05.682] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C5.dat
[11:21:05.695] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C6.dat
[11:21:05.709] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C7.dat
[11:21:05.722] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C8.dat
[11:21:05.736] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C9.dat
[11:21:05.749] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C10.dat
[11:21:05.763] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C11.dat
[11:21:05.776] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C12.dat
[11:21:05.790] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C13.dat
[11:21:05.803] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C14.dat
[11:21:05.816] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1051_FullQualification_2016-10-23_14h52m_1477227153//003_Fulltest_p17//phCalibrationFitErr35_C15.dat
[11:21:05.830] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 162 seconds
[11:21:05.830] <TB3> INFO: Decoding statistics:
[11:21:05.830] <TB3> INFO: General information:
[11:21:05.830] <TB3> INFO: 16bit words read: 3241834
[11:21:05.830] <TB3> INFO: valid events total: 332800
[11:21:05.830] <TB3> INFO: empty events: 3694
[11:21:05.830] <TB3> INFO: valid events with pixels: 329106
[11:21:05.830] <TB3> INFO: valid pixel hits: 622517
[11:21:05.830] <TB3> INFO: Event errors: 0
[11:21:05.830] <TB3> INFO: start marker: 0
[11:21:05.830] <TB3> INFO: stop marker: 0
[11:21:05.830] <TB3> INFO: overflow: 0
[11:21:05.830] <TB3> INFO: invalid 5bit words: 0
[11:21:05.830] <TB3> INFO: invalid XOR eye diagram: 0
[11:21:05.830] <TB3> INFO: frame (failed synchr.): 0
[11:21:05.830] <TB3> INFO: idle data (no TBM trl): 0
[11:21:05.830] <TB3> INFO: no data (only TBM hdr): 0
[11:21:05.830] <TB3> INFO: TBM errors: 0
[11:21:05.830] <TB3> INFO: flawed TBM headers: 0
[11:21:05.830] <TB3> INFO: flawed TBM trailers: 0
[11:21:05.830] <TB3> INFO: event ID mismatches: 0
[11:21:05.830] <TB3> INFO: ROC errors: 0
[11:21:05.830] <TB3> INFO: missing ROC header(s): 0
[11:21:05.830] <TB3> INFO: misplaced readback start: 0
[11:21:05.830] <TB3> INFO: Pixel decoding errors: 0
[11:21:05.830] <TB3> INFO: pixel data incomplete: 0
[11:21:05.830] <TB3> INFO: pixel address: 0
[11:21:05.830] <TB3> INFO: pulse height fill bit: 0
[11:21:05.830] <TB3> INFO: buffer corruption: 0
[11:21:05.845] <TB3> INFO: Decoding statistics:
[11:21:05.845] <TB3> INFO: General information:
[11:21:05.845] <TB3> INFO: 16bit words read: 3371252
[11:21:05.845] <TB3> INFO: valid events total: 353536
[11:21:05.845] <TB3> INFO: empty events: 21929
[11:21:05.845] <TB3> INFO: valid events with pixels: 331607
[11:21:05.845] <TB3> INFO: valid pixel hits: 625018
[11:21:05.845] <TB3> INFO: Event errors: 0
[11:21:05.845] <TB3> INFO: start marker: 0
[11:21:05.845] <TB3> INFO: stop marker: 0
[11:21:05.845] <TB3> INFO: overflow: 0
[11:21:05.845] <TB3> INFO: invalid 5bit words: 0
[11:21:05.845] <TB3> INFO: invalid XOR eye diagram: 0
[11:21:05.845] <TB3> INFO: frame (failed synchr.): 0
[11:21:05.845] <TB3> INFO: idle data (no TBM trl): 0
[11:21:05.845] <TB3> INFO: no data (only TBM hdr): 0
[11:21:05.845] <TB3> INFO: TBM errors: 0
[11:21:05.845] <TB3> INFO: flawed TBM headers: 0
[11:21:05.845] <TB3> INFO: flawed TBM trailers: 0
[11:21:05.845] <TB3> INFO: event ID mismatches: 0
[11:21:05.845] <TB3> INFO: ROC errors: 0
[11:21:05.845] <TB3> INFO: missing ROC header(s): 0
[11:21:05.845] <TB3> INFO: misplaced readback start: 0
[11:21:05.845] <TB3> INFO: Pixel decoding errors: 0
[11:21:05.845] <TB3> INFO: pixel data incomplete: 0
[11:21:05.845] <TB3> INFO: pixel address: 0
[11:21:05.845] <TB3> INFO: pulse height fill bit: 0
[11:21:05.845] <TB3> INFO: buffer corruption: 0
[11:21:05.845] <TB3> INFO: enter test to run
[11:21:05.845] <TB3> INFO: test: exit no parameter change
[11:21:05.959] <TB3> QUIET: Connection to board 126 closed.
[11:21:05.960] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud