Test Date: 2016-11-04 10:05
Analysis date: 2016-11-07 10:33
Logfile
LogfileView
[16:43:47.240] <TB0> INFO: *** Welcome to pxar ***
[16:43:47.240] <TB0> INFO: *** Today: 2016/11/04
[16:43:47.246] <TB0> INFO: *** Version: c8ba-dirty
[16:43:47.246] <TB0> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C15.dat
[16:43:47.247] <TB0> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//tbmParameters_C1b.dat
[16:43:47.247] <TB0> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//defaultMaskFile.dat
[16:43:47.247] <TB0> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters_C15.dat
[16:43:47.299] <TB0> INFO: clk: 4
[16:43:47.299] <TB0> INFO: ctr: 4
[16:43:47.299] <TB0> INFO: sda: 19
[16:43:47.299] <TB0> INFO: tin: 9
[16:43:47.299] <TB0> INFO: level: 15
[16:43:47.299] <TB0> INFO: triggerdelay: 0
[16:43:47.299] <TB0> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[16:43:47.299] <TB0> INFO: Log level: INFO
[16:43:47.308] <TB0> INFO: Found DTB DTB_WS6AYH
[16:43:47.315] <TB0> QUIET: Connection to board DTB_WS6AYH opened.
[16:43:47.317] <TB0> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 73
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WS6AYH
MAC address: 40D855118049
Hostname: pixelDTB073
Comment:
------------------------------------------------------
[16:43:47.319] <TB0> INFO: RPC call hashes of host and DTB match: 486171790
[16:43:48.803] <TB0> INFO: DUT info:
[16:43:48.803] <TB0> INFO: The DUT currently contains the following objects:
[16:43:48.803] <TB0> INFO: 4 TBM Cores tbm10c (4 ON)
[16:43:48.803] <TB0> INFO: TBM Core alpha (0): 7 registers set
[16:43:48.803] <TB0> INFO: TBM Core beta (1): 7 registers set
[16:43:48.803] <TB0> INFO: TBM Core alpha (2): 7 registers set
[16:43:48.803] <TB0> INFO: TBM Core beta (3): 7 registers set
[16:43:48.803] <TB0> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[16:43:48.803] <TB0> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:48.803] <TB0> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:43:49.204] <TB0> INFO: enter 'restricted' command line mode
[16:43:49.204] <TB0> INFO: enter test to run
[16:43:49.204] <TB0> INFO: test: pretest no parameter change
[16:43:49.204] <TB0> INFO: running: pretest
[16:43:49.730] <TB0> INFO: ######################################################################
[16:43:49.730] <TB0> INFO: PixTestPretest::doTest()
[16:43:49.730] <TB0> INFO: ######################################################################
[16:43:49.731] <TB0> INFO: ----------------------------------------------------------------------
[16:43:49.731] <TB0> INFO: PixTestPretest::programROC()
[16:43:49.731] <TB0> INFO: ----------------------------------------------------------------------
[16:44:07.744] <TB0> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[16:44:07.744] <TB0> INFO: IA differences per ROC: 17.7 19.3 19.3 18.5 20.1 16.9 18.5 17.7 18.5 20.9 19.3 16.9 18.5 20.9 17.7 18.5
[16:44:07.777] <TB0> INFO: ----------------------------------------------------------------------
[16:44:07.777] <TB0> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[16:44:07.777] <TB0> INFO: ----------------------------------------------------------------------
[16:44:29.013] <TB0> INFO: PixTestPretest::setVana() done, Module Ia 382.7 mA = 23.9187 mA/ROC
[16:44:29.014] <TB0> INFO: i(loss) [mA/ROC]: 20.1 19.3 19.3 18.5 19.3 20.1 19.3 20.1 19.3 19.3 20.1 19.3 19.3 19.3 19.3 19.3
[16:44:29.043] <TB0> INFO: ----------------------------------------------------------------------
[16:44:29.043] <TB0> INFO: PixTestPretest::findTiming()
[16:44:29.043] <TB0> INFO: ----------------------------------------------------------------------
[16:44:29.043] <TB0> INFO: PixTestCmd::init()
[16:44:29.612] <TB0> WARNING: Not unmasking DUT, not setting Calibrate bits!

[16:45:00.452] <TB0> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[16:45:00.452] <TB0> INFO: (success/tries = 100/100), width = 3
[16:45:01.954] <TB0> INFO: ----------------------------------------------------------------------
[16:45:01.954] <TB0> INFO: PixTestPretest::findWorkingPixel()
[16:45:01.954] <TB0> INFO: ----------------------------------------------------------------------
[16:45:02.046] <TB0> INFO: Expecting 231680 events.
[16:45:11.842] <TB0> INFO: 231680 events read in total (9204ms).
[16:45:11.849] <TB0> INFO: Test took 9892ms.
[16:45:12.095] <TB0> INFO: Found working pixel in all ROCs: col/row = 12/22
[16:45:12.126] <TB0> INFO: ----------------------------------------------------------------------
[16:45:12.126] <TB0> INFO: PixTestPretest::setVthrCompCalDel()
[16:45:12.126] <TB0> INFO: ----------------------------------------------------------------------
[16:45:12.219] <TB0> INFO: Expecting 231680 events.
[16:45:21.814] <TB0> INFO: 231680 events read in total (9004ms).
[16:45:21.822] <TB0> INFO: Test took 9692ms.
[16:45:22.079] <TB0> INFO: PixTestPretest::setVthrCompCalDel() done
[16:45:22.079] <TB0> INFO: CalDel: 98 93 103 108 97 96 98 110 112 104 93 89 103 94 98 101
[16:45:22.079] <TB0> INFO: VthrComp: 52 51 51 51 51 51 51 51 51 53 51 51 51 51 51 51
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C0.dat
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C1.dat
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C2.dat
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C3.dat
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C4.dat
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C5.dat
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C6.dat
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C7.dat
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C8.dat
[16:45:22.082] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C9.dat
[16:45:22.083] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C10.dat
[16:45:22.083] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C11.dat
[16:45:22.083] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C12.dat
[16:45:22.083] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C13.dat
[16:45:22.083] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C14.dat
[16:45:22.083] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters_C15.dat
[16:45:22.083] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//tbmParameters_C0a.dat
[16:45:22.083] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//tbmParameters_C0b.dat
[16:45:22.083] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//tbmParameters_C1a.dat
[16:45:22.083] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//tbmParameters_C1b.dat
[16:45:22.083] <TB0> INFO: PixTestPretest::doTest() done, duration: 92 seconds
[16:45:22.212] <TB0> INFO: enter test to run
[16:45:22.212] <TB0> INFO: test: FullTest no parameter change
[16:45:22.212] <TB0> INFO: running: fulltest
[16:45:22.212] <TB0> INFO: ######################################################################
[16:45:22.212] <TB0> INFO: PixTestFullTest::doTest()
[16:45:22.212] <TB0> INFO: ######################################################################
[16:45:22.214] <TB0> INFO: ######################################################################
[16:45:22.214] <TB0> INFO: PixTestAlive::doTest()
[16:45:22.214] <TB0> INFO: ######################################################################
[16:45:22.215] <TB0> INFO: ----------------------------------------------------------------------
[16:45:22.215] <TB0> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:45:22.215] <TB0> INFO: ----------------------------------------------------------------------
[16:45:22.450] <TB0> INFO: Expecting 41600 events.
[16:45:25.880] <TB0> INFO: 41600 events read in total (2838ms).
[16:45:25.881] <TB0> INFO: Test took 3665ms.
[16:45:26.110] <TB0> INFO: PixTestAlive::aliveTest() done
[16:45:26.110] <TB0> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:45:26.111] <TB0> INFO: ----------------------------------------------------------------------
[16:45:26.111] <TB0> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:45:26.111] <TB0> INFO: ----------------------------------------------------------------------
[16:45:26.345] <TB0> INFO: Expecting 41600 events.
[16:45:29.355] <TB0> INFO: 41600 events read in total (2418ms).
[16:45:29.355] <TB0> INFO: Test took 3242ms.
[16:45:29.356] <TB0> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[16:45:29.592] <TB0> INFO: PixTestAlive::maskTest() done
[16:45:29.592] <TB0> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:45:29.593] <TB0> INFO: ----------------------------------------------------------------------
[16:45:29.593] <TB0> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:45:29.593] <TB0> INFO: ----------------------------------------------------------------------
[16:45:29.852] <TB0> INFO: Expecting 41600 events.
[16:45:33.364] <TB0> INFO: 41600 events read in total (2921ms).
[16:45:33.364] <TB0> INFO: Test took 3769ms.
[16:45:33.597] <TB0> INFO: PixTestAlive::addressDecodingTest() done
[16:45:33.597] <TB0> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:45:33.597] <TB0> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[16:45:33.597] <TB0> INFO: Decoding statistics:
[16:45:33.598] <TB0> INFO: General information:
[16:45:33.598] <TB0> INFO: 16bit words read: 0
[16:45:33.598] <TB0> INFO: valid events total: 0
[16:45:33.598] <TB0> INFO: empty events: 0
[16:45:33.598] <TB0> INFO: valid events with pixels: 0
[16:45:33.598] <TB0> INFO: valid pixel hits: 0
[16:45:33.598] <TB0> INFO: Event errors: 0
[16:45:33.598] <TB0> INFO: start marker: 0
[16:45:33.598] <TB0> INFO: stop marker: 0
[16:45:33.598] <TB0> INFO: overflow: 0
[16:45:33.598] <TB0> INFO: invalid 5bit words: 0
[16:45:33.598] <TB0> INFO: invalid XOR eye diagram: 0
[16:45:33.598] <TB0> INFO: frame (failed synchr.): 0
[16:45:33.598] <TB0> INFO: idle data (no TBM trl): 0
[16:45:33.598] <TB0> INFO: no data (only TBM hdr): 0
[16:45:33.598] <TB0> INFO: TBM errors: 0
[16:45:33.598] <TB0> INFO: flawed TBM headers: 0
[16:45:33.598] <TB0> INFO: flawed TBM trailers: 0
[16:45:33.598] <TB0> INFO: event ID mismatches: 0
[16:45:33.598] <TB0> INFO: ROC errors: 0
[16:45:33.598] <TB0> INFO: missing ROC header(s): 0
[16:45:33.598] <TB0> INFO: misplaced readback start: 0
[16:45:33.598] <TB0> INFO: Pixel decoding errors: 0
[16:45:33.598] <TB0> INFO: pixel data incomplete: 0
[16:45:33.598] <TB0> INFO: pixel address: 0
[16:45:33.598] <TB0> INFO: pulse height fill bit: 0
[16:45:33.598] <TB0> INFO: buffer corruption: 0
[16:45:33.605] <TB0> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C15.dat
[16:45:33.605] <TB0> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[16:45:33.605] <TB0> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[16:45:33.605] <TB0> INFO: ######################################################################
[16:45:33.605] <TB0> INFO: PixTestReadback::doTest()
[16:45:33.605] <TB0> INFO: ######################################################################
[16:45:33.605] <TB0> INFO: ----------------------------------------------------------------------
[16:45:33.605] <TB0> INFO: PixTestReadback::CalibrateVd()
[16:45:33.605] <TB0> INFO: ----------------------------------------------------------------------
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C0.dat
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C1.dat
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C2.dat
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C3.dat
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C4.dat
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C5.dat
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C6.dat
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C7.dat
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C8.dat
[16:45:43.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C9.dat
[16:45:43.558] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C10.dat
[16:45:43.558] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C11.dat
[16:45:43.558] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C12.dat
[16:45:43.558] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C13.dat
[16:45:43.558] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C14.dat
[16:45:43.558] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C15.dat
[16:45:43.588] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[16:45:43.588] <TB0> INFO: ----------------------------------------------------------------------
[16:45:43.588] <TB0> INFO: PixTestReadback::CalibrateVa()
[16:45:43.588] <TB0> INFO: ----------------------------------------------------------------------
[16:45:53.485] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C0.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C1.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C2.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C3.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C4.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C5.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C6.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C7.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C8.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C9.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C10.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C11.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C12.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C13.dat
[16:45:53.486] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C14.dat
[16:45:53.487] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C15.dat
[16:45:53.514] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[16:45:53.514] <TB0> INFO: ----------------------------------------------------------------------
[16:45:53.514] <TB0> INFO: PixTestReadback::readbackVbg()
[16:45:53.514] <TB0> INFO: ----------------------------------------------------------------------
[16:46:01.153] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[16:46:01.153] <TB0> INFO: ----------------------------------------------------------------------
[16:46:01.153] <TB0> INFO: PixTestReadback::getCalibratedVbg()
[16:46:01.153] <TB0> INFO: ----------------------------------------------------------------------
[16:46:01.153] <TB0> INFO: Vbg will be calibrated using Vd calibration
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 151.2calibrated Vbg = 1.17019 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 159calibrated Vbg = 1.18569 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 154.3calibrated Vbg = 1.16833 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 151.5calibrated Vbg = 1.16832 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 162.2calibrated Vbg = 1.17655 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 153.5calibrated Vbg = 1.17742 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 149.9calibrated Vbg = 1.1771 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 152.2calibrated Vbg = 1.18056 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 160calibrated Vbg = 1.18 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 161.4calibrated Vbg = 1.17003 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 156.6calibrated Vbg = 1.17126 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 157.7calibrated Vbg = 1.15559 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 163calibrated Vbg = 1.17157 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 144.5calibrated Vbg = 1.16477 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 155.7calibrated Vbg = 1.17696 :::*/*/*/*/
[16:46:01.153] <TB0> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 155.4calibrated Vbg = 1.17233 :::*/*/*/*/
[16:46:01.155] <TB0> INFO: ----------------------------------------------------------------------
[16:46:01.155] <TB0> INFO: PixTestReadback::CalibrateIa()
[16:46:01.155] <TB0> INFO: ----------------------------------------------------------------------
[16:48:41.466] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C0.dat
[16:48:41.466] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C1.dat
[16:48:41.466] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C2.dat
[16:48:41.466] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C3.dat
[16:48:41.466] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C4.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C5.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C6.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C7.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C8.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C9.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C10.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C11.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C12.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C13.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C14.dat
[16:48:41.467] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//readbackCal_C15.dat
[16:48:41.495] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[16:48:41.496] <TB0> INFO: PixTestReadback::doTest() done
[16:48:41.496] <TB0> INFO: Decoding statistics:
[16:48:41.496] <TB0> INFO: General information:
[16:48:41.496] <TB0> INFO: 16bit words read: 1536
[16:48:41.496] <TB0> INFO: valid events total: 256
[16:48:41.496] <TB0> INFO: empty events: 256
[16:48:41.496] <TB0> INFO: valid events with pixels: 0
[16:48:41.496] <TB0> INFO: valid pixel hits: 0
[16:48:41.496] <TB0> INFO: Event errors: 0
[16:48:41.496] <TB0> INFO: start marker: 0
[16:48:41.496] <TB0> INFO: stop marker: 0
[16:48:41.496] <TB0> INFO: overflow: 0
[16:48:41.496] <TB0> INFO: invalid 5bit words: 0
[16:48:41.497] <TB0> INFO: invalid XOR eye diagram: 0
[16:48:41.497] <TB0> INFO: frame (failed synchr.): 0
[16:48:41.497] <TB0> INFO: idle data (no TBM trl): 0
[16:48:41.497] <TB0> INFO: no data (only TBM hdr): 0
[16:48:41.497] <TB0> INFO: TBM errors: 0
[16:48:41.497] <TB0> INFO: flawed TBM headers: 0
[16:48:41.497] <TB0> INFO: flawed TBM trailers: 0
[16:48:41.497] <TB0> INFO: event ID mismatches: 0
[16:48:41.497] <TB0> INFO: ROC errors: 0
[16:48:41.497] <TB0> INFO: missing ROC header(s): 0
[16:48:41.497] <TB0> INFO: misplaced readback start: 0
[16:48:41.497] <TB0> INFO: Pixel decoding errors: 0
[16:48:41.497] <TB0> INFO: pixel data incomplete: 0
[16:48:41.497] <TB0> INFO: pixel address: 0
[16:48:41.497] <TB0> INFO: pulse height fill bit: 0
[16:48:41.497] <TB0> INFO: buffer corruption: 0
[16:48:41.530] <TB0> INFO: ######################################################################
[16:48:41.530] <TB0> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[16:48:41.530] <TB0> INFO: ######################################################################
[16:48:41.533] <TB0> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[16:48:41.544] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[16:48:41.544] <TB0> INFO: run 1 of 1
[16:48:41.775] <TB0> INFO: Expecting 3120000 events.
[16:49:11.666] <TB0> INFO: 653710 events read in total (29299ms).
[16:49:23.729] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (15) != TBM ID (129)

[16:49:23.862] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 15 15 129 15 15 15 15 15

[16:49:23.862] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (16)

[16:49:23.862] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[16:49:23.862] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a013 8040 4830 250 2fef 4831 250 2fef e022 c000

[16:49:23.862] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00d 80c0 4830 250 2fef 4830 250 2fef e022 c000

[16:49:23.862] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00e 8000 4830 250 2fef 4830 250 2fef e022 c000

[16:49:23.862] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4831 4831 2fef 4833 250 2fef e022 c000

[16:49:23.862] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a010 80b1 4030 250 2fef 4830 250 2fef e022 c000

[16:49:23.862] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a011 80c0 4831 250 2fef 4831 250 2fef e022 c000

[16:49:23.862] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a012 8000 4830 250 2fef 4830 250 2fef e022 c000

[16:49:23.863] <TB0> WARNING: Channel 0 ROC 0: Readback start marker after 32 readouts!

[16:49:23.863] <TB0> WARNING: Channel 0 ROC 1: Readback start marker after 32 readouts!

[16:49:23.863] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[16:49:23.863] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a022 8000 4830 250 2fef 4830 250 2fef e022 c000

[16:49:23.863] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01c 80b1 4031 250 2fef 4831 250 2fef e022 c000

[16:49:23.863] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01d 80c0 4831 250 2fef 4831 250 2fef e022 c000

[16:49:23.863] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01e 8000 4030 250 2fef 4830 250 2fef e022 c000

[16:49:23.863] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01f 8040 4832 250 2fef 4832 250 2fef e022 c000

[16:49:23.863] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a020 80b1 4030 250 2fef 4830 250 2fef e022 c000

[16:49:23.863] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a021 80c0 4831 250 2fef 4831 250 2fef e022 c000

[16:49:41.070] <TB0> INFO: 1309620 events read in total (58703ms).
[16:49:53.181] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (53) != TBM ID (129)

[16:49:53.316] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 53 53 129 53 53 53 53 53

[16:49:53.316] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (54)

[16:49:53.316] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[16:49:53.316] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a039 80c0 4030 4030 e022 c000

[16:49:53.316] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a033 8040 4030 4031 e022 c000

[16:49:53.316] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a034 80b1 4030 4030 e022 c000

[16:49:53.316] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4831 4831 e022 c000

[16:49:53.316] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a036 8000 4030 4030 e022 c000

[16:49:53.316] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a037 8040 4030 4030 e022 c000

[16:49:53.316] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a038 80b1 4030 4030 e022 c000

[16:50:10.616] <TB0> INFO: 1968735 events read in total (88249ms).
[16:50:22.729] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (224) != TBM ID (129)

[16:50:22.865] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 224 224 129 224 224 224 224 224

[16:50:22.865] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (225)

[16:50:22.865] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[16:50:22.865] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e4 80b1 4830 810 21ef 4030 e022 c000

[16:50:22.865] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0de 8000 4831 810 21ef 4831 e022 c000

[16:50:22.865] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0df 8040 4833 810 21ef 4833 810 21ef e022 c000

[16:50:22.865] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4831 4831 21ef 4830 e022 c000

[16:50:22.865] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e1 80c0 4831 810 21ef 4831 e022 c000

[16:50:22.865] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e2 8000 4830 810 21ef 4830 e022 c000

[16:50:22.865] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e3 8040 4830 810 21ef 4831 e022 c000

[16:50:40.423] <TB0> INFO: 2627065 events read in total (118056ms).
[16:51:02.458] <TB0> INFO: 3120000 events read in total (140091ms).
[16:51:02.528] <TB0> INFO: Test took 140984ms.
[16:51:28.767] <TB0> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 167 seconds
[16:51:28.767] <TB0> INFO: number of dead bumps (per ROC): 6 2 0 18 10 4 2 2 3 2 18 7 33 22 2 1
[16:51:28.767] <TB0> INFO: separation cut (per ROC): 109 109 103 91 106 105 101 100 95 110 105 108 92 109 108 107
[16:51:28.767] <TB0> INFO: Decoding statistics:
[16:51:28.767] <TB0> INFO: General information:
[16:51:28.767] <TB0> INFO: 16bit words read: 0
[16:51:28.767] <TB0> INFO: valid events total: 0
[16:51:28.767] <TB0> INFO: empty events: 0
[16:51:28.767] <TB0> INFO: valid events with pixels: 0
[16:51:28.767] <TB0> INFO: valid pixel hits: 0
[16:51:28.767] <TB0> INFO: Event errors: 0
[16:51:28.767] <TB0> INFO: start marker: 0
[16:51:28.767] <TB0> INFO: stop marker: 0
[16:51:28.767] <TB0> INFO: overflow: 0
[16:51:28.767] <TB0> INFO: invalid 5bit words: 0
[16:51:28.767] <TB0> INFO: invalid XOR eye diagram: 0
[16:51:28.767] <TB0> INFO: frame (failed synchr.): 0
[16:51:28.767] <TB0> INFO: idle data (no TBM trl): 0
[16:51:28.767] <TB0> INFO: no data (only TBM hdr): 0
[16:51:28.767] <TB0> INFO: TBM errors: 0
[16:51:28.767] <TB0> INFO: flawed TBM headers: 0
[16:51:28.767] <TB0> INFO: flawed TBM trailers: 0
[16:51:28.767] <TB0> INFO: event ID mismatches: 0
[16:51:28.767] <TB0> INFO: ROC errors: 0
[16:51:28.767] <TB0> INFO: missing ROC header(s): 0
[16:51:28.768] <TB0> INFO: misplaced readback start: 0
[16:51:28.768] <TB0> INFO: Pixel decoding errors: 0
[16:51:28.768] <TB0> INFO: pixel data incomplete: 0
[16:51:28.768] <TB0> INFO: pixel address: 0
[16:51:28.768] <TB0> INFO: pulse height fill bit: 0
[16:51:28.768] <TB0> INFO: buffer corruption: 0
[16:51:28.807] <TB0> INFO: ######################################################################
[16:51:28.807] <TB0> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[16:51:28.807] <TB0> INFO: ######################################################################
[16:51:28.808] <TB0> INFO: ----------------------------------------------------------------------
[16:51:28.808] <TB0> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[16:51:28.808] <TB0> INFO: ----------------------------------------------------------------------
[16:51:28.808] <TB0> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[16:51:28.817] <TB0> INFO: dacScan split into 1 runs with ntrig = 50
[16:51:28.817] <TB0> INFO: run 1 of 1
[16:51:29.056] <TB0> INFO: Expecting 36608000 events.
[16:51:52.497] <TB0> INFO: 670800 events read in total (22849ms).
[16:52:14.667] <TB0> INFO: 1327800 events read in total (45019ms).
[16:52:37.130] <TB0> INFO: 1986200 events read in total (67482ms).
[16:52:59.427] <TB0> INFO: 2642750 events read in total (89779ms).
[16:53:21.634] <TB0> INFO: 3298400 events read in total (111986ms).
[16:53:43.810] <TB0> INFO: 3952850 events read in total (134162ms).
[16:54:06.096] <TB0> INFO: 4608800 events read in total (156448ms).
[16:54:28.534] <TB0> INFO: 5265600 events read in total (178886ms).
[16:54:50.622] <TB0> INFO: 5920650 events read in total (200974ms).
[16:55:13.060] <TB0> INFO: 6575300 events read in total (223412ms).
[16:55:35.289] <TB0> INFO: 7229350 events read in total (245641ms).
[16:55:57.549] <TB0> INFO: 7881650 events read in total (267901ms).
[16:56:19.661] <TB0> INFO: 8533550 events read in total (290013ms).
[16:56:41.734] <TB0> INFO: 9187100 events read in total (312086ms).
[16:57:03.839] <TB0> INFO: 9840800 events read in total (334191ms).
[16:57:25.900] <TB0> INFO: 10493650 events read in total (356252ms).
[16:57:47.853] <TB0> INFO: 11145250 events read in total (378205ms).
[16:58:10.090] <TB0> INFO: 11797500 events read in total (400442ms).
[16:58:32.197] <TB0> INFO: 12449600 events read in total (422549ms).
[16:58:54.533] <TB0> INFO: 13101550 events read in total (444885ms).
[16:59:17.104] <TB0> INFO: 13753300 events read in total (467456ms).
[16:59:39.595] <TB0> INFO: 14405750 events read in total (489947ms).
[17:00:01.867] <TB0> INFO: 15059500 events read in total (512219ms).
[17:00:24.158] <TB0> INFO: 15710700 events read in total (534510ms).
[17:00:46.383] <TB0> INFO: 16360800 events read in total (556735ms).
[17:01:08.510] <TB0> INFO: 17009950 events read in total (578862ms).
[17:01:30.708] <TB0> INFO: 17661050 events read in total (601060ms).
[17:01:53.018] <TB0> INFO: 18310550 events read in total (623370ms).
[17:02:15.132] <TB0> INFO: 18959500 events read in total (645484ms).
[17:02:37.288] <TB0> INFO: 19607200 events read in total (667640ms).
[17:02:59.604] <TB0> INFO: 20255600 events read in total (689956ms).
[17:03:21.853] <TB0> INFO: 20904050 events read in total (712205ms).
[17:03:43.985] <TB0> INFO: 21551200 events read in total (734337ms).
[17:04:06.474] <TB0> INFO: 22198250 events read in total (756826ms).
[17:04:28.692] <TB0> INFO: 22845350 events read in total (779044ms).
[17:04:51.095] <TB0> INFO: 23492800 events read in total (801447ms).
[17:05:13.114] <TB0> INFO: 24139250 events read in total (823466ms).
[17:05:35.306] <TB0> INFO: 24786600 events read in total (845658ms).
[17:05:57.559] <TB0> INFO: 25434950 events read in total (867911ms).
[17:06:19.927] <TB0> INFO: 26083050 events read in total (890279ms).
[17:06:41.931] <TB0> INFO: 26730350 events read in total (912283ms).
[17:07:04.165] <TB0> INFO: 27378250 events read in total (934517ms).
[17:07:26.248] <TB0> INFO: 28025800 events read in total (956600ms).
[17:07:48.580] <TB0> INFO: 28672800 events read in total (978932ms).
[17:08:10.729] <TB0> INFO: 29319550 events read in total (1001081ms).
[17:08:32.826] <TB0> INFO: 29965700 events read in total (1023178ms).
[17:08:54.002] <TB0> INFO: 30612650 events read in total (1045354ms).
[17:09:16.990] <TB0> INFO: 31259050 events read in total (1067342ms).
[17:09:39.224] <TB0> INFO: 31905150 events read in total (1089576ms).
[17:10:01.344] <TB0> INFO: 32550400 events read in total (1111696ms).
[17:10:23.516] <TB0> INFO: 33199600 events read in total (1133868ms).
[17:10:45.687] <TB0> INFO: 33848550 events read in total (1156039ms).
[17:11:07.618] <TB0> INFO: 34495850 events read in total (1177970ms).
[17:11:29.732] <TB0> INFO: 35143100 events read in total (1200084ms).
[17:11:51.913] <TB0> INFO: 35789250 events read in total (1222265ms).
[17:12:14.405] <TB0> INFO: 36446150 events read in total (1244757ms).
[17:12:20.337] <TB0> INFO: 36608000 events read in total (1250689ms).
[17:12:20.428] <TB0> INFO: Test took 1251611ms.
[17:12:20.905] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:22.531] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:24.547] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:26.519] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:28.232] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:30.130] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:32.035] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:33.995] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:35.939] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:37.990] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:39.002] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:42.043] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:43.847] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:45.855] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:47.713] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:49.708] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:12:51.700] <TB0> INFO: PixTestScurves::scurves() done
[17:12:51.700] <TB0> INFO: Vcal mean: 123.28 120.29 104.35 108.38 117.87 111.03 97.28 112.41 113.25 120.79 116.30 119.67 117.19 113.19 118.29 106.82
[17:12:51.700] <TB0> INFO: Vcal RMS: 6.52 5.97 5.22 5.45 5.66 4.75 5.09 5.42 5.71 6.99 5.60 5.94 5.85 5.24 5.91 5.72
[17:12:51.700] <TB0> INFO: PixTestScurves::fullTest() done, duration: 1282 seconds
[17:12:51.700] <TB0> INFO: Decoding statistics:
[17:12:51.700] <TB0> INFO: General information:
[17:12:51.700] <TB0> INFO: 16bit words read: 0
[17:12:51.700] <TB0> INFO: valid events total: 0
[17:12:51.700] <TB0> INFO: empty events: 0
[17:12:51.700] <TB0> INFO: valid events with pixels: 0
[17:12:51.700] <TB0> INFO: valid pixel hits: 0
[17:12:51.700] <TB0> INFO: Event errors: 0
[17:12:51.700] <TB0> INFO: start marker: 0
[17:12:51.700] <TB0> INFO: stop marker: 0
[17:12:51.700] <TB0> INFO: overflow: 0
[17:12:51.700] <TB0> INFO: invalid 5bit words: 0
[17:12:51.700] <TB0> INFO: invalid XOR eye diagram: 0
[17:12:51.700] <TB0> INFO: frame (failed synchr.): 0
[17:12:51.700] <TB0> INFO: idle data (no TBM trl): 0
[17:12:51.700] <TB0> INFO: no data (only TBM hdr): 0
[17:12:51.700] <TB0> INFO: TBM errors: 0
[17:12:51.700] <TB0> INFO: flawed TBM headers: 0
[17:12:51.700] <TB0> INFO: flawed TBM trailers: 0
[17:12:51.700] <TB0> INFO: event ID mismatches: 0
[17:12:51.700] <TB0> INFO: ROC errors: 0
[17:12:51.700] <TB0> INFO: missing ROC header(s): 0
[17:12:51.700] <TB0> INFO: misplaced readback start: 0
[17:12:51.700] <TB0> INFO: Pixel decoding errors: 0
[17:12:51.700] <TB0> INFO: pixel data incomplete: 0
[17:12:51.700] <TB0> INFO: pixel address: 0
[17:12:51.700] <TB0> INFO: pulse height fill bit: 0
[17:12:51.700] <TB0> INFO: buffer corruption: 0
[17:12:51.766] <TB0> INFO: ######################################################################
[17:12:51.766] <TB0> INFO: PixTestTrim::doTest()
[17:12:51.766] <TB0> INFO: ######################################################################
[17:12:51.767] <TB0> INFO: ----------------------------------------------------------------------
[17:12:51.767] <TB0> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[17:12:51.767] <TB0> INFO: ----------------------------------------------------------------------
[17:12:51.812] <TB0> INFO: ---> VthrComp thr map (minimal VthrComp)
[17:12:51.812] <TB0> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[17:12:51.823] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:12:51.823] <TB0> INFO: run 1 of 1
[17:12:52.067] <TB0> INFO: Expecting 5025280 events.
[17:13:22.589] <TB0> INFO: 822312 events read in total (29927ms).
[17:13:52.427] <TB0> INFO: 1640536 events read in total (59766ms).
[17:14:22.201] <TB0> INFO: 2455680 events read in total (89539ms).
[17:14:51.835] <TB0> INFO: 3268720 events read in total (119173ms).
[17:15:21.519] <TB0> INFO: 4079432 events read in total (148857ms).
[17:15:51.283] <TB0> INFO: 4887336 events read in total (178621ms).
[17:15:56.588] <TB0> INFO: 5025280 events read in total (183926ms).
[17:15:56.636] <TB0> INFO: Test took 184813ms.
[17:16:16.573] <TB0> INFO: ROC 0 VthrComp = 128
[17:16:16.573] <TB0> INFO: ROC 1 VthrComp = 125
[17:16:16.574] <TB0> INFO: ROC 2 VthrComp = 108
[17:16:16.574] <TB0> INFO: ROC 3 VthrComp = 107
[17:16:16.574] <TB0> INFO: ROC 4 VthrComp = 121
[17:16:16.574] <TB0> INFO: ROC 5 VthrComp = 118
[17:16:16.574] <TB0> INFO: ROC 6 VthrComp = 106
[17:16:16.574] <TB0> INFO: ROC 7 VthrComp = 114
[17:16:16.574] <TB0> INFO: ROC 8 VthrComp = 108
[17:16:16.574] <TB0> INFO: ROC 9 VthrComp = 126
[17:16:16.574] <TB0> INFO: ROC 10 VthrComp = 124
[17:16:16.574] <TB0> INFO: ROC 11 VthrComp = 126
[17:16:16.575] <TB0> INFO: ROC 12 VthrComp = 120
[17:16:16.575] <TB0> INFO: ROC 13 VthrComp = 122
[17:16:16.575] <TB0> INFO: ROC 14 VthrComp = 123
[17:16:16.575] <TB0> INFO: ROC 15 VthrComp = 112
[17:16:16.820] <TB0> INFO: Expecting 41600 events.
[17:16:20.249] <TB0> INFO: 41600 events read in total (2838ms).
[17:16:20.250] <TB0> INFO: Test took 3674ms.
[17:16:20.259] <TB0> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[17:16:20.259] <TB0> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[17:16:20.269] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:16:20.269] <TB0> INFO: run 1 of 1
[17:16:20.547] <TB0> INFO: Expecting 5025280 events.
[17:16:46.851] <TB0> INFO: 589272 events read in total (25713ms).
[17:17:12.273] <TB0> INFO: 1178328 events read in total (51136ms).
[17:17:37.563] <TB0> INFO: 1766816 events read in total (76425ms).
[17:18:02.970] <TB0> INFO: 2355432 events read in total (101832ms).
[17:18:28.163] <TB0> INFO: 2942280 events read in total (127025ms).
[17:18:53.755] <TB0> INFO: 3528176 events read in total (152617ms).
[17:19:18.983] <TB0> INFO: 4113232 events read in total (177845ms).
[17:19:44.173] <TB0> INFO: 4697488 events read in total (203035ms).
[17:19:58.377] <TB0> INFO: 5025280 events read in total (217239ms).
[17:19:58.434] <TB0> INFO: Test took 218166ms.
[17:20:25.799] <TB0> INFO: roc 0 with ID = 0 has maximal Vcal 62.4604 for pixel 50/0 mean/min/max = 47.2795/31.6968/62.8622
[17:20:25.800] <TB0> INFO: roc 1 with ID = 1 has maximal Vcal 60.552 for pixel 18/78 mean/min/max = 45.2961/29.9538/60.6385
[17:20:25.800] <TB0> INFO: roc 2 with ID = 2 has maximal Vcal 61.5709 for pixel 6/16 mean/min/max = 48.0634/34.4899/61.6369
[17:20:25.800] <TB0> INFO: roc 3 with ID = 3 has maximal Vcal 63.5776 for pixel 9/5 mean/min/max = 48.9168/34.1068/63.7268
[17:20:25.801] <TB0> INFO: roc 4 with ID = 4 has maximal Vcal 62.4324 for pixel 0/2 mean/min/max = 46.7326/30.9549/62.5102
[17:20:25.801] <TB0> INFO: roc 5 with ID = 5 has maximal Vcal 59.1559 for pixel 28/0 mean/min/max = 45.4122/31.4787/59.3456
[17:20:25.801] <TB0> INFO: roc 6 with ID = 6 has maximal Vcal 58.4044 for pixel 9/2 mean/min/max = 46.6627/34.8501/58.4754
[17:20:25.802] <TB0> INFO: roc 7 with ID = 7 has maximal Vcal 62.5381 for pixel 25/0 mean/min/max = 47.2736/31.8685/62.6787
[17:20:25.802] <TB0> INFO: roc 8 with ID = 8 has maximal Vcal 65.8378 for pixel 0/5 mean/min/max = 49.8468/33.6742/66.0194
[17:20:25.803] <TB0> INFO: roc 9 with ID = 9 has maximal Vcal 63.0483 for pixel 1/12 mean/min/max = 46.512/29.7757/63.2484
[17:20:25.803] <TB0> INFO: roc 10 with ID = 10 has maximal Vcal 60.2125 for pixel 41/1 mean/min/max = 45.8025/31.3228/60.2821
[17:20:25.803] <TB0> INFO: roc 11 with ID = 11 has maximal Vcal 59.5754 for pixel 9/6 mean/min/max = 44.9975/30.19/59.805
[17:20:25.804] <TB0> INFO: roc 12 with ID = 12 has maximal Vcal 59.8086 for pixel 10/4 mean/min/max = 45.8908/31.4797/60.3019
[17:20:25.804] <TB0> INFO: roc 13 with ID = 13 has maximal Vcal 58.3913 for pixel 20/2 mean/min/max = 45.002/31.5246/58.4793
[17:20:25.804] <TB0> INFO: roc 14 with ID = 14 has maximal Vcal 60.5248 for pixel 0/14 mean/min/max = 45.6455/30.4252/60.8658
[17:20:25.805] <TB0> INFO: roc 15 with ID = 15 has maximal Vcal 60.8428 for pixel 1/19 mean/min/max = 46.4733/32.0516/60.8949
[17:20:25.805] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:20:25.894] <TB0> INFO: Expecting 411648 events.
[17:20:35.366] <TB0> INFO: 411648 events read in total (8876ms).
[17:20:35.375] <TB0> INFO: Expecting 411648 events.
[17:20:44.588] <TB0> INFO: 411648 events read in total (8810ms).
[17:20:44.600] <TB0> INFO: Expecting 411648 events.
[17:20:53.933] <TB0> INFO: 411648 events read in total (8930ms).
[17:20:53.948] <TB0> INFO: Expecting 411648 events.
[17:21:03.050] <TB0> INFO: 411648 events read in total (8699ms).
[17:21:03.063] <TB0> INFO: Expecting 411648 events.
[17:21:12.172] <TB0> INFO: 411648 events read in total (8706ms).
[17:21:12.189] <TB0> INFO: Expecting 411648 events.
[17:21:21.285] <TB0> INFO: 411648 events read in total (8693ms).
[17:21:21.305] <TB0> INFO: Expecting 411648 events.
[17:21:30.309] <TB0> INFO: 411648 events read in total (8601ms).
[17:21:30.331] <TB0> INFO: Expecting 411648 events.
[17:21:39.359] <TB0> INFO: 411648 events read in total (8625ms).
[17:21:39.384] <TB0> INFO: Expecting 411648 events.
[17:21:48.422] <TB0> INFO: 411648 events read in total (8635ms).
[17:21:48.461] <TB0> INFO: Expecting 411648 events.
[17:21:57.488] <TB0> INFO: 411648 events read in total (8624ms).
[17:21:57.517] <TB0> INFO: Expecting 411648 events.
[17:22:06.543] <TB0> INFO: 411648 events read in total (8623ms).
[17:22:06.577] <TB0> INFO: Expecting 411648 events.
[17:22:15.598] <TB0> INFO: 411648 events read in total (8618ms).
[17:22:15.633] <TB0> INFO: Expecting 411648 events.
[17:22:24.630] <TB0> INFO: 411648 events read in total (8594ms).
[17:22:24.667] <TB0> INFO: Expecting 411648 events.
[17:22:33.705] <TB0> INFO: 411648 events read in total (8634ms).
[17:22:33.761] <TB0> INFO: Expecting 411648 events.
[17:22:42.772] <TB0> INFO: 411648 events read in total (8608ms).
[17:22:42.816] <TB0> INFO: Expecting 411648 events.
[17:22:51.933] <TB0> INFO: 411648 events read in total (8714ms).
[17:22:51.990] <TB0> INFO: Test took 146185ms.
[17:22:52.728] <TB0> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[17:22:52.740] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:22:52.740] <TB0> INFO: run 1 of 1
[17:22:52.972] <TB0> INFO: Expecting 5025280 events.
[17:23:18.814] <TB0> INFO: 589736 events read in total (25251ms).
[17:23:44.448] <TB0> INFO: 1178144 events read in total (50885ms).
[17:24:10.013] <TB0> INFO: 1764208 events read in total (76450ms).
[17:24:35.600] <TB0> INFO: 2351256 events read in total (102037ms).
[17:25:01.221] <TB0> INFO: 2939656 events read in total (127658ms).
[17:25:27.093] <TB0> INFO: 3530856 events read in total (153530ms).
[17:25:52.798] <TB0> INFO: 4122984 events read in total (179235ms).
[17:26:18.600] <TB0> INFO: 4715512 events read in total (205037ms).
[17:26:32.193] <TB0> INFO: 5025280 events read in total (218630ms).
[17:26:32.322] <TB0> INFO: Test took 219583ms.
[17:26:56.525] <TB0> INFO: ---> TrimStepCorr4 extremal thresholds: 0.359110 .. 147.260171
[17:26:56.796] <TB0> INFO: Expecting 208000 events.
[17:27:06.286] <TB0> INFO: 208000 events read in total (8898ms).
[17:27:06.287] <TB0> INFO: Test took 9761ms.
[17:27:06.367] <TB0> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 0 .. 157 (-1/-1) hits flags = 528 (plus default)
[17:27:06.381] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:27:06.381] <TB0> INFO: run 1 of 1
[17:27:06.690] <TB0> INFO: Expecting 5258240 events.
[17:27:32.685] <TB0> INFO: 585056 events read in total (25403ms).
[17:27:58.025] <TB0> INFO: 1170096 events read in total (50743ms).
[17:28:23.355] <TB0> INFO: 1755480 events read in total (76073ms).
[17:28:49.062] <TB0> INFO: 2340736 events read in total (101781ms).
[17:29:14.537] <TB0> INFO: 2925744 events read in total (127255ms).
[17:29:39.665] <TB0> INFO: 3509600 events read in total (152383ms).
[17:30:04.640] <TB0> INFO: 4093856 events read in total (177358ms).
[17:30:30.009] <TB0> INFO: 4677464 events read in total (202727ms).
[17:30:55.482] <TB0> INFO: 5258240 events read in total (228200ms).
[17:30:55.599] <TB0> INFO: Test took 229218ms.
[17:31:22.766] <TB0> INFO: ---> TrimStepCorr2 extremal thresholds: 26.681762 .. 45.572952
[17:31:23.023] <TB0> INFO: Expecting 208000 events.
[17:31:32.814] <TB0> INFO: 208000 events read in total (9199ms).
[17:31:32.815] <TB0> INFO: Test took 10047ms.
[17:31:32.862] <TB0> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 55 (-1/-1) hits flags = 528 (plus default)
[17:31:32.873] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:31:32.873] <TB0> INFO: run 1 of 1
[17:31:33.151] <TB0> INFO: Expecting 1331200 events.
[17:32:01.094] <TB0> INFO: 663192 events read in total (27352ms).
[17:32:28.650] <TB0> INFO: 1323720 events read in total (54909ms).
[17:32:29.415] <TB0> INFO: 1331200 events read in total (55674ms).
[17:32:29.441] <TB0> INFO: Test took 56569ms.
[17:32:43.357] <TB0> INFO: ---> TrimStepCorr1a extremal thresholds: 26.283605 .. 46.658649
[17:32:43.612] <TB0> INFO: Expecting 208000 events.
[17:32:53.159] <TB0> INFO: 208000 events read in total (8955ms).
[17:32:53.160] <TB0> INFO: Test took 9801ms.
[17:32:53.205] <TB0> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 56 (-1/-1) hits flags = 528 (plus default)
[17:32:53.217] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:32:53.217] <TB0> INFO: run 1 of 1
[17:32:53.496] <TB0> INFO: Expecting 1364480 events.
[17:33:22.210] <TB0> INFO: 659648 events read in total (28123ms).
[17:33:49.394] <TB0> INFO: 1316880 events read in total (55307ms).
[17:33:51.729] <TB0> INFO: 1364480 events read in total (57643ms).
[17:33:51.752] <TB0> INFO: Test took 58536ms.
[17:34:05.025] <TB0> INFO: ---> TrimStepCorr1b extremal thresholds: 25.306538 .. 44.313352
[17:34:05.288] <TB0> INFO: Expecting 208000 events.
[17:34:15.188] <TB0> INFO: 208000 events read in total (9309ms).
[17:34:15.189] <TB0> INFO: Test took 10162ms.
[17:34:15.241] <TB0> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 15 .. 54 (-1/-1) hits flags = 528 (plus default)
[17:34:15.252] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:34:15.252] <TB0> INFO: run 1 of 1
[17:34:15.530] <TB0> INFO: Expecting 1331200 events.
[17:34:43.461] <TB0> INFO: 670624 events read in total (27339ms).
[17:35:10.576] <TB0> INFO: 1331200 events read in total (54454ms).
[17:35:10.602] <TB0> INFO: Test took 55350ms.
[17:35:24.244] <TB0> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[17:35:24.244] <TB0> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[17:35:24.254] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:35:24.255] <TB0> INFO: run 1 of 1
[17:35:24.487] <TB0> INFO: Expecting 1364480 events.
[17:35:52.415] <TB0> INFO: 667216 events read in total (27336ms).
[17:36:20.077] <TB0> INFO: 1333232 events read in total (54998ms).
[17:36:21.729] <TB0> INFO: 1364480 events read in total (56650ms).
[17:36:21.756] <TB0> INFO: Test took 57502ms.
[17:36:35.103] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C0.dat
[17:36:35.103] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C1.dat
[17:36:35.103] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C2.dat
[17:36:35.103] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C3.dat
[17:36:35.103] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C4.dat
[17:36:35.103] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C5.dat
[17:36:35.103] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C6.dat
[17:36:35.103] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C7.dat
[17:36:35.104] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C8.dat
[17:36:35.104] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C9.dat
[17:36:35.104] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C10.dat
[17:36:35.104] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C11.dat
[17:36:35.104] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C12.dat
[17:36:35.104] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C13.dat
[17:36:35.104] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C14.dat
[17:36:35.104] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C15.dat
[17:36:35.104] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C0.dat
[17:36:35.110] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C1.dat
[17:36:35.115] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C2.dat
[17:36:35.121] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C3.dat
[17:36:35.127] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C4.dat
[17:36:35.134] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C5.dat
[17:36:35.140] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C6.dat
[17:36:35.145] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C7.dat
[17:36:35.153] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C8.dat
[17:36:35.160] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C9.dat
[17:36:35.167] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C10.dat
[17:36:35.174] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C11.dat
[17:36:35.180] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C12.dat
[17:36:35.185] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C13.dat
[17:36:35.191] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C14.dat
[17:36:35.197] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//trimParameters35_C15.dat
[17:36:35.202] <TB0> INFO: PixTestTrim::trimTest() done
[17:36:35.202] <TB0> INFO: vtrim: 153 147 125 140 146 142 111 168 132 133 142 129 126 136 125 153
[17:36:35.202] <TB0> INFO: vthrcomp: 128 125 108 107 121 118 106 114 108 126 124 126 120 122 123 112
[17:36:35.202] <TB0> INFO: vcal mean: 34.85 34.91 35.00 35.11 34.96 34.93 35.04 35.06 35.04 34.90 34.96 34.96 34.91 34.97 34.90 35.00
[17:36:35.202] <TB0> INFO: vcal RMS: 1.19 1.17 0.93 1.14 1.25 1.12 0.88 1.36 1.11 1.18 1.20 1.32 1.14 1.14 1.15 1.07
[17:36:35.202] <TB0> INFO: bits mean: 10.05 10.47 8.77 9.44 9.88 10.09 8.80 10.49 8.31 9.96 9.86 10.19 9.57 10.58 9.49 9.99
[17:36:35.202] <TB0> INFO: bits RMS: 2.36 2.48 2.55 2.31 2.58 2.55 2.56 2.18 2.70 2.64 2.61 2.63 2.73 2.31 2.90 2.42
[17:36:35.209] <TB0> INFO: ----------------------------------------------------------------------
[17:36:35.209] <TB0> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[17:36:35.209] <TB0> INFO: ----------------------------------------------------------------------
[17:36:35.211] <TB0> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[17:36:35.221] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[17:36:35.221] <TB0> INFO: run 1 of 1
[17:36:35.453] <TB0> INFO: Expecting 4160000 events.
[17:37:07.020] <TB0> INFO: 736305 events read in total (30975ms).
[17:37:37.770] <TB0> INFO: 1465270 events read in total (61725ms).
[17:38:08.496] <TB0> INFO: 2190875 events read in total (92451ms).
[17:38:39.107] <TB0> INFO: 2912615 events read in total (123062ms).
[17:39:09.747] <TB0> INFO: 3633400 events read in total (153702ms).
[17:39:32.372] <TB0> INFO: 4160000 events read in total (176327ms).
[17:39:32.491] <TB0> INFO: Test took 177270ms.
[17:39:59.044] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[17:39:59.056] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[17:39:59.056] <TB0> INFO: run 1 of 1
[17:39:59.326] <TB0> INFO: Expecting 4139200 events.
[17:40:30.054] <TB0> INFO: 714715 events read in total (30130ms).
[17:41:00.299] <TB0> INFO: 1423225 events read in total (60375ms).
[17:41:30.621] <TB0> INFO: 2129410 events read in total (90697ms).
[17:42:00.888] <TB0> INFO: 2832110 events read in total (120964ms).
[17:42:31.105] <TB0> INFO: 3534290 events read in total (151181ms).
[17:42:57.225] <TB0> INFO: 4139200 events read in total (177301ms).
[17:42:57.321] <TB0> INFO: Test took 178266ms.
[17:43:24.336] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 194 (-1/-1) hits flags = 528 (plus default)
[17:43:24.346] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[17:43:24.346] <TB0> INFO: run 1 of 1
[17:43:24.623] <TB0> INFO: Expecting 4056000 events.
[17:43:56.050] <TB0> INFO: 720000 events read in total (30836ms).
[17:44:26.430] <TB0> INFO: 1433405 events read in total (61216ms).
[17:44:56.624] <TB0> INFO: 2144375 events read in total (91410ms).
[17:45:27.638] <TB0> INFO: 2851820 events read in total (122424ms).
[17:45:57.813] <TB0> INFO: 3558400 events read in total (152599ms).
[17:46:19.026] <TB0> INFO: 4056000 events read in total (173812ms).
[17:46:19.118] <TB0> INFO: Test took 174772ms.
[17:46:45.343] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 193 (-1/-1) hits flags = 528 (plus default)
[17:46:45.352] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[17:46:45.352] <TB0> INFO: run 1 of 1
[17:46:45.585] <TB0> INFO: Expecting 4035200 events.
[17:47:17.126] <TB0> INFO: 721310 events read in total (30950ms).
[17:47:47.516] <TB0> INFO: 1436035 events read in total (61340ms).
[17:48:18.252] <TB0> INFO: 2148305 events read in total (92076ms).
[17:48:48.610] <TB0> INFO: 2857015 events read in total (122434ms).
[17:49:18.917] <TB0> INFO: 3564685 events read in total (152741ms).
[17:49:38.911] <TB0> INFO: 4035200 events read in total (172735ms).
[17:49:39.013] <TB0> INFO: Test took 173661ms.
[17:50:07.727] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 195 (-1/-1) hits flags = 528 (plus default)
[17:50:07.737] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[17:50:07.737] <TB0> INFO: run 1 of 1
[17:50:08.005] <TB0> INFO: Expecting 4076800 events.
[17:50:39.150] <TB0> INFO: 718895 events read in total (30553ms).
[17:51:09.420] <TB0> INFO: 1431100 events read in total (60823ms).
[17:51:39.935] <TB0> INFO: 2141000 events read in total (91338ms).
[17:52:10.199] <TB0> INFO: 2847025 events read in total (121602ms).
[17:52:40.575] <TB0> INFO: 3552400 events read in total (151978ms).
[17:53:03.424] <TB0> INFO: 4076800 events read in total (174827ms).
[17:53:03.546] <TB0> INFO: Test took 175810ms.
[17:53:30.671] <TB0> INFO: PixTestTrim::trimBitTest() done
[17:53:30.672] <TB0> INFO: PixTestTrim::doTest() done, duration: 2438 seconds
[17:53:30.672] <TB0> INFO: Decoding statistics:
[17:53:30.672] <TB0> INFO: General information:
[17:53:30.672] <TB0> INFO: 16bit words read: 0
[17:53:30.672] <TB0> INFO: valid events total: 0
[17:53:30.672] <TB0> INFO: empty events: 0
[17:53:30.672] <TB0> INFO: valid events with pixels: 0
[17:53:30.672] <TB0> INFO: valid pixel hits: 0
[17:53:30.672] <TB0> INFO: Event errors: 0
[17:53:30.672] <TB0> INFO: start marker: 0
[17:53:30.672] <TB0> INFO: stop marker: 0
[17:53:30.672] <TB0> INFO: overflow: 0
[17:53:30.672] <TB0> INFO: invalid 5bit words: 0
[17:53:30.672] <TB0> INFO: invalid XOR eye diagram: 0
[17:53:30.672] <TB0> INFO: frame (failed synchr.): 0
[17:53:30.672] <TB0> INFO: idle data (no TBM trl): 0
[17:53:30.672] <TB0> INFO: no data (only TBM hdr): 0
[17:53:30.672] <TB0> INFO: TBM errors: 0
[17:53:30.672] <TB0> INFO: flawed TBM headers: 0
[17:53:30.672] <TB0> INFO: flawed TBM trailers: 0
[17:53:30.672] <TB0> INFO: event ID mismatches: 0
[17:53:30.672] <TB0> INFO: ROC errors: 0
[17:53:30.672] <TB0> INFO: missing ROC header(s): 0
[17:53:30.672] <TB0> INFO: misplaced readback start: 0
[17:53:30.672] <TB0> INFO: Pixel decoding errors: 0
[17:53:30.672] <TB0> INFO: pixel data incomplete: 0
[17:53:30.672] <TB0> INFO: pixel address: 0
[17:53:30.672] <TB0> INFO: pulse height fill bit: 0
[17:53:30.672] <TB0> INFO: buffer corruption: 0
[17:53:31.327] <TB0> INFO: ######################################################################
[17:53:31.327] <TB0> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[17:53:31.327] <TB0> INFO: ######################################################################
[17:53:31.588] <TB0> INFO: Expecting 41600 events.
[17:53:35.192] <TB0> INFO: 41600 events read in total (3012ms).
[17:53:35.193] <TB0> INFO: Test took 3864ms.
[17:53:35.628] <TB0> INFO: Expecting 41600 events.
[17:53:39.164] <TB0> INFO: 41600 events read in total (2944ms).
[17:53:39.165] <TB0> INFO: Test took 3769ms.
[17:53:39.453] <TB0> INFO: Expecting 41600 events.
[17:53:42.985] <TB0> INFO: 41600 events read in total (2940ms).
[17:53:42.985] <TB0> INFO: Test took 3796ms.
[17:53:43.273] <TB0> INFO: Expecting 41600 events.
[17:53:46.725] <TB0> INFO: 41600 events read in total (2860ms).
[17:53:46.725] <TB0> INFO: Test took 3716ms.
[17:53:47.013] <TB0> INFO: Expecting 41600 events.
[17:53:50.471] <TB0> INFO: 41600 events read in total (2866ms).
[17:53:50.472] <TB0> INFO: Test took 3723ms.
[17:53:50.759] <TB0> INFO: Expecting 41600 events.
[17:53:54.280] <TB0> INFO: 41600 events read in total (2929ms).
[17:53:54.281] <TB0> INFO: Test took 3786ms.
[17:53:54.571] <TB0> INFO: Expecting 41600 events.
[17:53:58.182] <TB0> INFO: 41600 events read in total (3019ms).
[17:53:58.182] <TB0> INFO: Test took 3875ms.
[17:53:58.470] <TB0> INFO: Expecting 41600 events.
[17:54:01.985] <TB0> INFO: 41600 events read in total (2923ms).
[17:54:01.986] <TB0> INFO: Test took 3780ms.
[17:54:02.273] <TB0> INFO: Expecting 41600 events.
[17:54:05.741] <TB0> INFO: 41600 events read in total (2876ms).
[17:54:05.741] <TB0> INFO: Test took 3732ms.
[17:54:06.029] <TB0> INFO: Expecting 41600 events.
[17:54:09.560] <TB0> INFO: 41600 events read in total (2939ms).
[17:54:09.561] <TB0> INFO: Test took 3796ms.
[17:54:09.850] <TB0> INFO: Expecting 41600 events.
[17:54:13.314] <TB0> INFO: 41600 events read in total (2873ms).
[17:54:13.314] <TB0> INFO: Test took 3729ms.
[17:54:13.602] <TB0> INFO: Expecting 41600 events.
[17:54:17.065] <TB0> INFO: 41600 events read in total (2871ms).
[17:54:17.066] <TB0> INFO: Test took 3728ms.
[17:54:17.354] <TB0> INFO: Expecting 41600 events.
[17:54:20.818] <TB0> INFO: 41600 events read in total (2873ms).
[17:54:20.819] <TB0> INFO: Test took 3730ms.
[17:54:21.107] <TB0> INFO: Expecting 41600 events.
[17:54:24.601] <TB0> INFO: 41600 events read in total (2902ms).
[17:54:24.602] <TB0> INFO: Test took 3760ms.
[17:54:24.890] <TB0> INFO: Expecting 41600 events.
[17:54:28.459] <TB0> INFO: 41600 events read in total (2978ms).
[17:54:28.461] <TB0> INFO: Test took 3836ms.
[17:54:28.748] <TB0> INFO: Expecting 41600 events.
[17:54:32.189] <TB0> INFO: 41600 events read in total (2849ms).
[17:54:32.190] <TB0> INFO: Test took 3706ms.
[17:54:32.478] <TB0> INFO: Expecting 41600 events.
[17:54:35.998] <TB0> INFO: 41600 events read in total (2928ms).
[17:54:35.998] <TB0> INFO: Test took 3785ms.
[17:54:36.287] <TB0> INFO: Expecting 41600 events.
[17:54:39.882] <TB0> INFO: 41600 events read in total (3004ms).
[17:54:39.882] <TB0> INFO: Test took 3860ms.
[17:54:40.182] <TB0> INFO: Expecting 41600 events.
[17:54:43.864] <TB0> INFO: 41600 events read in total (3090ms).
[17:54:43.865] <TB0> INFO: Test took 3959ms.
[17:54:44.156] <TB0> INFO: Expecting 41600 events.
[17:54:47.671] <TB0> INFO: 41600 events read in total (2924ms).
[17:54:47.671] <TB0> INFO: Test took 3780ms.
[17:54:47.962] <TB0> INFO: Expecting 41600 events.
[17:54:51.496] <TB0> INFO: 41600 events read in total (2942ms).
[17:54:51.497] <TB0> INFO: Test took 3799ms.
[17:54:51.785] <TB0> INFO: Expecting 41600 events.
[17:54:55.234] <TB0> INFO: 41600 events read in total (2857ms).
[17:54:55.235] <TB0> INFO: Test took 3715ms.
[17:54:55.523] <TB0> INFO: Expecting 41600 events.
[17:54:59.098] <TB0> INFO: 41600 events read in total (2984ms).
[17:54:59.098] <TB0> INFO: Test took 3840ms.
[17:54:59.389] <TB0> INFO: Expecting 41600 events.
[17:55:02.919] <TB0> INFO: 41600 events read in total (2938ms).
[17:55:02.920] <TB0> INFO: Test took 3796ms.
[17:55:03.217] <TB0> INFO: Expecting 41600 events.
[17:55:06.773] <TB0> INFO: 41600 events read in total (2964ms).
[17:55:06.774] <TB0> INFO: Test took 3830ms.
[17:55:07.062] <TB0> INFO: Expecting 41600 events.
[17:55:10.541] <TB0> INFO: 41600 events read in total (2887ms).
[17:55:10.542] <TB0> INFO: Test took 3744ms.
[17:55:10.842] <TB0> INFO: Expecting 41600 events.
[17:55:14.381] <TB0> INFO: 41600 events read in total (2947ms).
[17:55:14.381] <TB0> INFO: Test took 3811ms.
[17:55:14.670] <TB0> INFO: Expecting 41600 events.
[17:55:18.141] <TB0> INFO: 41600 events read in total (2879ms).
[17:55:18.142] <TB0> INFO: Test took 3737ms.
[17:55:18.432] <TB0> INFO: Expecting 41600 events.
[17:55:21.922] <TB0> INFO: 41600 events read in total (2898ms).
[17:55:21.923] <TB0> INFO: Test took 3756ms.
[17:55:22.212] <TB0> INFO: Expecting 41600 events.
[17:55:25.756] <TB0> INFO: 41600 events read in total (2953ms).
[17:55:25.757] <TB0> INFO: Test took 3810ms.
[17:55:26.048] <TB0> INFO: Expecting 2560 events.
[17:55:26.931] <TB0> INFO: 2560 events read in total (291ms).
[17:55:26.931] <TB0> INFO: Test took 1160ms.
[17:55:27.239] <TB0> INFO: Expecting 2560 events.
[17:55:28.121] <TB0> INFO: 2560 events read in total (290ms).
[17:55:28.122] <TB0> INFO: Test took 1191ms.
[17:55:28.430] <TB0> INFO: Expecting 2560 events.
[17:55:29.312] <TB0> INFO: 2560 events read in total (291ms).
[17:55:29.312] <TB0> INFO: Test took 1190ms.
[17:55:29.620] <TB0> INFO: Expecting 2560 events.
[17:55:30.502] <TB0> INFO: 2560 events read in total (291ms).
[17:55:30.502] <TB0> INFO: Test took 1189ms.
[17:55:30.810] <TB0> INFO: Expecting 2560 events.
[17:55:31.690] <TB0> INFO: 2560 events read in total (288ms).
[17:55:31.690] <TB0> INFO: Test took 1187ms.
[17:55:31.998] <TB0> INFO: Expecting 2560 events.
[17:55:32.877] <TB0> INFO: 2560 events read in total (288ms).
[17:55:32.877] <TB0> INFO: Test took 1187ms.
[17:55:33.185] <TB0> INFO: Expecting 2560 events.
[17:55:34.065] <TB0> INFO: 2560 events read in total (288ms).
[17:55:34.065] <TB0> INFO: Test took 1187ms.
[17:55:34.373] <TB0> INFO: Expecting 2560 events.
[17:55:35.254] <TB0> INFO: 2560 events read in total (288ms).
[17:55:35.254] <TB0> INFO: Test took 1188ms.
[17:55:35.562] <TB0> INFO: Expecting 2560 events.
[17:55:36.443] <TB0> INFO: 2560 events read in total (289ms).
[17:55:36.443] <TB0> INFO: Test took 1189ms.
[17:55:36.751] <TB0> INFO: Expecting 2560 events.
[17:55:37.634] <TB0> INFO: 2560 events read in total (291ms).
[17:55:37.634] <TB0> INFO: Test took 1190ms.
[17:55:37.942] <TB0> INFO: Expecting 2560 events.
[17:55:38.824] <TB0> INFO: 2560 events read in total (291ms).
[17:55:38.824] <TB0> INFO: Test took 1190ms.
[17:55:39.132] <TB0> INFO: Expecting 2560 events.
[17:55:40.013] <TB0> INFO: 2560 events read in total (289ms).
[17:55:40.013] <TB0> INFO: Test took 1189ms.
[17:55:40.321] <TB0> INFO: Expecting 2560 events.
[17:55:41.204] <TB0> INFO: 2560 events read in total (291ms).
[17:55:41.204] <TB0> INFO: Test took 1191ms.
[17:55:41.512] <TB0> INFO: Expecting 2560 events.
[17:55:42.394] <TB0> INFO: 2560 events read in total (290ms).
[17:55:42.395] <TB0> INFO: Test took 1191ms.
[17:55:42.702] <TB0> INFO: Expecting 2560 events.
[17:55:43.587] <TB0> INFO: 2560 events read in total (293ms).
[17:55:43.587] <TB0> INFO: Test took 1192ms.
[17:55:43.896] <TB0> INFO: Expecting 2560 events.
[17:55:44.778] <TB0> INFO: 2560 events read in total (291ms).
[17:55:44.778] <TB0> INFO: Test took 1190ms.
[17:55:44.782] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:55:45.088] <TB0> INFO: Expecting 655360 events.
[17:55:59.643] <TB0> INFO: 655360 events read in total (13964ms).
[17:55:59.657] <TB0> INFO: Expecting 655360 events.
[17:56:13.878] <TB0> INFO: 655360 events read in total (13818ms).
[17:56:13.894] <TB0> INFO: Expecting 655360 events.
[17:56:28.094] <TB0> INFO: 655360 events read in total (13797ms).
[17:56:28.116] <TB0> INFO: Expecting 655360 events.
[17:56:42.319] <TB0> INFO: 655360 events read in total (13800ms).
[17:56:42.344] <TB0> INFO: Expecting 655360 events.
[17:56:56.619] <TB0> INFO: 655360 events read in total (13872ms).
[17:56:56.654] <TB0> INFO: Expecting 655360 events.
[17:57:10.840] <TB0> INFO: 655360 events read in total (13783ms).
[17:57:10.874] <TB0> INFO: Expecting 655360 events.
[17:57:25.090] <TB0> INFO: 655360 events read in total (13813ms).
[17:57:25.127] <TB0> INFO: Expecting 655360 events.
[17:57:39.387] <TB0> INFO: 655360 events read in total (13857ms).
[17:57:39.429] <TB0> INFO: Expecting 655360 events.
[17:57:53.604] <TB0> INFO: 655360 events read in total (13772ms).
[17:57:53.676] <TB0> INFO: Expecting 655360 events.
[17:58:07.800] <TB0> INFO: 655360 events read in total (13721ms).
[17:58:07.881] <TB0> INFO: Expecting 655360 events.
[17:58:21.973] <TB0> INFO: 655360 events read in total (13689ms).
[17:58:22.065] <TB0> INFO: Expecting 655360 events.
[17:58:36.271] <TB0> INFO: 655360 events read in total (13803ms).
[17:58:36.411] <TB0> INFO: Expecting 655360 events.
[17:58:50.792] <TB0> INFO: 655360 events read in total (13978ms).
[17:58:50.906] <TB0> INFO: Expecting 655360 events.
[17:59:05.081] <TB0> INFO: 655360 events read in total (13772ms).
[17:59:05.194] <TB0> INFO: Expecting 655360 events.
[17:59:19.470] <TB0> INFO: 655360 events read in total (13873ms).
[17:59:19.589] <TB0> INFO: Expecting 655360 events.
[17:59:33.732] <TB0> INFO: 655360 events read in total (13740ms).
[17:59:33.907] <TB0> INFO: Test took 229126ms.
[17:59:33.986] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:59:34.249] <TB0> INFO: Expecting 655360 events.
[17:59:48.536] <TB0> INFO: 655360 events read in total (13695ms).
[17:59:48.552] <TB0> INFO: Expecting 655360 events.
[18:00:02.483] <TB0> INFO: 655360 events read in total (13528ms).
[18:00:02.500] <TB0> INFO: Expecting 655360 events.
[18:00:16.577] <TB0> INFO: 655360 events read in total (13675ms).
[18:00:16.597] <TB0> INFO: Expecting 655360 events.
[18:00:30.724] <TB0> INFO: 655360 events read in total (13724ms).
[18:00:30.750] <TB0> INFO: Expecting 655360 events.
[18:00:44.612] <TB0> INFO: 655360 events read in total (13459ms).
[18:00:44.651] <TB0> INFO: Expecting 655360 events.
[18:00:58.738] <TB0> INFO: 655360 events read in total (13684ms).
[18:00:58.770] <TB0> INFO: Expecting 655360 events.
[18:01:12.945] <TB0> INFO: 655360 events read in total (13772ms).
[18:01:12.995] <TB0> INFO: Expecting 655360 events.
[18:01:26.907] <TB0> INFO: 655360 events read in total (13510ms).
[18:01:26.947] <TB0> INFO: Expecting 655360 events.
[18:01:40.995] <TB0> INFO: 655360 events read in total (13645ms).
[18:01:41.071] <TB0> INFO: Expecting 655360 events.
[18:01:55.031] <TB0> INFO: 655360 events read in total (13557ms).
[18:01:55.113] <TB0> INFO: Expecting 655360 events.
[18:02:09.094] <TB0> INFO: 655360 events read in total (13578ms).
[18:02:09.184] <TB0> INFO: Expecting 655360 events.
[18:02:22.993] <TB0> INFO: 655360 events read in total (13406ms).
[18:02:23.051] <TB0> INFO: Expecting 655360 events.
[18:02:37.090] <TB0> INFO: 655360 events read in total (13636ms).
[18:02:37.152] <TB0> INFO: Expecting 655360 events.
[18:02:51.178] <TB0> INFO: 655360 events read in total (13623ms).
[18:02:51.243] <TB0> INFO: Expecting 655360 events.
[18:03:05.317] <TB0> INFO: 655360 events read in total (13671ms).
[18:03:05.386] <TB0> INFO: Expecting 655360 events.
[18:03:19.326] <TB0> INFO: 655360 events read in total (13537ms).
[18:03:19.401] <TB0> INFO: Test took 225415ms.
[18:03:19.557] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.562] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.567] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.571] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.576] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.580] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.585] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[18:03:19.589] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[18:03:19.594] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[18:03:19.598] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[18:03:19.602] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.607] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.611] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[18:03:19.616] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[18:03:19.620] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[18:03:19.625] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[18:03:19.630] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.634] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.638] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.643] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.647] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.652] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[18:03:19.656] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.661] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.665] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[18:03:19.670] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:03:19.702] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C0.dat
[18:03:19.702] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C1.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C2.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C3.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C4.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C5.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C6.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C7.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C8.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C9.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C10.dat
[18:03:19.703] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C11.dat
[18:03:19.704] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C12.dat
[18:03:19.704] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C13.dat
[18:03:19.704] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C14.dat
[18:03:19.704] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//dacParameters35_C15.dat
[18:03:19.943] <TB0> INFO: Expecting 41600 events.
[18:03:23.049] <TB0> INFO: 41600 events read in total (2516ms).
[18:03:23.050] <TB0> INFO: Test took 3344ms.
[18:03:23.495] <TB0> INFO: Expecting 41600 events.
[18:03:26.521] <TB0> INFO: 41600 events read in total (2435ms).
[18:03:26.522] <TB0> INFO: Test took 3260ms.
[18:03:27.012] <TB0> INFO: Expecting 41600 events.
[18:03:30.093] <TB0> INFO: 41600 events read in total (2489ms).
[18:03:30.094] <TB0> INFO: Test took 3360ms.
[18:03:30.308] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:30.397] <TB0> INFO: Expecting 2560 events.
[18:03:31.284] <TB0> INFO: 2560 events read in total (296ms).
[18:03:31.285] <TB0> INFO: Test took 977ms.
[18:03:31.286] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:31.593] <TB0> INFO: Expecting 2560 events.
[18:03:32.476] <TB0> INFO: 2560 events read in total (291ms).
[18:03:32.477] <TB0> INFO: Test took 1191ms.
[18:03:32.478] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:32.785] <TB0> INFO: Expecting 2560 events.
[18:03:33.668] <TB0> INFO: 2560 events read in total (292ms).
[18:03:33.668] <TB0> INFO: Test took 1190ms.
[18:03:33.670] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:33.976] <TB0> INFO: Expecting 2560 events.
[18:03:34.859] <TB0> INFO: 2560 events read in total (291ms).
[18:03:34.859] <TB0> INFO: Test took 1189ms.
[18:03:34.861] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:35.167] <TB0> INFO: Expecting 2560 events.
[18:03:36.049] <TB0> INFO: 2560 events read in total (290ms).
[18:03:36.049] <TB0> INFO: Test took 1188ms.
[18:03:36.051] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:36.357] <TB0> INFO: Expecting 2560 events.
[18:03:37.240] <TB0> INFO: 2560 events read in total (291ms).
[18:03:37.241] <TB0> INFO: Test took 1190ms.
[18:03:37.242] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:37.549] <TB0> INFO: Expecting 2560 events.
[18:03:38.435] <TB0> INFO: 2560 events read in total (294ms).
[18:03:38.435] <TB0> INFO: Test took 1193ms.
[18:03:38.437] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:38.743] <TB0> INFO: Expecting 2560 events.
[18:03:39.626] <TB0> INFO: 2560 events read in total (291ms).
[18:03:39.627] <TB0> INFO: Test took 1190ms.
[18:03:39.628] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:39.935] <TB0> INFO: Expecting 2560 events.
[18:03:40.812] <TB0> INFO: 2560 events read in total (286ms).
[18:03:40.813] <TB0> INFO: Test took 1185ms.
[18:03:40.815] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:41.121] <TB0> INFO: Expecting 2560 events.
[18:03:41.999] <TB0> INFO: 2560 events read in total (286ms).
[18:03:41.000] <TB0> INFO: Test took 1186ms.
[18:03:41.002] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:42.308] <TB0> INFO: Expecting 2560 events.
[18:03:43.189] <TB0> INFO: 2560 events read in total (289ms).
[18:03:43.189] <TB0> INFO: Test took 1187ms.
[18:03:43.191] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:43.497] <TB0> INFO: Expecting 2560 events.
[18:03:44.375] <TB0> INFO: 2560 events read in total (286ms).
[18:03:44.375] <TB0> INFO: Test took 1184ms.
[18:03:44.377] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:44.683] <TB0> INFO: Expecting 2560 events.
[18:03:45.561] <TB0> INFO: 2560 events read in total (287ms).
[18:03:45.562] <TB0> INFO: Test took 1185ms.
[18:03:45.564] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:45.870] <TB0> INFO: Expecting 2560 events.
[18:03:46.748] <TB0> INFO: 2560 events read in total (286ms).
[18:03:46.749] <TB0> INFO: Test took 1185ms.
[18:03:46.750] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:47.057] <TB0> INFO: Expecting 2560 events.
[18:03:47.936] <TB0> INFO: 2560 events read in total (287ms).
[18:03:47.936] <TB0> INFO: Test took 1186ms.
[18:03:47.938] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:48.244] <TB0> INFO: Expecting 2560 events.
[18:03:49.125] <TB0> INFO: 2560 events read in total (289ms).
[18:03:49.125] <TB0> INFO: Test took 1187ms.
[18:03:49.127] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:49.433] <TB0> INFO: Expecting 2560 events.
[18:03:50.311] <TB0> INFO: 2560 events read in total (286ms).
[18:03:50.311] <TB0> INFO: Test took 1184ms.
[18:03:50.313] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:50.620] <TB0> INFO: Expecting 2560 events.
[18:03:51.498] <TB0> INFO: 2560 events read in total (286ms).
[18:03:51.498] <TB0> INFO: Test took 1185ms.
[18:03:51.501] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:51.806] <TB0> INFO: Expecting 2560 events.
[18:03:52.685] <TB0> INFO: 2560 events read in total (287ms).
[18:03:52.685] <TB0> INFO: Test took 1185ms.
[18:03:52.687] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:52.994] <TB0> INFO: Expecting 2560 events.
[18:03:53.871] <TB0> INFO: 2560 events read in total (286ms).
[18:03:53.872] <TB0> INFO: Test took 1185ms.
[18:03:53.874] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:54.180] <TB0> INFO: Expecting 2560 events.
[18:03:55.057] <TB0> INFO: 2560 events read in total (286ms).
[18:03:55.058] <TB0> INFO: Test took 1184ms.
[18:03:55.059] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:55.366] <TB0> INFO: Expecting 2560 events.
[18:03:56.243] <TB0> INFO: 2560 events read in total (285ms).
[18:03:56.244] <TB0> INFO: Test took 1185ms.
[18:03:56.245] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:56.552] <TB0> INFO: Expecting 2560 events.
[18:03:57.431] <TB0> INFO: 2560 events read in total (288ms).
[18:03:57.432] <TB0> INFO: Test took 1187ms.
[18:03:57.433] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:57.740] <TB0> INFO: Expecting 2560 events.
[18:03:58.622] <TB0> INFO: 2560 events read in total (291ms).
[18:03:58.622] <TB0> INFO: Test took 1189ms.
[18:03:58.624] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:03:58.930] <TB0> INFO: Expecting 2560 events.
[18:03:59.816] <TB0> INFO: 2560 events read in total (294ms).
[18:03:59.816] <TB0> INFO: Test took 1192ms.
[18:03:59.818] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:04:00.125] <TB0> INFO: Expecting 2560 events.
[18:04:01.007] <TB0> INFO: 2560 events read in total (291ms).
[18:04:01.007] <TB0> INFO: Test took 1189ms.
[18:04:01.009] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:04:01.316] <TB0> INFO: Expecting 2560 events.
[18:04:02.202] <TB0> INFO: 2560 events read in total (295ms).
[18:04:02.202] <TB0> INFO: Test took 1193ms.
[18:04:02.204] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:04:02.510] <TB0> INFO: Expecting 2560 events.
[18:04:03.393] <TB0> INFO: 2560 events read in total (291ms).
[18:04:03.393] <TB0> INFO: Test took 1189ms.
[18:04:03.395] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:04:03.702] <TB0> INFO: Expecting 2560 events.
[18:04:04.584] <TB0> INFO: 2560 events read in total (291ms).
[18:04:04.584] <TB0> INFO: Test took 1189ms.
[18:04:04.586] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:04:04.892] <TB0> INFO: Expecting 2560 events.
[18:04:05.777] <TB0> INFO: 2560 events read in total (293ms).
[18:04:05.777] <TB0> INFO: Test took 1191ms.
[18:04:05.779] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:04:06.085] <TB0> INFO: Expecting 2560 events.
[18:04:06.970] <TB0> INFO: 2560 events read in total (293ms).
[18:04:06.970] <TB0> INFO: Test took 1191ms.
[18:04:06.971] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:04:07.278] <TB0> INFO: Expecting 2560 events.
[18:04:08.161] <TB0> INFO: 2560 events read in total (291ms).
[18:04:08.161] <TB0> INFO: Test took 1190ms.
[18:04:08.624] <TB0> INFO: PixTestPhOptimization::doTest() done, duration: 637 seconds
[18:04:08.624] <TB0> INFO: PH scale (per ROC): 67 59 59 48 42 55 59 48 39 61 63 45 60 53 48 76
[18:04:08.624] <TB0> INFO: PH offset (per ROC): 126 137 109 113 99 112 131 143 91 122 132 107 124 135 101 133
[18:04:08.629] <TB0> INFO: Decoding statistics:
[18:04:08.629] <TB0> INFO: General information:
[18:04:08.629] <TB0> INFO: 16bit words read: 127882
[18:04:08.629] <TB0> INFO: valid events total: 20480
[18:04:08.629] <TB0> INFO: empty events: 17979
[18:04:08.629] <TB0> INFO: valid events with pixels: 2501
[18:04:08.629] <TB0> INFO: valid pixel hits: 2501
[18:04:08.629] <TB0> INFO: Event errors: 0
[18:04:08.629] <TB0> INFO: start marker: 0
[18:04:08.629] <TB0> INFO: stop marker: 0
[18:04:08.629] <TB0> INFO: overflow: 0
[18:04:08.629] <TB0> INFO: invalid 5bit words: 0
[18:04:08.629] <TB0> INFO: invalid XOR eye diagram: 0
[18:04:08.629] <TB0> INFO: frame (failed synchr.): 0
[18:04:08.629] <TB0> INFO: idle data (no TBM trl): 0
[18:04:08.629] <TB0> INFO: no data (only TBM hdr): 0
[18:04:08.629] <TB0> INFO: TBM errors: 0
[18:04:08.629] <TB0> INFO: flawed TBM headers: 0
[18:04:08.629] <TB0> INFO: flawed TBM trailers: 0
[18:04:08.629] <TB0> INFO: event ID mismatches: 0
[18:04:08.629] <TB0> INFO: ROC errors: 0
[18:04:08.629] <TB0> INFO: missing ROC header(s): 0
[18:04:08.629] <TB0> INFO: misplaced readback start: 0
[18:04:08.629] <TB0> INFO: Pixel decoding errors: 0
[18:04:08.629] <TB0> INFO: pixel data incomplete: 0
[18:04:08.629] <TB0> INFO: pixel address: 0
[18:04:08.629] <TB0> INFO: pulse height fill bit: 0
[18:04:08.629] <TB0> INFO: buffer corruption: 0
[18:04:08.898] <TB0> INFO: ######################################################################
[18:04:08.898] <TB0> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[18:04:08.898] <TB0> INFO: ######################################################################
[18:04:08.908] <TB0> INFO: scanning low vcal = 10
[18:04:09.141] <TB0> INFO: Expecting 41600 events.
[18:04:12.678] <TB0> INFO: 41600 events read in total (2946ms).
[18:04:12.678] <TB0> INFO: Test took 3770ms.
[18:04:12.680] <TB0> INFO: scanning low vcal = 20
[18:04:12.979] <TB0> INFO: Expecting 41600 events.
[18:04:16.522] <TB0> INFO: 41600 events read in total (2951ms).
[18:04:16.522] <TB0> INFO: Test took 3842ms.
[18:04:16.524] <TB0> INFO: scanning low vcal = 30
[18:04:16.824] <TB0> INFO: Expecting 41600 events.
[18:04:20.478] <TB0> INFO: 41600 events read in total (3063ms).
[18:04:20.479] <TB0> INFO: Test took 3955ms.
[18:04:20.481] <TB0> INFO: scanning low vcal = 40
[18:04:20.758] <TB0> INFO: Expecting 41600 events.
[18:04:24.639] <TB0> INFO: 41600 events read in total (3290ms).
[18:04:24.640] <TB0> INFO: Test took 4159ms.
[18:04:24.643] <TB0> INFO: scanning low vcal = 50
[18:04:24.920] <TB0> INFO: Expecting 41600 events.
[18:04:28.849] <TB0> INFO: 41600 events read in total (3338ms).
[18:04:28.850] <TB0> INFO: Test took 4207ms.
[18:04:28.853] <TB0> INFO: scanning low vcal = 60
[18:04:29.129] <TB0> INFO: Expecting 41600 events.
[18:04:33.071] <TB0> INFO: 41600 events read in total (3350ms).
[18:04:33.072] <TB0> INFO: Test took 4219ms.
[18:04:33.075] <TB0> INFO: scanning low vcal = 70
[18:04:33.353] <TB0> INFO: Expecting 41600 events.
[18:04:37.287] <TB0> INFO: 41600 events read in total (3342ms).
[18:04:37.287] <TB0> INFO: Test took 4212ms.
[18:04:37.290] <TB0> INFO: scanning low vcal = 80
[18:04:37.567] <TB0> INFO: Expecting 41600 events.
[18:04:41.481] <TB0> INFO: 41600 events read in total (3323ms).
[18:04:41.481] <TB0> INFO: Test took 4191ms.
[18:04:41.484] <TB0> INFO: scanning low vcal = 90
[18:04:41.760] <TB0> INFO: Expecting 41600 events.
[18:04:45.704] <TB0> INFO: 41600 events read in total (3352ms).
[18:04:45.705] <TB0> INFO: Test took 4221ms.
[18:04:45.707] <TB0> INFO: scanning low vcal = 100
[18:04:45.984] <TB0> INFO: Expecting 41600 events.
[18:04:49.940] <TB0> INFO: 41600 events read in total (3365ms).
[18:04:49.941] <TB0> INFO: Test took 4234ms.
[18:04:49.943] <TB0> INFO: scanning low vcal = 110
[18:04:50.220] <TB0> INFO: Expecting 41600 events.
[18:04:54.170] <TB0> INFO: 41600 events read in total (3359ms).
[18:04:54.171] <TB0> INFO: Test took 4228ms.
[18:04:54.174] <TB0> INFO: scanning low vcal = 120
[18:04:54.450] <TB0> INFO: Expecting 41600 events.
[18:04:58.357] <TB0> INFO: 41600 events read in total (3315ms).
[18:04:58.358] <TB0> INFO: Test took 4183ms.
[18:04:58.361] <TB0> INFO: scanning low vcal = 130
[18:04:58.637] <TB0> INFO: Expecting 41600 events.
[18:05:02.567] <TB0> INFO: 41600 events read in total (3338ms).
[18:05:02.567] <TB0> INFO: Test took 4206ms.
[18:05:02.571] <TB0> INFO: scanning low vcal = 140
[18:05:02.847] <TB0> INFO: Expecting 41600 events.
[18:05:06.780] <TB0> INFO: 41600 events read in total (3341ms).
[18:05:06.781] <TB0> INFO: Test took 4210ms.
[18:05:06.785] <TB0> INFO: scanning low vcal = 150
[18:05:07.061] <TB0> INFO: Expecting 41600 events.
[18:05:11.025] <TB0> INFO: 41600 events read in total (3372ms).
[18:05:11.026] <TB0> INFO: Test took 4241ms.
[18:05:11.029] <TB0> INFO: scanning low vcal = 160
[18:05:11.305] <TB0> INFO: Expecting 41600 events.
[18:05:15.212] <TB0> INFO: 41600 events read in total (3315ms).
[18:05:15.213] <TB0> INFO: Test took 4184ms.
[18:05:15.216] <TB0> INFO: scanning low vcal = 170
[18:05:15.492] <TB0> INFO: Expecting 41600 events.
[18:05:19.469] <TB0> INFO: 41600 events read in total (3385ms).
[18:05:19.470] <TB0> INFO: Test took 4254ms.
[18:05:19.472] <TB0> INFO: scanning low vcal = 180
[18:05:19.749] <TB0> INFO: Expecting 41600 events.
[18:05:23.728] <TB0> INFO: 41600 events read in total (3387ms).
[18:05:23.728] <TB0> INFO: Test took 4255ms.
[18:05:23.732] <TB0> INFO: scanning low vcal = 190
[18:05:24.008] <TB0> INFO: Expecting 41600 events.
[18:05:27.931] <TB0> INFO: 41600 events read in total (3332ms).
[18:05:27.932] <TB0> INFO: Test took 4200ms.
[18:05:27.935] <TB0> INFO: scanning low vcal = 200
[18:05:28.212] <TB0> INFO: Expecting 41600 events.
[18:05:32.150] <TB0> INFO: 41600 events read in total (3347ms).
[18:05:32.151] <TB0> INFO: Test took 4216ms.
[18:05:32.153] <TB0> INFO: scanning low vcal = 210
[18:05:32.430] <TB0> INFO: Expecting 41600 events.
[18:05:36.340] <TB0> INFO: 41600 events read in total (3318ms).
[18:05:36.341] <TB0> INFO: Test took 4187ms.
[18:05:36.343] <TB0> INFO: scanning low vcal = 220
[18:05:36.620] <TB0> INFO: Expecting 41600 events.
[18:05:40.574] <TB0> INFO: 41600 events read in total (3363ms).
[18:05:40.575] <TB0> INFO: Test took 4232ms.
[18:05:40.578] <TB0> INFO: scanning low vcal = 230
[18:05:40.854] <TB0> INFO: Expecting 41600 events.
[18:05:44.792] <TB0> INFO: 41600 events read in total (3346ms).
[18:05:44.792] <TB0> INFO: Test took 4214ms.
[18:05:44.795] <TB0> INFO: scanning low vcal = 240
[18:05:45.072] <TB0> INFO: Expecting 41600 events.
[18:05:48.980] <TB0> INFO: 41600 events read in total (3317ms).
[18:05:48.981] <TB0> INFO: Test took 4186ms.
[18:05:48.983] <TB0> INFO: scanning low vcal = 250
[18:05:49.260] <TB0> INFO: Expecting 41600 events.
[18:05:53.196] <TB0> INFO: 41600 events read in total (3344ms).
[18:05:53.196] <TB0> INFO: Test took 4212ms.
[18:05:53.200] <TB0> INFO: scanning high vcal = 30 (= 210 in low range)
[18:05:53.476] <TB0> INFO: Expecting 41600 events.
[18:05:57.397] <TB0> INFO: 41600 events read in total (3329ms).
[18:05:57.398] <TB0> INFO: Test took 4198ms.
[18:05:57.400] <TB0> INFO: scanning high vcal = 50 (= 350 in low range)
[18:05:57.677] <TB0> INFO: Expecting 41600 events.
[18:06:01.643] <TB0> INFO: 41600 events read in total (3374ms).
[18:06:01.644] <TB0> INFO: Test took 4244ms.
[18:06:01.646] <TB0> INFO: scanning high vcal = 70 (= 490 in low range)
[18:06:01.923] <TB0> INFO: Expecting 41600 events.
[18:06:05.832] <TB0> INFO: 41600 events read in total (3318ms).
[18:06:05.832] <TB0> INFO: Test took 4185ms.
[18:06:05.835] <TB0> INFO: scanning high vcal = 90 (= 630 in low range)
[18:06:06.111] <TB0> INFO: Expecting 41600 events.
[18:06:10.015] <TB0> INFO: 41600 events read in total (3312ms).
[18:06:10.016] <TB0> INFO: Test took 4181ms.
[18:06:10.019] <TB0> INFO: scanning high vcal = 200 (= 1400 in low range)
[18:06:10.295] <TB0> INFO: Expecting 41600 events.
[18:06:14.240] <TB0> INFO: 41600 events read in total (3353ms).
[18:06:14.241] <TB0> INFO: Test took 4222ms.
[18:06:14.655] <TB0> INFO: PixTestGainPedestal::measure() done
[18:06:55.505] <TB0> INFO: PixTestGainPedestal::fit() done
[18:06:55.505] <TB0> INFO: non-linearity mean: 0.983 0.979 0.945 0.942 0.943 0.971 0.981 0.982 0.913 0.983 0.983 0.925 0.984 0.973 0.964 0.983
[18:06:55.505] <TB0> INFO: non-linearity RMS: 0.003 0.007 0.068 0.093 0.161 0.015 0.005 0.005 0.173 0.003 0.004 0.098 0.004 0.006 0.030 0.004
[18:06:55.505] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[18:06:55.526] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[18:06:55.548] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[18:06:55.570] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[18:06:55.591] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[18:06:55.614] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[18:06:55.636] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[18:06:55.658] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[18:06:55.680] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[18:06:55.698] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[18:06:55.712] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[18:06:55.726] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[18:06:55.740] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[18:06:55.754] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[18:06:55.768] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[18:06:55.782] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1000_FullQualification_2016-11-04_10h05m_1478250315//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[18:06:55.804] <TB0> INFO: PixTestGainPedestal::fullTest() done, duration: 166 seconds
[18:06:55.804] <TB0> INFO: Decoding statistics:
[18:06:55.804] <TB0> INFO: General information:
[18:06:55.804] <TB0> INFO: 16bit words read: 3327804
[18:06:55.804] <TB0> INFO: valid events total: 332800
[18:06:55.804] <TB0> INFO: empty events: 0
[18:06:55.804] <TB0> INFO: valid events with pixels: 332800
[18:06:55.804] <TB0> INFO: valid pixel hits: 665502
[18:06:55.804] <TB0> INFO: Event errors: 0
[18:06:55.804] <TB0> INFO: start marker: 0
[18:06:55.804] <TB0> INFO: stop marker: 0
[18:06:55.804] <TB0> INFO: overflow: 0
[18:06:55.804] <TB0> INFO: invalid 5bit words: 0
[18:06:55.804] <TB0> INFO: invalid XOR eye diagram: 0
[18:06:55.804] <TB0> INFO: frame (failed synchr.): 0
[18:06:55.804] <TB0> INFO: idle data (no TBM trl): 0
[18:06:55.804] <TB0> INFO: no data (only TBM hdr): 0
[18:06:55.804] <TB0> INFO: TBM errors: 0
[18:06:55.804] <TB0> INFO: flawed TBM headers: 0
[18:06:55.804] <TB0> INFO: flawed TBM trailers: 0
[18:06:55.804] <TB0> INFO: event ID mismatches: 0
[18:06:55.804] <TB0> INFO: ROC errors: 0
[18:06:55.804] <TB0> INFO: missing ROC header(s): 0
[18:06:55.804] <TB0> INFO: misplaced readback start: 0
[18:06:55.805] <TB0> INFO: Pixel decoding errors: 0
[18:06:55.805] <TB0> INFO: pixel data incomplete: 0
[18:06:55.805] <TB0> INFO: pixel address: 0
[18:06:55.805] <TB0> INFO: pulse height fill bit: 0
[18:06:55.805] <TB0> INFO: buffer corruption: 0
[18:06:55.825] <TB0> INFO: Decoding statistics:
[18:06:55.825] <TB0> INFO: General information:
[18:06:55.825] <TB0> INFO: 16bit words read: 3457222
[18:06:55.825] <TB0> INFO: valid events total: 353536
[18:06:55.825] <TB0> INFO: empty events: 18235
[18:06:55.825] <TB0> INFO: valid events with pixels: 335301
[18:06:55.825] <TB0> INFO: valid pixel hits: 668003
[18:06:55.825] <TB0> INFO: Event errors: 0
[18:06:55.825] <TB0> INFO: start marker: 0
[18:06:55.825] <TB0> INFO: stop marker: 0
[18:06:55.825] <TB0> INFO: overflow: 0
[18:06:55.825] <TB0> INFO: invalid 5bit words: 0
[18:06:55.825] <TB0> INFO: invalid XOR eye diagram: 0
[18:06:55.825] <TB0> INFO: frame (failed synchr.): 0
[18:06:55.825] <TB0> INFO: idle data (no TBM trl): 0
[18:06:55.825] <TB0> INFO: no data (only TBM hdr): 0
[18:06:55.825] <TB0> INFO: TBM errors: 0
[18:06:55.825] <TB0> INFO: flawed TBM headers: 0
[18:06:55.825] <TB0> INFO: flawed TBM trailers: 0
[18:06:55.825] <TB0> INFO: event ID mismatches: 0
[18:06:55.825] <TB0> INFO: ROC errors: 0
[18:06:55.825] <TB0> INFO: missing ROC header(s): 0
[18:06:55.825] <TB0> INFO: misplaced readback start: 0
[18:06:55.825] <TB0> INFO: Pixel decoding errors: 0
[18:06:55.825] <TB0> INFO: pixel data incomplete: 0
[18:06:55.825] <TB0> INFO: pixel address: 0
[18:06:55.825] <TB0> INFO: pulse height fill bit: 0
[18:06:55.826] <TB0> INFO: buffer corruption: 0
[18:06:55.826] <TB0> INFO: enter test to run
[18:06:55.826] <TB0> INFO: test: exit no parameter change
[18:06:55.882] <TB0> QUIET: Connection to board 73 closed.
[18:06:55.882] <TB0> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud