Test Date: 2016-10-26 16:26
Analysis date: 2016-10-28 10:40
Logfile
LogfileView
[17:20:28.000] <TB0> INFO: *** Welcome to pxar ***
[17:20:28.000] <TB0> INFO: *** Today: 2016/10/26
[17:20:29.006] <TB0> INFO: *** Version: c8ba-dirty
[17:20:29.006] <TB0> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C15.dat
[17:20:29.007] <TB0> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C1b.dat
[17:20:29.007] <TB0> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//defaultMaskFile.dat
[17:20:29.007] <TB0> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters_C15.dat
[17:20:29.060] <TB0> INFO: clk: 4
[17:20:29.060] <TB0> INFO: ctr: 4
[17:20:29.060] <TB0> INFO: sda: 19
[17:20:29.060] <TB0> INFO: tin: 9
[17:20:29.060] <TB0> INFO: level: 15
[17:20:29.060] <TB0> INFO: triggerdelay: 0
[17:20:29.060] <TB0> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[17:20:29.060] <TB0> INFO: Log level: INFO
[17:20:29.069] <TB0> INFO: Found DTB DTB_WS6AYH
[17:20:29.077] <TB0> QUIET: Connection to board DTB_WS6AYH opened.
[17:20:29.079] <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:
------------------------------------------------------
[17:20:29.080] <TB0> INFO: RPC call hashes of host and DTB match: 486171790
[17:20:30.566] <TB0> INFO: DUT info:
[17:20:30.566] <TB0> INFO: The DUT currently contains the following objects:
[17:20:30.566] <TB0> INFO: 4 TBM Cores tbm10c (4 ON)
[17:20:30.566] <TB0> INFO: TBM Core alpha (0): 7 registers set
[17:20:30.566] <TB0> INFO: TBM Core beta (1): 7 registers set
[17:20:30.566] <TB0> INFO: TBM Core alpha (2): 7 registers set
[17:20:30.566] <TB0> INFO: TBM Core beta (3): 7 registers set
[17:20:30.566] <TB0> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[17:20:30.566] <TB0> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.566] <TB0> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:20:30.967] <TB0> INFO: enter 'restricted' command line mode
[17:20:30.967] <TB0> INFO: enter test to run
[17:20:30.967] <TB0> INFO: test: pretest no parameter change
[17:20:30.967] <TB0> INFO: running: pretest
[17:20:31.518] <TB0> INFO: ######################################################################
[17:20:31.518] <TB0> INFO: PixTestPretest::doTest()
[17:20:31.518] <TB0> INFO: ######################################################################
[17:20:31.519] <TB0> INFO: ----------------------------------------------------------------------
[17:20:31.519] <TB0> INFO: PixTestPretest::programROC()
[17:20:31.519] <TB0> INFO: ----------------------------------------------------------------------
[17:20:49.533] <TB0> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[17:20:49.533] <TB0> INFO: IA differences per ROC: 21.7 21.7 19.3 16.9 19.3 17.7 20.1 16.9 20.9 17.7 19.3 20.1 20.1 18.5 20.9 16.9
[17:20:49.567] <TB0> INFO: ----------------------------------------------------------------------
[17:20:49.567] <TB0> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[17:20:49.567] <TB0> INFO: ----------------------------------------------------------------------
[17:21:10.808] <TB0> INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[17:21:10.808] <TB0> INFO: i(loss) [mA/ROC]: 20.1 19.3 20.1 20.1 20.1 20.1 19.3 20.1 19.3 20.1 19.3 20.1 19.3 19.3 20.1 19.3
[17:21:10.838] <TB0> INFO: ----------------------------------------------------------------------
[17:21:10.838] <TB0> INFO: PixTestPretest::findTiming()
[17:21:10.838] <TB0> INFO: ----------------------------------------------------------------------
[17:21:10.838] <TB0> INFO: PixTestCmd::init()
[17:21:11.401] <TB0> WARNING: Not unmasking DUT, not setting Calibrate bits!

[17:21:41.948] <TB0> INFO: TBM phases: 160MHz: 7, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[17:21:41.948] <TB0> INFO: (success/tries = 100/100), width = 3
[17:21:43.451] <TB0> INFO: ----------------------------------------------------------------------
[17:21:43.451] <TB0> INFO: PixTestPretest::findWorkingPixel()
[17:21:43.451] <TB0> INFO: ----------------------------------------------------------------------
[17:21:43.542] <TB0> INFO: Expecting 231680 events.
[17:21:53.237] <TB0> INFO: 231680 events read in total (9103ms).
[17:21:53.246] <TB0> INFO: Test took 9793ms.
[17:21:53.495] <TB0> INFO: Found working pixel in all ROCs: col/row = 12/22
[17:21:53.525] <TB0> INFO: ----------------------------------------------------------------------
[17:21:53.525] <TB0> INFO: PixTestPretest::setVthrCompCalDel()
[17:21:53.525] <TB0> INFO: ----------------------------------------------------------------------
[17:21:53.618] <TB0> INFO: Expecting 231680 events.
[17:22:03.251] <TB0> INFO: 231680 events read in total (9042ms).
[17:22:03.258] <TB0> INFO: Test took 9729ms.
[17:22:03.523] <TB0> INFO: PixTestPretest::setVthrCompCalDel() done
[17:22:03.523] <TB0> INFO: CalDel: 89 100 77 85 78 92 88 86 122 93 101 81 100 101 99 111
[17:22:03.523] <TB0> INFO: VthrComp: 51 51 52 51 51 51 51 51 51 51 51 51 51 51 51 51
[17:22:03.526] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C0.dat
[17:22:03.526] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C1.dat
[17:22:03.526] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C2.dat
[17:22:03.526] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C3.dat
[17:22:03.526] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C4.dat
[17:22:03.526] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C5.dat
[17:22:03.526] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C6.dat
[17:22:03.527] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C7.dat
[17:22:03.527] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C8.dat
[17:22:03.527] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C9.dat
[17:22:03.527] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C10.dat
[17:22:03.527] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C11.dat
[17:22:03.527] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C12.dat
[17:22:03.527] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C13.dat
[17:22:03.527] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C14.dat
[17:22:03.527] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters_C15.dat
[17:22:03.528] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C0a.dat
[17:22:03.528] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C0b.dat
[17:22:03.528] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C1a.dat
[17:22:03.528] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//tbmParameters_C1b.dat
[17:22:03.528] <TB0> INFO: PixTestPretest::doTest() done, duration: 92 seconds
[17:22:03.624] <TB0> INFO: enter test to run
[17:22:03.624] <TB0> INFO: test: FullTest no parameter change
[17:22:03.624] <TB0> INFO: running: fulltest
[17:22:03.624] <TB0> INFO: ######################################################################
[17:22:03.625] <TB0> INFO: PixTestFullTest::doTest()
[17:22:03.625] <TB0> INFO: ######################################################################
[17:22:03.626] <TB0> INFO: ######################################################################
[17:22:03.626] <TB0> INFO: PixTestAlive::doTest()
[17:22:03.626] <TB0> INFO: ######################################################################
[17:22:03.627] <TB0> INFO: ----------------------------------------------------------------------
[17:22:03.627] <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)
[17:22:03.627] <TB0> INFO: ----------------------------------------------------------------------
[17:22:03.892] <TB0> INFO: Expecting 41600 events.
[17:22:07.412] <TB0> INFO: 41600 events read in total (2929ms).
[17:22:07.413] <TB0> INFO: Test took 3785ms.
[17:22:07.640] <TB0> INFO: PixTestAlive::aliveTest() done
[17:22:07.640] <TB0> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:22:07.641] <TB0> INFO: ----------------------------------------------------------------------
[17:22:07.641] <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)
[17:22:07.641] <TB0> INFO: ----------------------------------------------------------------------
[17:22:07.874] <TB0> INFO: Expecting 41600 events.
[17:22:10.839] <TB0> INFO: 41600 events read in total (2373ms).
[17:22:10.839] <TB0> INFO: Test took 3197ms.
[17:22:10.840] <TB0> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[17:22:11.078] <TB0> INFO: PixTestAlive::maskTest() done
[17:22:11.078] <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
[17:22:11.079] <TB0> INFO: ----------------------------------------------------------------------
[17:22:11.079] <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)
[17:22:11.079] <TB0> INFO: ----------------------------------------------------------------------
[17:22:11.315] <TB0> INFO: Expecting 41600 events.
[17:22:14.771] <TB0> INFO: 41600 events read in total (2864ms).
[17:22:14.771] <TB0> INFO: Test took 3690ms.
[17:22:14.998] <TB0> INFO: PixTestAlive::addressDecodingTest() done
[17:22:14.998] <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
[17:22:14.998] <TB0> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[17:22:14.998] <TB0> INFO: Decoding statistics:
[17:22:14.998] <TB0> INFO: General information:
[17:22:14.998] <TB0> INFO: 16bit words read: 0
[17:22:14.998] <TB0> INFO: valid events total: 0
[17:22:14.998] <TB0> INFO: empty events: 0
[17:22:14.998] <TB0> INFO: valid events with pixels: 0
[17:22:14.998] <TB0> INFO: valid pixel hits: 0
[17:22:14.998] <TB0> INFO: Event errors: 0
[17:22:14.998] <TB0> INFO: start marker: 0
[17:22:14.998] <TB0> INFO: stop marker: 0
[17:22:14.999] <TB0> INFO: overflow: 0
[17:22:14.999] <TB0> INFO: invalid 5bit words: 0
[17:22:14.999] <TB0> INFO: invalid XOR eye diagram: 0
[17:22:14.999] <TB0> INFO: frame (failed synchr.): 0
[17:22:14.999] <TB0> INFO: idle data (no TBM trl): 0
[17:22:14.999] <TB0> INFO: no data (only TBM hdr): 0
[17:22:14.999] <TB0> INFO: TBM errors: 0
[17:22:14.999] <TB0> INFO: flawed TBM headers: 0
[17:22:14.999] <TB0> INFO: flawed TBM trailers: 0
[17:22:14.999] <TB0> INFO: event ID mismatches: 0
[17:22:14.999] <TB0> INFO: ROC errors: 0
[17:22:14.999] <TB0> INFO: missing ROC header(s): 0
[17:22:14.999] <TB0> INFO: misplaced readback start: 0
[17:22:14.999] <TB0> INFO: Pixel decoding errors: 0
[17:22:14.999] <TB0> INFO: pixel data incomplete: 0
[17:22:14.999] <TB0> INFO: pixel address: 0
[17:22:14.999] <TB0> INFO: pulse height fill bit: 0
[17:22:14.999] <TB0> INFO: buffer corruption: 0
[17:22:15.008] <TB0> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C15.dat
[17:22:15.008] <TB0> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[17:22:15.008] <TB0> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[17:22:15.008] <TB0> INFO: ######################################################################
[17:22:15.008] <TB0> INFO: PixTestReadback::doTest()
[17:22:15.008] <TB0> INFO: ######################################################################
[17:22:15.008] <TB0> INFO: ----------------------------------------------------------------------
[17:22:15.008] <TB0> INFO: PixTestReadback::CalibrateVd()
[17:22:15.008] <TB0> INFO: ----------------------------------------------------------------------
[17:22:24.978] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C0.dat
[17:22:24.978] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C1.dat
[17:22:24.978] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C2.dat
[17:22:24.978] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C3.dat
[17:22:24.978] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C4.dat
[17:22:24.978] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C5.dat
[17:22:24.978] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C6.dat
[17:22:24.979] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C7.dat
[17:22:24.979] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C8.dat
[17:22:24.979] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C9.dat
[17:22:24.979] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C10.dat
[17:22:24.979] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C11.dat
[17:22:24.979] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C12.dat
[17:22:24.979] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C13.dat
[17:22:24.979] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C14.dat
[17:22:24.979] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C15.dat
[17:22:25.008] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[17:22:25.008] <TB0> INFO: ----------------------------------------------------------------------
[17:22:25.008] <TB0> INFO: PixTestReadback::CalibrateVa()
[17:22:25.008] <TB0> INFO: ----------------------------------------------------------------------
[17:22:34.902] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C0.dat
[17:22:34.902] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C1.dat
[17:22:34.902] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C2.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C3.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C4.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C5.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C6.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C7.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C8.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C9.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C10.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C11.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C12.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C13.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C14.dat
[17:22:34.903] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C15.dat
[17:22:34.931] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[17:22:34.931] <TB0> INFO: ----------------------------------------------------------------------
[17:22:34.931] <TB0> INFO: PixTestReadback::readbackVbg()
[17:22:34.931] <TB0> INFO: ----------------------------------------------------------------------
[17:22:42.569] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[17:22:42.569] <TB0> INFO: ----------------------------------------------------------------------
[17:22:42.569] <TB0> INFO: PixTestReadback::getCalibratedVbg()
[17:22:42.569] <TB0> INFO: ----------------------------------------------------------------------
[17:22:42.569] <TB0> INFO: Vbg will be calibrated using Vd calibration
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 152calibrated Vbg = 1.18378 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 159.9calibrated Vbg = 1.17566 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 153.8calibrated Vbg = 1.17506 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 154.5calibrated Vbg = 1.16629 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 160.9calibrated Vbg = 1.1787 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 157.2calibrated Vbg = 1.17387 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 144.4calibrated Vbg = 1.17963 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 149.2calibrated Vbg = 1.17984 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 151.7calibrated Vbg = 1.17851 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 148.1calibrated Vbg = 1.17612 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 157.8calibrated Vbg = 1.17029 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 159.4calibrated Vbg = 1.1688 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 158.4calibrated Vbg = 1.17823 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 152.2calibrated Vbg = 1.16946 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 161.6calibrated Vbg = 1.17772 :::*/*/*/*/
[17:22:42.569] <TB0> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 145calibrated Vbg = 1.17373 :::*/*/*/*/
[17:22:42.572] <TB0> INFO: ----------------------------------------------------------------------
[17:22:42.572] <TB0> INFO: PixTestReadback::CalibrateIa()
[17:22:42.572] <TB0> INFO: ----------------------------------------------------------------------
[17:25:22.911] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C0.dat
[17:25:22.911] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C1.dat
[17:25:22.911] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C2.dat
[17:25:22.911] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C3.dat
[17:25:22.911] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C4.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C5.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C6.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C7.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C8.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C9.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C10.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C11.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C12.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C13.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C14.dat
[17:25:22.912] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//readbackCal_C15.dat
[17:25:22.943] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[17:25:22.944] <TB0> INFO: PixTestReadback::doTest() done
[17:25:22.944] <TB0> INFO: Decoding statistics:
[17:25:22.944] <TB0> INFO: General information:
[17:25:22.944] <TB0> INFO: 16bit words read: 1536
[17:25:22.944] <TB0> INFO: valid events total: 256
[17:25:22.944] <TB0> INFO: empty events: 256
[17:25:22.944] <TB0> INFO: valid events with pixels: 0
[17:25:22.944] <TB0> INFO: valid pixel hits: 0
[17:25:22.944] <TB0> INFO: Event errors: 0
[17:25:22.944] <TB0> INFO: start marker: 0
[17:25:22.944] <TB0> INFO: stop marker: 0
[17:25:22.944] <TB0> INFO: overflow: 0
[17:25:22.944] <TB0> INFO: invalid 5bit words: 0
[17:25:22.944] <TB0> INFO: invalid XOR eye diagram: 0
[17:25:22.944] <TB0> INFO: frame (failed synchr.): 0
[17:25:22.944] <TB0> INFO: idle data (no TBM trl): 0
[17:25:22.944] <TB0> INFO: no data (only TBM hdr): 0
[17:25:22.944] <TB0> INFO: TBM errors: 0
[17:25:22.944] <TB0> INFO: flawed TBM headers: 0
[17:25:22.944] <TB0> INFO: flawed TBM trailers: 0
[17:25:22.944] <TB0> INFO: event ID mismatches: 0
[17:25:22.944] <TB0> INFO: ROC errors: 0
[17:25:22.944] <TB0> INFO: missing ROC header(s): 0
[17:25:22.944] <TB0> INFO: misplaced readback start: 0
[17:25:22.944] <TB0> INFO: Pixel decoding errors: 0
[17:25:22.944] <TB0> INFO: pixel data incomplete: 0
[17:25:22.944] <TB0> INFO: pixel address: 0
[17:25:22.944] <TB0> INFO: pulse height fill bit: 0
[17:25:22.944] <TB0> INFO: buffer corruption: 0
[17:25:22.982] <TB0> INFO: ######################################################################
[17:25:22.982] <TB0> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[17:25:22.982] <TB0> INFO: ######################################################################
[17:25:22.985] <TB0> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[17:25:22.997] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[17:25:22.997] <TB0> INFO: run 1 of 1
[17:25:23.237] <TB0> INFO: Expecting 3120000 events.
[17:25:53.034] <TB0> INFO: 656160 events read in total (29205ms).
[17:26:04.973] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (161) != TBM ID (129)

[17:26:05.109] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 161 161 129 161 161 161 161 161

[17:26:05.109] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (162)

[17:26:05.109] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[17:26:05.109] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a5 80c0 4300 252 25ef 4300 252 25ef e022 c000

[17:26:05.109] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09f 8040 4382 252 25ef 4382 252 25ef e022 c000

[17:26:05.109] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a0 80b1 4380 252 25ef 4380 252 25ef e022 c000

[17:26:05.109] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 25ef 4381 252 25ef e022 c000

[17:26:05.109] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a2 8000 4380 252 25ef 4380 252 25ef e022 c000

[17:26:05.109] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a3 8040 4380 252 25ef 4301 252 25ef e022 c000

[17:26:05.109] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a4 80b1 4380 252 25ef 4380 252 25ef e022 c000

[17:26:22.308] <TB0> INFO: 1305650 events read in total (58479ms).
[17:26:34.194] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (179) != TBM ID (129)

[17:26:34.328] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 179 179 129 179 179 179 179 179

[17:26:34.328] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (180)

[17:26:34.329] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[17:26:34.329] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b7 8040 4380 4ae 29a9 4300 4ae 29ef e022 c000

[17:26:34.329] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b1 80c0 4301 4ae 29a4 4381 4ae 29ef e022 c000

[17:26:34.329] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b2 8000 4300 4ae 29a4 4380 4ae 29ef e022 c000

[17:26:34.329] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 29a5 4381 4ae 29ef e022 c000

[17:26:34.329] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b4 80b1 4380 4ae 29a2 4380 4ae 29ef e022 c000

[17:26:34.329] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b5 80c0 4380 4ae 29a5 4300 4ae 29ef e022 c000

[17:26:34.329] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b6 8000 4380 4ae 29a5 4380 4ae 29ef e022 c000

[17:26:51.501] <TB0> INFO: 1952120 events read in total (87672ms).
[17:27:03.328] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (249) != TBM ID (129)

[17:27:03.464] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 249 249 129 249 249 249 249 249

[17:27:03.464] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (250)

[17:27:03.465] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[17:27:03.465] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fd 80c0 4300 80a 25ef 4300 80a 25ef e022 c000

[17:27:03.465] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f7 8040 4300 80a 25ef 4300 80a 25ef e022 c000

[17:27:03.465] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f8 80b1 4380 80a 25ef 4380 80a 25ef e022 c000

[17:27:03.465] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 25ef 4301 80a 25ef e022 c000

[17:27:03.465] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fa 8000 4301 80a 25ef 4301 80a 25ef e022 c000

[17:27:03.465] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fb 8040 4301 80a 25ef 4301 80a 25ef e022 c000

[17:27:03.465] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fc 80b1 4381 80a 25ef 4381 80a 25ef e022 c000

[17:27:20.628] <TB0> INFO: 2595945 events read in total (116799ms).
[17:27:30.328] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (234) != TBM ID (129)

[17:27:30.468] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 234 234 129 234 234 234 234 234

[17:27:30.468] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (235)

[17:27:30.468] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[17:27:30.468] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ee 8000 4300 4300 e022 c000

[17:27:30.468] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e8 80b1 4380 4380 e022 c000

[17:27:30.468] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e9 80c0 4300 4300 e022 c000

[17:27:30.468] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 e022 c000

[17:27:30.468] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0eb 8040 4380 4380 e022 c000

[17:27:30.468] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ec 80b1 4300 4300 e022 c000

[17:27:30.468] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ed 80c0 4301 4301 e022 c000

[17:27:44.327] <TB0> INFO: 3120000 events read in total (140498ms).
[17:27:44.397] <TB0> INFO: Test took 141401ms.
[17:28:10.846] <TB0> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 167 seconds
[17:28:10.846] <TB0> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:28:10.846] <TB0> INFO: separation cut (per ROC): 107 105 110 106 107 101 105 104 88 104 104 115 107 99 98 100
[17:28:10.846] <TB0> INFO: Decoding statistics:
[17:28:10.846] <TB0> INFO: General information:
[17:28:10.846] <TB0> INFO: 16bit words read: 0
[17:28:10.846] <TB0> INFO: valid events total: 0
[17:28:10.846] <TB0> INFO: empty events: 0
[17:28:10.846] <TB0> INFO: valid events with pixels: 0
[17:28:10.846] <TB0> INFO: valid pixel hits: 0
[17:28:10.846] <TB0> INFO: Event errors: 0
[17:28:10.846] <TB0> INFO: start marker: 0
[17:28:10.846] <TB0> INFO: stop marker: 0
[17:28:10.846] <TB0> INFO: overflow: 0
[17:28:10.846] <TB0> INFO: invalid 5bit words: 0
[17:28:10.846] <TB0> INFO: invalid XOR eye diagram: 0
[17:28:10.846] <TB0> INFO: frame (failed synchr.): 0
[17:28:10.846] <TB0> INFO: idle data (no TBM trl): 0
[17:28:10.846] <TB0> INFO: no data (only TBM hdr): 0
[17:28:10.846] <TB0> INFO: TBM errors: 0
[17:28:10.846] <TB0> INFO: flawed TBM headers: 0
[17:28:10.846] <TB0> INFO: flawed TBM trailers: 0
[17:28:10.846] <TB0> INFO: event ID mismatches: 0
[17:28:10.846] <TB0> INFO: ROC errors: 0
[17:28:10.846] <TB0> INFO: missing ROC header(s): 0
[17:28:10.846] <TB0> INFO: misplaced readback start: 0
[17:28:10.847] <TB0> INFO: Pixel decoding errors: 0
[17:28:10.847] <TB0> INFO: pixel data incomplete: 0
[17:28:10.847] <TB0> INFO: pixel address: 0
[17:28:10.847] <TB0> INFO: pulse height fill bit: 0
[17:28:10.847] <TB0> INFO: buffer corruption: 0
[17:28:10.881] <TB0> INFO: ######################################################################
[17:28:10.881] <TB0> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[17:28:10.881] <TB0> INFO: ######################################################################
[17:28:10.882] <TB0> INFO: ----------------------------------------------------------------------
[17:28:10.882] <TB0> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[17:28:10.882] <TB0> INFO: ----------------------------------------------------------------------
[17:28:10.882] <TB0> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[17:28:10.893] <TB0> INFO: dacScan split into 1 runs with ntrig = 50
[17:28:10.893] <TB0> INFO: run 1 of 1
[17:28:11.162] <TB0> INFO: Expecting 36608000 events.
[17:28:34.628] <TB0> INFO: 668100 events read in total (22874ms).
[17:28:56.950] <TB0> INFO: 1324750 events read in total (45196ms).
[17:29:19.292] <TB0> INFO: 1980950 events read in total (67538ms).
[17:29:41.500] <TB0> INFO: 2637500 events read in total (89746ms).
[17:30:03.993] <TB0> INFO: 3294600 events read in total (112239ms).
[17:30:26.411] <TB0> INFO: 3950400 events read in total (134657ms).
[17:30:48.710] <TB0> INFO: 4607150 events read in total (156956ms).
[17:31:10.957] <TB0> INFO: 5263900 events read in total (179203ms).
[17:31:33.302] <TB0> INFO: 5919750 events read in total (201548ms).
[17:31:55.717] <TB0> INFO: 6577350 events read in total (223963ms).
[17:32:17.875] <TB0> INFO: 7232250 events read in total (246121ms).
[17:32:40.135] <TB0> INFO: 7889550 events read in total (268381ms).
[17:33:02.615] <TB0> INFO: 8544400 events read in total (290861ms).
[17:33:25.038] <TB0> INFO: 9202450 events read in total (313284ms).
[17:33:47.164] <TB0> INFO: 9857550 events read in total (335410ms).
[17:34:09.317] <TB0> INFO: 10514950 events read in total (357563ms).
[17:34:31.469] <TB0> INFO: 11172350 events read in total (379715ms).
[17:34:53.854] <TB0> INFO: 11827200 events read in total (402100ms).
[17:35:16.131] <TB0> INFO: 12483750 events read in total (424377ms).
[17:35:38.346] <TB0> INFO: 13138200 events read in total (446592ms).
[17:36:00.735] <TB0> INFO: 13794600 events read in total (468981ms).
[17:36:22.868] <TB0> INFO: 14449400 events read in total (491114ms).
[17:36:44.976] <TB0> INFO: 15106150 events read in total (513222ms).
[17:37:07.171] <TB0> INFO: 15760950 events read in total (535417ms).
[17:37:29.268] <TB0> INFO: 16417600 events read in total (557514ms).
[17:37:51.435] <TB0> INFO: 17071450 events read in total (579681ms).
[17:38:13.935] <TB0> INFO: 17727500 events read in total (602181ms).
[17:38:36.440] <TB0> INFO: 18380450 events read in total (624687ms).
[17:38:59.137] <TB0> INFO: 19034250 events read in total (647383ms).
[17:39:21.641] <TB0> INFO: 19687300 events read in total (669887ms).
[17:39:44.467] <TB0> INFO: 20341650 events read in total (692713ms).
[17:40:06.755] <TB0> INFO: 20995100 events read in total (715001ms).
[17:40:29.135] <TB0> INFO: 21647900 events read in total (737381ms).
[17:40:51.675] <TB0> INFO: 22302200 events read in total (759921ms).
[17:41:14.199] <TB0> INFO: 22955950 events read in total (782445ms).
[17:41:36.544] <TB0> INFO: 23608150 events read in total (804790ms).
[17:41:59.013] <TB0> INFO: 24260700 events read in total (827259ms).
[17:42:21.664] <TB0> INFO: 24913600 events read in total (849910ms).
[17:42:44.172] <TB0> INFO: 25566550 events read in total (872418ms).
[17:43:06.467] <TB0> INFO: 26217150 events read in total (894713ms).
[17:43:28.917] <TB0> INFO: 26869200 events read in total (917163ms).
[17:43:51.277] <TB0> INFO: 27521250 events read in total (939523ms).
[17:44:13.373] <TB0> INFO: 28171200 events read in total (961619ms).
[17:44:35.703] <TB0> INFO: 28824250 events read in total (983949ms).
[17:44:58.227] <TB0> INFO: 29476550 events read in total (1006473ms).
[17:45:20.498] <TB0> INFO: 30127950 events read in total (1028744ms).
[17:45:42.732] <TB0> INFO: 30779100 events read in total (1050978ms).
[17:46:05.030] <TB0> INFO: 31430450 events read in total (1073276ms).
[17:46:27.394] <TB0> INFO: 32082100 events read in total (1095640ms).
[17:46:50.126] <TB0> INFO: 32734600 events read in total (1118373ms).
[17:47:12.413] <TB0> INFO: 33389250 events read in total (1140659ms).
[17:47:34.892] <TB0> INFO: 34043950 events read in total (1163138ms).
[17:47:57.234] <TB0> INFO: 34695900 events read in total (1185480ms).
[17:48:19.430] <TB0> INFO: 35349600 events read in total (1207676ms).
[17:48:42.074] <TB0> INFO: 36007800 events read in total (1230320ms).
[17:49:02.193] <TB0> INFO: 36608000 events read in total (1250440ms).
[17:49:02.255] <TB0> INFO: Test took 1251363ms.
[17:49:02.713] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:04.506] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:06.310] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:08.072] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:09.887] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:11.812] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:13.636] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:15.729] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:17.700] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:19.587] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:21.708] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:23.284] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:25.180] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:27.161] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:28.921] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:30.972] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[17:49:32.932] <TB0> INFO: PixTestScurves::scurves() done
[17:49:32.932] <TB0> INFO: Vcal mean: 118.27 122.08 125.48 118.05 112.11 111.24 115.47 109.60 101.53 112.91 114.16 124.94 111.13 107.03 114.15 104.52
[17:49:32.932] <TB0> INFO: Vcal RMS: 5.68 6.26 5.80 6.19 4.68 5.10 5.29 4.85 4.66 4.60 5.62 6.11 4.63 5.03 5.55 5.37
[17:49:32.932] <TB0> INFO: PixTestScurves::fullTest() done, duration: 1282 seconds
[17:49:32.932] <TB0> INFO: Decoding statistics:
[17:49:32.932] <TB0> INFO: General information:
[17:49:32.932] <TB0> INFO: 16bit words read: 0
[17:49:32.932] <TB0> INFO: valid events total: 0
[17:49:32.932] <TB0> INFO: empty events: 0
[17:49:32.932] <TB0> INFO: valid events with pixels: 0
[17:49:32.932] <TB0> INFO: valid pixel hits: 0
[17:49:32.932] <TB0> INFO: Event errors: 0
[17:49:32.932] <TB0> INFO: start marker: 0
[17:49:32.932] <TB0> INFO: stop marker: 0
[17:49:32.932] <TB0> INFO: overflow: 0
[17:49:32.932] <TB0> INFO: invalid 5bit words: 0
[17:49:32.932] <TB0> INFO: invalid XOR eye diagram: 0
[17:49:32.932] <TB0> INFO: frame (failed synchr.): 0
[17:49:32.932] <TB0> INFO: idle data (no TBM trl): 0
[17:49:32.932] <TB0> INFO: no data (only TBM hdr): 0
[17:49:32.932] <TB0> INFO: TBM errors: 0
[17:49:32.932] <TB0> INFO: flawed TBM headers: 0
[17:49:32.932] <TB0> INFO: flawed TBM trailers: 0
[17:49:32.932] <TB0> INFO: event ID mismatches: 0
[17:49:32.932] <TB0> INFO: ROC errors: 0
[17:49:32.932] <TB0> INFO: missing ROC header(s): 0
[17:49:32.932] <TB0> INFO: misplaced readback start: 0
[17:49:32.932] <TB0> INFO: Pixel decoding errors: 0
[17:49:32.932] <TB0> INFO: pixel data incomplete: 0
[17:49:32.932] <TB0> INFO: pixel address: 0
[17:49:32.932] <TB0> INFO: pulse height fill bit: 0
[17:49:32.932] <TB0> INFO: buffer corruption: 0
[17:49:33.011] <TB0> INFO: ######################################################################
[17:49:33.011] <TB0> INFO: PixTestTrim::doTest()
[17:49:33.011] <TB0> INFO: ######################################################################
[17:49:33.012] <TB0> INFO: ----------------------------------------------------------------------
[17:49:33.012] <TB0> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[17:49:33.012] <TB0> INFO: ----------------------------------------------------------------------
[17:49:33.069] <TB0> INFO: ---> VthrComp thr map (minimal VthrComp)
[17:49:33.069] <TB0> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[17:49:33.080] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:49:33.080] <TB0> INFO: run 1 of 1
[17:49:33.332] <TB0> INFO: Expecting 5025280 events.
[17:50:04.850] <TB0> INFO: 820880 events read in total (30923ms).
[17:50:34.671] <TB0> INFO: 1639072 events read in total (60744ms).
[17:51:04.603] <TB0> INFO: 2454784 events read in total (90677ms).
[17:51:34.242] <TB0> INFO: 3266416 events read in total (120315ms).
[17:52:03.774] <TB0> INFO: 4074296 events read in total (149847ms).
[17:52:33.313] <TB0> INFO: 4881224 events read in total (179386ms).
[17:52:38.744] <TB0> INFO: 5025280 events read in total (184817ms).
[17:52:38.791] <TB0> INFO: Test took 185711ms.
[17:52:57.079] <TB0> INFO: ROC 0 VthrComp = 131
[17:52:57.079] <TB0> INFO: ROC 1 VthrComp = 130
[17:52:57.079] <TB0> INFO: ROC 2 VthrComp = 131
[17:52:57.079] <TB0> INFO: ROC 3 VthrComp = 126
[17:52:57.079] <TB0> INFO: ROC 4 VthrComp = 129
[17:52:57.079] <TB0> INFO: ROC 5 VthrComp = 122
[17:52:57.079] <TB0> INFO: ROC 6 VthrComp = 128
[17:52:57.080] <TB0> INFO: ROC 7 VthrComp = 123
[17:52:57.080] <TB0> INFO: ROC 8 VthrComp = 107
[17:52:57.080] <TB0> INFO: ROC 9 VthrComp = 126
[17:52:57.081] <TB0> INFO: ROC 10 VthrComp = 121
[17:52:57.081] <TB0> INFO: ROC 11 VthrComp = 132
[17:52:57.081] <TB0> INFO: ROC 12 VthrComp = 127
[17:52:57.081] <TB0> INFO: ROC 13 VthrComp = 113
[17:52:57.081] <TB0> INFO: ROC 14 VthrComp = 120
[17:52:57.081] <TB0> INFO: ROC 15 VthrComp = 108
[17:52:57.317] <TB0> INFO: Expecting 41600 events.
[17:53:00.830] <TB0> INFO: 41600 events read in total (2921ms).
[17:53:00.831] <TB0> INFO: Test took 3748ms.
[17:53:00.841] <TB0> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[17:53:00.841] <TB0> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[17:53:00.850] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:53:00.850] <TB0> INFO: run 1 of 1
[17:53:01.127] <TB0> INFO: Expecting 5025280 events.
[17:53:28.370] <TB0> INFO: 588552 events read in total (26651ms).
[17:53:53.944] <TB0> INFO: 1175760 events read in total (52225ms).
[17:54:19.242] <TB0> INFO: 1763024 events read in total (77523ms).
[17:54:44.245] <TB0> INFO: 2349296 events read in total (102526ms).
[17:55:09.561] <TB0> INFO: 2933712 events read in total (127842ms).
[17:55:34.681] <TB0> INFO: 3517640 events read in total (152962ms).
[17:55:59.588] <TB0> INFO: 4100408 events read in total (177869ms).
[17:56:24.564] <TB0> INFO: 4682448 events read in total (202845ms).
[17:56:39.184] <TB0> INFO: 5025280 events read in total (217465ms).
[17:56:39.260] <TB0> INFO: Test took 218410ms.
[17:57:06.171] <TB0> INFO: roc 0 with ID = 0 has maximal Vcal 57.5434 for pixel 6/71 mean/min/max = 44.9512/32.3467/57.5557
[17:57:06.171] <TB0> INFO: roc 1 with ID = 1 has maximal Vcal 62.5871 for pixel 46/61 mean/min/max = 48.6808/34.5097/62.8519
[17:57:06.172] <TB0> INFO: roc 2 with ID = 2 has maximal Vcal 62.9839 for pixel 13/76 mean/min/max = 49.1812/35.3609/63.0015
[17:57:06.172] <TB0> INFO: roc 3 with ID = 3 has maximal Vcal 60.5032 for pixel 0/79 mean/min/max = 45.5198/30.4561/60.5835
[17:57:06.173] <TB0> INFO: roc 4 with ID = 4 has maximal Vcal 55.9575 for pixel 14/79 mean/min/max = 43.8407/31.434/56.2473
[17:57:06.173] <TB0> INFO: roc 5 with ID = 5 has maximal Vcal 59.0864 for pixel 1/32 mean/min/max = 45.603/31.8483/59.3578
[17:57:06.173] <TB0> INFO: roc 6 with ID = 6 has maximal Vcal 57.5278 for pixel 0/2 mean/min/max = 44.1072/30.6697/57.5447
[17:57:06.174] <TB0> INFO: roc 7 with ID = 7 has maximal Vcal 55.7656 for pixel 22/79 mean/min/max = 43.8339/31.6487/56.0191
[17:57:06.174] <TB0> INFO: roc 8 with ID = 8 has maximal Vcal 59.9657 for pixel 42/73 mean/min/max = 47.4665/34.7704/60.1626
[17:57:06.174] <TB0> INFO: roc 9 with ID = 9 has maximal Vcal 56.4469 for pixel 36/69 mean/min/max = 44.0414/31.2763/56.8065
[17:57:06.174] <TB0> INFO: roc 10 with ID = 10 has maximal Vcal 60.1214 for pixel 0/2 mean/min/max = 46.2545/32.2478/60.2611
[17:57:06.175] <TB0> INFO: roc 11 with ID = 11 has maximal Vcal 59.8457 for pixel 5/54 mean/min/max = 46.2556/32.6061/59.9051
[17:57:06.175] <TB0> INFO: roc 12 with ID = 12 has maximal Vcal 55.5078 for pixel 15/0 mean/min/max = 43.4828/31.1147/55.8508
[17:57:06.175] <TB0> INFO: roc 13 with ID = 13 has maximal Vcal 58.6898 for pixel 0/56 mean/min/max = 45.6945/32.6924/58.6965
[17:57:06.175] <TB0> INFO: roc 14 with ID = 14 has maximal Vcal 62.0929 for pixel 10/72 mean/min/max = 46.6225/31.1484/62.0966
[17:57:06.176] <TB0> INFO: roc 15 with ID = 15 has maximal Vcal 62.2051 for pixel 15/13 mean/min/max = 47.8967/33.4507/62.3427
[17:57:06.176] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:57:06.264] <TB0> INFO: Expecting 411648 events.
[17:57:15.863] <TB0> INFO: 411648 events read in total (9007ms).
[17:57:15.873] <TB0> INFO: Expecting 411648 events.
[17:57:25.508] <TB0> INFO: 411648 events read in total (9232ms).
[17:57:25.521] <TB0> INFO: Expecting 411648 events.
[17:57:35.085] <TB0> INFO: 411648 events read in total (9161ms).
[17:57:35.098] <TB0> INFO: Expecting 411648 events.
[17:57:44.277] <TB0> INFO: 411648 events read in total (8776ms).
[17:57:44.292] <TB0> INFO: Expecting 411648 events.
[17:57:53.289] <TB0> INFO: 411648 events read in total (8594ms).
[17:57:53.306] <TB0> INFO: Expecting 411648 events.
[17:58:02.373] <TB0> INFO: 411648 events read in total (8664ms).
[17:58:02.395] <TB0> INFO: Expecting 411648 events.
[17:58:11.420] <TB0> INFO: 411648 events read in total (8622ms).
[17:58:11.452] <TB0> INFO: Expecting 411648 events.
[17:58:20.461] <TB0> INFO: 411648 events read in total (8606ms).
[17:58:20.493] <TB0> INFO: Expecting 411648 events.
[17:58:29.576] <TB0> INFO: 411648 events read in total (8680ms).
[17:58:29.605] <TB0> INFO: Expecting 411648 events.
[17:58:38.574] <TB0> INFO: 411648 events read in total (8566ms).
[17:58:38.604] <TB0> INFO: Expecting 411648 events.
[17:58:47.582] <TB0> INFO: 411648 events read in total (8575ms).
[17:58:47.614] <TB0> INFO: Expecting 411648 events.
[17:58:56.634] <TB0> INFO: 411648 events read in total (8617ms).
[17:58:56.670] <TB0> INFO: Expecting 411648 events.
[17:59:05.691] <TB0> INFO: 411648 events read in total (8618ms).
[17:59:05.729] <TB0> INFO: Expecting 411648 events.
[17:59:14.789] <TB0> INFO: 411648 events read in total (8657ms).
[17:59:14.829] <TB0> INFO: Expecting 411648 events.
[17:59:23.794] <TB0> INFO: 411648 events read in total (8562ms).
[17:59:23.855] <TB0> INFO: Expecting 411648 events.
[17:59:32.913] <TB0> INFO: 411648 events read in total (8655ms).
[17:59:32.972] <TB0> INFO: Test took 146796ms.
[17:59:33.894] <TB0> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[17:59:33.903] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[17:59:33.903] <TB0> INFO: run 1 of 1
[17:59:34.145] <TB0> INFO: Expecting 5025280 events.
[17:59:59.777] <TB0> INFO: 584792 events read in total (25040ms).
[18:00:25.070] <TB0> INFO: 1168160 events read in total (50333ms).
[18:00:50.279] <TB0> INFO: 1750976 events read in total (75542ms).
[18:01:15.779] <TB0> INFO: 2333104 events read in total (101042ms).
[18:01:41.500] <TB0> INFO: 2914480 events read in total (126763ms).
[18:02:07.184] <TB0> INFO: 3497432 events read in total (152447ms).
[18:02:32.806] <TB0> INFO: 4080776 events read in total (178069ms).
[18:02:58.468] <TB0> INFO: 4662440 events read in total (203731ms).
[18:03:14.425] <TB0> INFO: 5025280 events read in total (219688ms).
[18:03:14.549] <TB0> INFO: Test took 220647ms.
[18:03:40.087] <TB0> INFO: ---> TrimStepCorr4 extremal thresholds: 8.212944 .. 144.842394
[18:03:40.321] <TB0> INFO: Expecting 208000 events.
[18:03:50.069] <TB0> INFO: 208000 events read in total (9157ms).
[18:03:50.070] <TB0> INFO: Test took 9982ms.
[18:03:50.116] <TB0> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 8 .. 154 (-1/-1) hits flags = 528 (plus default)
[18:03:50.125] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[18:03:50.125] <TB0> INFO: run 1 of 1
[18:03:50.403] <TB0> INFO: Expecting 4892160 events.
[18:04:17.222] <TB0> INFO: 575192 events read in total (26228ms).
[18:04:42.422] <TB0> INFO: 1150544 events read in total (51428ms).
[18:05:07.908] <TB0> INFO: 1726008 events read in total (76914ms).
[18:05:33.011] <TB0> INFO: 2300752 events read in total (102017ms).
[18:05:58.226] <TB0> INFO: 2875088 events read in total (127232ms).
[18:06:23.576] <TB0> INFO: 3448760 events read in total (152582ms).
[18:06:48.792] <TB0> INFO: 4021680 events read in total (177798ms).
[18:07:14.202] <TB0> INFO: 4594392 events read in total (203208ms).
[18:07:27.285] <TB0> INFO: 4892160 events read in total (216291ms).
[18:07:27.351] <TB0> INFO: Test took 217227ms.
[18:07:53.875] <TB0> INFO: ---> TrimStepCorr2 extremal thresholds: 28.147074 .. 43.060684
[18:07:54.110] <TB0> INFO: Expecting 208000 events.
[18:08:03.813] <TB0> INFO: 208000 events read in total (9111ms).
[18:08:03.814] <TB0> INFO: Test took 9938ms.
[18:08:03.878] <TB0> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 18 .. 53 (-1/-1) hits flags = 528 (plus default)
[18:08:03.889] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[18:08:03.889] <TB0> INFO: run 1 of 1
[18:08:04.167] <TB0> INFO: Expecting 1198080 events.
[18:08:33.762] <TB0> INFO: 662512 events read in total (29003ms).
[18:08:56.096] <TB0> INFO: 1198080 events read in total (51338ms).
[18:08:56.128] <TB0> INFO: Test took 52240ms.
[18:09:09.045] <TB0> INFO: ---> TrimStepCorr1a extremal thresholds: 25.653620 .. 46.499982
[18:09:09.279] <TB0> INFO: Expecting 208000 events.
[18:09:18.830] <TB0> INFO: 208000 events read in total (8960ms).
[18:09:18.831] <TB0> INFO: Test took 9784ms.
[18:09:18.877] <TB0> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 15 .. 56 (-1/-1) hits flags = 528 (plus default)
[18:09:18.886] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[18:09:18.886] <TB0> INFO: run 1 of 1
[18:09:19.164] <TB0> INFO: Expecting 1397760 events.
[18:09:47.595] <TB0> INFO: 662864 events read in total (27839ms).
[18:10:15.244] <TB0> INFO: 1324464 events read in total (55488ms).
[18:10:18.629] <TB0> INFO: 1397760 events read in total (58873ms).
[18:10:18.655] <TB0> INFO: Test took 59769ms.
[18:10:32.006] <TB0> INFO: ---> TrimStepCorr1b extremal thresholds: 23.982275 .. 42.892320
[18:10:32.324] <TB0> INFO: Expecting 208000 events.
[18:10:42.093] <TB0> INFO: 208000 events read in total (9177ms).
[18:10:42.094] <TB0> INFO: Test took 10086ms.
[18:10:42.160] <TB0> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 13 .. 52 (-1/-1) hits flags = 528 (plus default)
[18:10:42.171] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[18:10:42.171] <TB0> INFO: run 1 of 1
[18:10:42.449] <TB0> INFO: Expecting 1331200 events.
[18:11:11.727] <TB0> INFO: 688880 events read in total (28686ms).
[18:11:37.906] <TB0> INFO: 1331200 events read in total (54866ms).
[18:11:37.934] <TB0> INFO: Test took 55764ms.
[18:11:50.352] <TB0> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[18:11:50.352] <TB0> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[18:11:50.360] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[18:11:50.360] <TB0> INFO: run 1 of 1
[18:11:50.608] <TB0> INFO: Expecting 1364480 events.
[18:12:19.005] <TB0> INFO: 667120 events read in total (27806ms).
[18:12:46.956] <TB0> INFO: 1333640 events read in total (55757ms).
[18:12:48.644] <TB0> INFO: 1364480 events read in total (57445ms).
[18:12:48.668] <TB0> INFO: Test took 58309ms.
[18:13:02.743] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C0.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C1.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C2.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C3.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C4.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C5.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C6.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C7.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C8.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C9.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C10.dat
[18:13:02.744] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C11.dat
[18:13:02.745] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C12.dat
[18:13:02.745] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C13.dat
[18:13:02.745] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C14.dat
[18:13:02.745] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C15.dat
[18:13:02.745] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C0.dat
[18:13:02.753] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C1.dat
[18:13:02.760] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C2.dat
[18:13:02.768] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C3.dat
[18:13:02.776] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C4.dat
[18:13:02.783] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C5.dat
[18:13:02.790] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C6.dat
[18:13:02.795] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C7.dat
[18:13:02.800] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C8.dat
[18:13:02.806] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C9.dat
[18:13:02.812] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C10.dat
[18:13:02.821] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C11.dat
[18:13:02.828] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C12.dat
[18:13:02.833] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C13.dat
[18:13:02.839] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C14.dat
[18:13:02.847] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//trimParameters35_C15.dat
[18:13:02.854] <TB0> INFO: PixTestTrim::trimTest() done
[18:13:02.854] <TB0> INFO: vtrim: 160 145 171 117 130 163 130 133 144 139 130 156 123 123 154 147
[18:13:02.854] <TB0> INFO: vthrcomp: 131 130 131 126 129 122 128 123 107 126 121 132 127 113 120 108
[18:13:02.854] <TB0> INFO: vcal mean: 34.93 34.97 35.05 34.86 34.91 34.92 34.88 34.99 34.99 34.94 35.01 35.00 34.96 34.99 34.99 34.98
[18:13:02.854] <TB0> INFO: vcal RMS: 1.00 1.03 1.09 1.17 1.03 1.10 1.04 0.96 0.95 1.06 1.03 1.12 0.98 0.94 1.12 1.07
[18:13:02.854] <TB0> INFO: bits mean: 10.37 9.09 8.93 9.73 10.39 9.89 10.37 10.53 9.00 10.42 9.10 9.90 10.59 9.13 9.83 9.46
[18:13:02.854] <TB0> INFO: bits RMS: 2.24 2.32 2.27 2.82 2.45 2.54 2.55 2.38 2.45 2.44 2.82 2.37 2.34 2.74 2.62 2.44
[18:13:02.861] <TB0> INFO: ----------------------------------------------------------------------
[18:13:02.862] <TB0> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[18:13:02.862] <TB0> INFO: ----------------------------------------------------------------------
[18:13:02.864] <TB0> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[18:13:02.875] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[18:13:02.875] <TB0> INFO: run 1 of 1
[18:13:03.107] <TB0> INFO: Expecting 4160000 events.
[18:13:35.005] <TB0> INFO: 736150 events read in total (31306ms).
[18:14:05.795] <TB0> INFO: 1469830 events read in total (62096ms).
[18:14:36.945] <TB0> INFO: 2200900 events read in total (93246ms).
[18:15:07.768] <TB0> INFO: 2929420 events read in total (124069ms).
[18:15:38.637] <TB0> INFO: 3655995 events read in total (154938ms).
[18:16:00.132] <TB0> INFO: 4160000 events read in total (176433ms).
[18:16:00.183] <TB0> INFO: Test took 177307ms.
[18:16:26.155] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[18:16:26.164] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[18:16:26.164] <TB0> INFO: run 1 of 1
[18:16:26.396] <TB0> INFO: Expecting 4139200 events.
[18:16:57.641] <TB0> INFO: 715305 events read in total (30653ms).
[18:17:28.780] <TB0> INFO: 1428675 events read in total (61792ms).
[18:17:59.431] <TB0> INFO: 2140035 events read in total (92443ms).
[18:18:30.216] <TB0> INFO: 2848985 events read in total (123228ms).
[18:19:00.931] <TB0> INFO: 3556255 events read in total (153943ms).
[18:19:26.068] <TB0> INFO: 4139200 events read in total (179081ms).
[18:19:26.147] <TB0> INFO: Test took 179983ms.
[18:19:54.027] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 188 (-1/-1) hits flags = 528 (plus default)
[18:19:54.037] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[18:19:54.037] <TB0> INFO: run 1 of 1
[18:19:54.269] <TB0> INFO: Expecting 3931200 events.
[18:20:26.038] <TB0> INFO: 728720 events read in total (31178ms).
[18:20:56.852] <TB0> INFO: 1455335 events read in total (61992ms).
[18:21:27.770] <TB0> INFO: 2179450 events read in total (92911ms).
[18:21:58.298] <TB0> INFO: 2900890 events read in total (123438ms).
[18:22:29.084] <TB0> INFO: 3621695 events read in total (154224ms).
[18:22:42.303] <TB0> INFO: 3931200 events read in total (167443ms).
[18:22:42.370] <TB0> INFO: Test took 168333ms.
[18:23:08.514] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 185 (-1/-1) hits flags = 528 (plus default)
[18:23:08.524] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[18:23:08.524] <TB0> INFO: run 1 of 1
[18:23:08.775] <TB0> INFO: Expecting 3868800 events.
[18:23:40.579] <TB0> INFO: 733040 events read in total (31213ms).
[18:24:11.220] <TB0> INFO: 1463810 events read in total (61853ms).
[18:24:42.055] <TB0> INFO: 2192010 events read in total (92689ms).
[18:25:12.647] <TB0> INFO: 2917465 events read in total (123280ms).
[18:25:43.435] <TB0> INFO: 3642755 events read in total (154068ms).
[18:25:53.345] <TB0> INFO: 3868800 events read in total (163978ms).
[18:25:53.406] <TB0> INFO: Test took 164882ms.
[18:26:20.628] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 185 (-1/-1) hits flags = 528 (plus default)
[18:26:20.640] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[18:26:20.640] <TB0> INFO: run 1 of 1
[18:26:20.909] <TB0> INFO: Expecting 3868800 events.
[18:26:52.992] <TB0> INFO: 733120 events read in total (31492ms).
[18:27:23.863] <TB0> INFO: 1463970 events read in total (62363ms).
[18:27:54.639] <TB0> INFO: 2192370 events read in total (93139ms).
[18:28:25.227] <TB0> INFO: 2918110 events read in total (123727ms).
[18:28:55.747] <TB0> INFO: 3643550 events read in total (154247ms).
[18:29:05.502] <TB0> INFO: 3868800 events read in total (164002ms).
[18:29:05.566] <TB0> INFO: Test took 164926ms.
[18:29:29.843] <TB0> INFO: PixTestTrim::trimBitTest() done
[18:29:29.844] <TB0> INFO: PixTestTrim::doTest() done, duration: 2396 seconds
[18:29:29.844] <TB0> INFO: Decoding statistics:
[18:29:29.844] <TB0> INFO: General information:
[18:29:29.844] <TB0> INFO: 16bit words read: 0
[18:29:29.844] <TB0> INFO: valid events total: 0
[18:29:29.844] <TB0> INFO: empty events: 0
[18:29:29.844] <TB0> INFO: valid events with pixels: 0
[18:29:29.844] <TB0> INFO: valid pixel hits: 0
[18:29:29.844] <TB0> INFO: Event errors: 0
[18:29:29.844] <TB0> INFO: start marker: 0
[18:29:29.844] <TB0> INFO: stop marker: 0
[18:29:29.844] <TB0> INFO: overflow: 0
[18:29:29.844] <TB0> INFO: invalid 5bit words: 0
[18:29:29.844] <TB0> INFO: invalid XOR eye diagram: 0
[18:29:29.844] <TB0> INFO: frame (failed synchr.): 0
[18:29:29.844] <TB0> INFO: idle data (no TBM trl): 0
[18:29:29.844] <TB0> INFO: no data (only TBM hdr): 0
[18:29:29.844] <TB0> INFO: TBM errors: 0
[18:29:29.844] <TB0> INFO: flawed TBM headers: 0
[18:29:29.844] <TB0> INFO: flawed TBM trailers: 0
[18:29:29.844] <TB0> INFO: event ID mismatches: 0
[18:29:29.844] <TB0> INFO: ROC errors: 0
[18:29:29.844] <TB0> INFO: missing ROC header(s): 0
[18:29:29.844] <TB0> INFO: misplaced readback start: 0
[18:29:29.844] <TB0> INFO: Pixel decoding errors: 0
[18:29:29.844] <TB0> INFO: pixel data incomplete: 0
[18:29:29.844] <TB0> INFO: pixel address: 0
[18:29:29.844] <TB0> INFO: pulse height fill bit: 0
[18:29:29.844] <TB0> INFO: buffer corruption: 0
[18:29:30.484] <TB0> INFO: ######################################################################
[18:29:30.484] <TB0> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[18:29:30.484] <TB0> INFO: ######################################################################
[18:29:30.718] <TB0> INFO: Expecting 41600 events.
[18:29:34.255] <TB0> INFO: 41600 events read in total (2946ms).
[18:29:34.256] <TB0> INFO: Test took 3770ms.
[18:29:34.760] <TB0> INFO: Expecting 41600 events.
[18:29:38.377] <TB0> INFO: 41600 events read in total (3025ms).
[18:29:38.377] <TB0> INFO: Test took 3916ms.
[18:29:38.668] <TB0> INFO: Expecting 41600 events.
[18:29:42.194] <TB0> INFO: 41600 events read in total (2935ms).
[18:29:42.194] <TB0> INFO: Test took 3791ms.
[18:29:42.482] <TB0> INFO: Expecting 41600 events.
[18:29:46.038] <TB0> INFO: 41600 events read in total (2964ms).
[18:29:46.039] <TB0> INFO: Test took 3821ms.
[18:29:46.338] <TB0> INFO: Expecting 41600 events.
[18:29:49.918] <TB0> INFO: 41600 events read in total (2988ms).
[18:29:49.919] <TB0> INFO: Test took 3855ms.
[18:29:50.207] <TB0> INFO: Expecting 41600 events.
[18:29:53.818] <TB0> INFO: 41600 events read in total (3020ms).
[18:29:53.818] <TB0> INFO: Test took 3877ms.
[18:29:54.106] <TB0> INFO: Expecting 41600 events.
[18:29:57.709] <TB0> INFO: 41600 events read in total (3011ms).
[18:29:57.709] <TB0> INFO: Test took 3867ms.
[18:29:57.998] <TB0> INFO: Expecting 41600 events.
[18:30:01.510] <TB0> INFO: 41600 events read in total (2921ms).
[18:30:01.511] <TB0> INFO: Test took 3778ms.
[18:30:01.818] <TB0> INFO: Expecting 41600 events.
[18:30:05.480] <TB0> INFO: 41600 events read in total (3070ms).
[18:30:05.481] <TB0> INFO: Test took 3944ms.
[18:30:05.770] <TB0> INFO: Expecting 41600 events.
[18:30:09.386] <TB0> INFO: 41600 events read in total (3025ms).
[18:30:09.386] <TB0> INFO: Test took 3881ms.
[18:30:09.675] <TB0> INFO: Expecting 41600 events.
[18:30:13.175] <TB0> INFO: 41600 events read in total (2909ms).
[18:30:13.176] <TB0> INFO: Test took 3766ms.
[18:30:13.464] <TB0> INFO: Expecting 41600 events.
[18:30:16.929] <TB0> INFO: 41600 events read in total (2873ms).
[18:30:16.930] <TB0> INFO: Test took 3731ms.
[18:30:17.219] <TB0> INFO: Expecting 41600 events.
[18:30:20.780] <TB0> INFO: 41600 events read in total (2970ms).
[18:30:20.781] <TB0> INFO: Test took 3827ms.
[18:30:21.069] <TB0> INFO: Expecting 41600 events.
[18:30:24.586] <TB0> INFO: 41600 events read in total (2925ms).
[18:30:24.586] <TB0> INFO: Test took 3782ms.
[18:30:24.875] <TB0> INFO: Expecting 41600 events.
[18:30:28.476] <TB0> INFO: 41600 events read in total (3009ms).
[18:30:28.477] <TB0> INFO: Test took 3867ms.
[18:30:28.765] <TB0> INFO: Expecting 41600 events.
[18:30:32.284] <TB0> INFO: 41600 events read in total (2928ms).
[18:30:32.285] <TB0> INFO: Test took 3785ms.
[18:30:32.576] <TB0> INFO: Expecting 41600 events.
[18:30:36.154] <TB0> INFO: 41600 events read in total (2986ms).
[18:30:36.154] <TB0> INFO: Test took 3846ms.
[18:30:36.445] <TB0> INFO: Expecting 41600 events.
[18:30:39.952] <TB0> INFO: 41600 events read in total (2916ms).
[18:30:39.953] <TB0> INFO: Test took 3773ms.
[18:30:40.241] <TB0> INFO: Expecting 41600 events.
[18:30:43.797] <TB0> INFO: 41600 events read in total (2964ms).
[18:30:43.797] <TB0> INFO: Test took 3814ms.
[18:30:44.098] <TB0> INFO: Expecting 41600 events.
[18:30:47.599] <TB0> INFO: 41600 events read in total (2909ms).
[18:30:47.600] <TB0> INFO: Test took 3777ms.
[18:30:47.890] <TB0> INFO: Expecting 41600 events.
[18:30:51.398] <TB0> INFO: 41600 events read in total (2916ms).
[18:30:51.399] <TB0> INFO: Test took 3773ms.
[18:30:51.686] <TB0> INFO: Expecting 41600 events.
[18:30:55.129] <TB0> INFO: 41600 events read in total (2851ms).
[18:30:55.129] <TB0> INFO: Test took 3707ms.
[18:30:55.417] <TB0> INFO: Expecting 41600 events.
[18:30:58.870] <TB0> INFO: 41600 events read in total (2861ms).
[18:30:58.871] <TB0> INFO: Test took 3719ms.
[18:30:59.159] <TB0> INFO: Expecting 41600 events.
[18:31:02.687] <TB0> INFO: 41600 events read in total (2936ms).
[18:31:02.688] <TB0> INFO: Test took 3794ms.
[18:31:02.976] <TB0> INFO: Expecting 41600 events.
[18:31:06.508] <TB0> INFO: 41600 events read in total (2941ms).
[18:31:06.508] <TB0> INFO: Test took 3797ms.
[18:31:06.796] <TB0> INFO: Expecting 41600 events.
[18:31:10.342] <TB0> INFO: 41600 events read in total (2954ms).
[18:31:10.342] <TB0> INFO: Test took 3811ms.
[18:31:10.631] <TB0> INFO: Expecting 41600 events.
[18:31:14.079] <TB0> INFO: 41600 events read in total (2857ms).
[18:31:14.079] <TB0> INFO: Test took 3713ms.
[18:31:14.367] <TB0> INFO: Expecting 41600 events.
[18:31:17.920] <TB0> INFO: 41600 events read in total (2961ms).
[18:31:17.920] <TB0> INFO: Test took 3817ms.
[18:31:18.209] <TB0> INFO: Expecting 41600 events.
[18:31:21.745] <TB0> INFO: 41600 events read in total (2945ms).
[18:31:21.746] <TB0> INFO: Test took 3802ms.
[18:31:22.036] <TB0> INFO: Expecting 41600 events.
[18:31:25.514] <TB0> INFO: 41600 events read in total (2886ms).
[18:31:25.514] <TB0> INFO: Test took 3743ms.
[18:31:25.807] <TB0> INFO: Expecting 41600 events.
[18:31:29.270] <TB0> INFO: 41600 events read in total (2871ms).
[18:31:29.271] <TB0> INFO: Test took 3728ms.
[18:31:29.560] <TB0> INFO: Expecting 2560 events.
[18:31:30.446] <TB0> INFO: 2560 events read in total (295ms).
[18:31:30.446] <TB0> INFO: Test took 1163ms.
[18:31:30.753] <TB0> INFO: Expecting 2560 events.
[18:31:31.639] <TB0> INFO: 2560 events read in total (294ms).
[18:31:31.639] <TB0> INFO: Test took 1193ms.
[18:31:31.947] <TB0> INFO: Expecting 2560 events.
[18:31:32.829] <TB0> INFO: 2560 events read in total (290ms).
[18:31:32.829] <TB0> INFO: Test took 1190ms.
[18:31:33.138] <TB0> INFO: Expecting 2560 events.
[18:31:34.020] <TB0> INFO: 2560 events read in total (291ms).
[18:31:34.020] <TB0> INFO: Test took 1190ms.
[18:31:34.327] <TB0> INFO: Expecting 2560 events.
[18:31:35.206] <TB0> INFO: 2560 events read in total (287ms).
[18:31:35.206] <TB0> INFO: Test took 1186ms.
[18:31:35.514] <TB0> INFO: Expecting 2560 events.
[18:31:36.393] <TB0> INFO: 2560 events read in total (287ms).
[18:31:36.393] <TB0> INFO: Test took 1186ms.
[18:31:36.701] <TB0> INFO: Expecting 2560 events.
[18:31:37.579] <TB0> INFO: 2560 events read in total (286ms).
[18:31:37.580] <TB0> INFO: Test took 1187ms.
[18:31:37.888] <TB0> INFO: Expecting 2560 events.
[18:31:38.768] <TB0> INFO: 2560 events read in total (289ms).
[18:31:38.768] <TB0> INFO: Test took 1188ms.
[18:31:39.077] <TB0> INFO: Expecting 2560 events.
[18:31:39.956] <TB0> INFO: 2560 events read in total (288ms).
[18:31:39.956] <TB0> INFO: Test took 1187ms.
[18:31:40.264] <TB0> INFO: Expecting 2560 events.
[18:31:41.144] <TB0> INFO: 2560 events read in total (288ms).
[18:31:41.145] <TB0> INFO: Test took 1188ms.
[18:31:41.453] <TB0> INFO: Expecting 2560 events.
[18:31:42.335] <TB0> INFO: 2560 events read in total (290ms).
[18:31:42.336] <TB0> INFO: Test took 1191ms.
[18:31:42.643] <TB0> INFO: Expecting 2560 events.
[18:31:43.523] <TB0> INFO: 2560 events read in total (288ms).
[18:31:43.523] <TB0> INFO: Test took 1187ms.
[18:31:43.831] <TB0> INFO: Expecting 2560 events.
[18:31:44.719] <TB0> INFO: 2560 events read in total (294ms).
[18:31:44.719] <TB0> INFO: Test took 1196ms.
[18:31:45.027] <TB0> INFO: Expecting 2560 events.
[18:31:45.913] <TB0> INFO: 2560 events read in total (294ms).
[18:31:45.914] <TB0> INFO: Test took 1195ms.
[18:31:46.221] <TB0> INFO: Expecting 2560 events.
[18:31:47.104] <TB0> INFO: 2560 events read in total (291ms).
[18:31:47.104] <TB0> INFO: Test took 1190ms.
[18:31:47.412] <TB0> INFO: Expecting 2560 events.
[18:31:48.295] <TB0> INFO: 2560 events read in total (291ms).
[18:31:48.295] <TB0> INFO: Test took 1190ms.
[18:31:48.298] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:31:48.604] <TB0> INFO: Expecting 655360 events.
[18:32:02.914] <TB0> INFO: 655360 events read in total (13719ms).
[18:32:02.928] <TB0> INFO: Expecting 655360 events.
[18:32:17.082] <TB0> INFO: 655360 events read in total (13751ms).
[18:32:17.097] <TB0> INFO: Expecting 655360 events.
[18:32:31.206] <TB0> INFO: 655360 events read in total (13706ms).
[18:32:31.230] <TB0> INFO: Expecting 655360 events.
[18:32:45.395] <TB0> INFO: 655360 events read in total (13762ms).
[18:32:45.423] <TB0> INFO: Expecting 655360 events.
[18:32:59.537] <TB0> INFO: 655360 events read in total (13711ms).
[18:32:59.571] <TB0> INFO: Expecting 655360 events.
[18:33:13.674] <TB0> INFO: 655360 events read in total (13700ms).
[18:33:13.717] <TB0> INFO: Expecting 655360 events.
[18:33:27.866] <TB0> INFO: 655360 events read in total (13746ms).
[18:33:27.901] <TB0> INFO: Expecting 655360 events.
[18:33:42.016] <TB0> INFO: 655360 events read in total (13712ms).
[18:33:42.055] <TB0> INFO: Expecting 655360 events.
[18:33:56.092] <TB0> INFO: 655360 events read in total (13634ms).
[18:33:56.153] <TB0> INFO: Expecting 655360 events.
[18:34:10.220] <TB0> INFO: 655360 events read in total (13664ms).
[18:34:10.266] <TB0> INFO: Expecting 655360 events.
[18:34:24.479] <TB0> INFO: 655360 events read in total (13810ms).
[18:34:24.533] <TB0> INFO: Expecting 655360 events.
[18:34:38.678] <TB0> INFO: 655360 events read in total (13742ms).
[18:34:38.737] <TB0> INFO: Expecting 655360 events.
[18:34:52.882] <TB0> INFO: 655360 events read in total (13742ms).
[18:34:52.945] <TB0> INFO: Expecting 655360 events.
[18:35:06.002] <TB0> INFO: 655360 events read in total (13654ms).
[18:35:07.068] <TB0> INFO: Expecting 655360 events.
[18:35:21.241] <TB0> INFO: 655360 events read in total (13771ms).
[18:35:21.312] <TB0> INFO: Expecting 655360 events.
[18:35:35.494] <TB0> INFO: 655360 events read in total (13779ms).
[18:35:35.568] <TB0> INFO: Test took 227270ms.
[18:35:35.659] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:35:35.924] <TB0> INFO: Expecting 655360 events.
[18:35:50.105] <TB0> INFO: 655360 events read in total (13590ms).
[18:35:50.115] <TB0> INFO: Expecting 655360 events.
[18:36:04.056] <TB0> INFO: 655360 events read in total (13538ms).
[18:36:04.070] <TB0> INFO: Expecting 655360 events.
[18:36:18.119] <TB0> INFO: 655360 events read in total (13646ms).
[18:36:18.137] <TB0> INFO: Expecting 655360 events.
[18:36:32.103] <TB0> INFO: 655360 events read in total (13563ms).
[18:36:32.128] <TB0> INFO: Expecting 655360 events.
[18:36:46.144] <TB0> INFO: 655360 events read in total (13613ms).
[18:36:46.179] <TB0> INFO: Expecting 655360 events.
[18:37:00.139] <TB0> INFO: 655360 events read in total (13557ms).
[18:37:00.180] <TB0> INFO: Expecting 655360 events.
[18:37:14.124] <TB0> INFO: 655360 events read in total (13530ms).
[18:37:14.158] <TB0> INFO: Expecting 655360 events.
[18:37:28.049] <TB0> INFO: 655360 events read in total (13488ms).
[18:37:28.100] <TB0> INFO: Expecting 655360 events.
[18:37:42.170] <TB0> INFO: 655360 events read in total (13667ms).
[18:37:42.216] <TB0> INFO: Expecting 655360 events.
[18:37:56.125] <TB0> INFO: 655360 events read in total (13506ms).
[18:37:56.171] <TB0> INFO: Expecting 655360 events.
[18:38:10.183] <TB0> INFO: 655360 events read in total (13609ms).
[18:38:10.254] <TB0> INFO: Expecting 655360 events.
[18:38:24.181] <TB0> INFO: 655360 events read in total (13524ms).
[18:38:24.240] <TB0> INFO: Expecting 655360 events.
[18:38:38.369] <TB0> INFO: 655360 events read in total (13727ms).
[18:38:38.442] <TB0> INFO: Expecting 655360 events.
[18:38:52.492] <TB0> INFO: 655360 events read in total (13646ms).
[18:38:52.558] <TB0> INFO: Expecting 655360 events.
[18:39:06.233] <TB0> INFO: 655360 events read in total (13272ms).
[18:39:06.328] <TB0> INFO: Expecting 655360 events.
[18:39:20.365] <TB0> INFO: 655360 events read in total (13634ms).
[18:39:20.451] <TB0> INFO: Test took 224792ms.
[18:39:20.659] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.664] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[18:39:20.669] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[18:39:20.675] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[18:39:20.680] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.685] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.689] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[18:39:20.694] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[18:39:20.699] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.703] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.708] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.713] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.717] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.722] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.726] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.731] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.735] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.741] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[18:39:20.747] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[18:39:20.754] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.760] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.765] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.770] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[18:39:20.801] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C0.dat
[18:39:20.801] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C1.dat
[18:39:20.802] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C2.dat
[18:39:20.802] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C3.dat
[18:39:20.802] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C4.dat
[18:39:20.802] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C5.dat
[18:39:20.802] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C6.dat
[18:39:20.802] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C7.dat
[18:39:20.802] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C8.dat
[18:39:20.802] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C9.dat
[18:39:20.802] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C10.dat
[18:39:20.803] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C11.dat
[18:39:20.803] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C12.dat
[18:39:20.803] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C13.dat
[18:39:20.803] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C14.dat
[18:39:20.803] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//dacParameters35_C15.dat
[18:39:21.037] <TB0> INFO: Expecting 41600 events.
[18:39:24.102] <TB0> INFO: 41600 events read in total (2473ms).
[18:39:24.103] <TB0> INFO: Test took 3298ms.
[18:39:24.547] <TB0> INFO: Expecting 41600 events.
[18:39:27.584] <TB0> INFO: 41600 events read in total (2445ms).
[18:39:27.585] <TB0> INFO: Test took 3272ms.
[18:39:28.070] <TB0> INFO: Expecting 41600 events.
[18:39:31.171] <TB0> INFO: 41600 events read in total (2509ms).
[18:39:31.172] <TB0> INFO: Test took 3377ms.
[18:39:31.390] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:31.478] <TB0> INFO: Expecting 2560 events.
[18:39:32.360] <TB0> INFO: 2560 events read in total (290ms).
[18:39:32.361] <TB0> INFO: Test took 971ms.
[18:39:32.363] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:32.669] <TB0> INFO: Expecting 2560 events.
[18:39:33.554] <TB0> INFO: 2560 events read in total (293ms).
[18:39:33.555] <TB0> INFO: Test took 1193ms.
[18:39:33.556] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:33.863] <TB0> INFO: Expecting 2560 events.
[18:39:34.745] <TB0> INFO: 2560 events read in total (291ms).
[18:39:34.746] <TB0> INFO: Test took 1190ms.
[18:39:34.747] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:35.054] <TB0> INFO: Expecting 2560 events.
[18:39:35.937] <TB0> INFO: 2560 events read in total (291ms).
[18:39:35.937] <TB0> INFO: Test took 1190ms.
[18:39:35.939] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:36.246] <TB0> INFO: Expecting 2560 events.
[18:39:37.127] <TB0> INFO: 2560 events read in total (290ms).
[18:39:37.128] <TB0> INFO: Test took 1189ms.
[18:39:37.129] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:37.436] <TB0> INFO: Expecting 2560 events.
[18:39:38.319] <TB0> INFO: 2560 events read in total (291ms).
[18:39:38.319] <TB0> INFO: Test took 1190ms.
[18:39:38.321] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:38.628] <TB0> INFO: Expecting 2560 events.
[18:39:39.513] <TB0> INFO: 2560 events read in total (294ms).
[18:39:39.513] <TB0> INFO: Test took 1192ms.
[18:39:39.515] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:39.822] <TB0> INFO: Expecting 2560 events.
[18:39:40.704] <TB0> INFO: 2560 events read in total (291ms).
[18:39:40.704] <TB0> INFO: Test took 1189ms.
[18:39:40.706] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:41.013] <TB0> INFO: Expecting 2560 events.
[18:39:41.891] <TB0> INFO: 2560 events read in total (287ms).
[18:39:41.891] <TB0> INFO: Test took 1185ms.
[18:39:41.893] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:42.200] <TB0> INFO: Expecting 2560 events.
[18:39:43.081] <TB0> INFO: 2560 events read in total (290ms).
[18:39:43.081] <TB0> INFO: Test took 1188ms.
[18:39:43.083] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:43.389] <TB0> INFO: Expecting 2560 events.
[18:39:44.267] <TB0> INFO: 2560 events read in total (286ms).
[18:39:44.268] <TB0> INFO: Test took 1185ms.
[18:39:44.270] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:44.576] <TB0> INFO: Expecting 2560 events.
[18:39:45.457] <TB0> INFO: 2560 events read in total (289ms).
[18:39:45.457] <TB0> INFO: Test took 1187ms.
[18:39:45.459] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:45.766] <TB0> INFO: Expecting 2560 events.
[18:39:46.643] <TB0> INFO: 2560 events read in total (286ms).
[18:39:46.643] <TB0> INFO: Test took 1184ms.
[18:39:46.645] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:46.951] <TB0> INFO: Expecting 2560 events.
[18:39:47.829] <TB0> INFO: 2560 events read in total (286ms).
[18:39:47.829] <TB0> INFO: Test took 1184ms.
[18:39:47.831] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:48.138] <TB0> INFO: Expecting 2560 events.
[18:39:49.016] <TB0> INFO: 2560 events read in total (287ms).
[18:39:49.017] <TB0> INFO: Test took 1186ms.
[18:39:49.019] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:49.324] <TB0> INFO: Expecting 2560 events.
[18:39:50.205] <TB0> INFO: 2560 events read in total (289ms).
[18:39:50.205] <TB0> INFO: Test took 1186ms.
[18:39:50.207] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:50.513] <TB0> INFO: Expecting 2560 events.
[18:39:51.391] <TB0> INFO: 2560 events read in total (286ms).
[18:39:51.392] <TB0> INFO: Test took 1185ms.
[18:39:51.393] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:51.700] <TB0> INFO: Expecting 2560 events.
[18:39:52.582] <TB0> INFO: 2560 events read in total (291ms).
[18:39:52.582] <TB0> INFO: Test took 1189ms.
[18:39:52.584] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:52.890] <TB0> INFO: Expecting 2560 events.
[18:39:53.768] <TB0> INFO: 2560 events read in total (286ms).
[18:39:53.768] <TB0> INFO: Test took 1184ms.
[18:39:53.770] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:54.077] <TB0> INFO: Expecting 2560 events.
[18:39:54.956] <TB0> INFO: 2560 events read in total (288ms).
[18:39:54.957] <TB0> INFO: Test took 1187ms.
[18:39:54.958] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:55.265] <TB0> INFO: Expecting 2560 events.
[18:39:56.146] <TB0> INFO: 2560 events read in total (289ms).
[18:39:56.147] <TB0> INFO: Test took 1189ms.
[18:39:56.148] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:56.455] <TB0> INFO: Expecting 2560 events.
[18:39:57.334] <TB0> INFO: 2560 events read in total (287ms).
[18:39:57.334] <TB0> INFO: Test took 1186ms.
[18:39:57.336] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:57.651] <TB0> INFO: Expecting 2560 events.
[18:39:58.533] <TB0> INFO: 2560 events read in total (290ms).
[18:39:58.534] <TB0> INFO: Test took 1198ms.
[18:39:58.535] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:39:58.842] <TB0> INFO: Expecting 2560 events.
[18:39:59.720] <TB0> INFO: 2560 events read in total (287ms).
[18:39:59.720] <TB0> INFO: Test took 1185ms.
[18:39:59.722] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:00.028] <TB0> INFO: Expecting 2560 events.
[18:40:00.914] <TB0> INFO: 2560 events read in total (294ms).
[18:40:00.914] <TB0> INFO: Test took 1192ms.
[18:40:00.915] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:01.222] <TB0> INFO: Expecting 2560 events.
[18:40:02.106] <TB0> INFO: 2560 events read in total (292ms).
[18:40:02.106] <TB0> INFO: Test took 1191ms.
[18:40:02.108] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:02.414] <TB0> INFO: Expecting 2560 events.
[18:40:03.299] <TB0> INFO: 2560 events read in total (293ms).
[18:40:03.299] <TB0> INFO: Test took 1191ms.
[18:40:03.301] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:03.607] <TB0> INFO: Expecting 2560 events.
[18:40:04.490] <TB0> INFO: 2560 events read in total (291ms).
[18:40:04.490] <TB0> INFO: Test took 1189ms.
[18:40:04.492] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:04.798] <TB0> INFO: Expecting 2560 events.
[18:40:05.681] <TB0> INFO: 2560 events read in total (291ms).
[18:40:05.682] <TB0> INFO: Test took 1190ms.
[18:40:05.683] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:05.990] <TB0> INFO: Expecting 2560 events.
[18:40:06.876] <TB0> INFO: 2560 events read in total (295ms).
[18:40:06.876] <TB0> INFO: Test took 1193ms.
[18:40:06.878] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:07.184] <TB0> INFO: Expecting 2560 events.
[18:40:08.067] <TB0> INFO: 2560 events read in total (291ms).
[18:40:08.068] <TB0> INFO: Test took 1190ms.
[18:40:08.069] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:40:08.376] <TB0> INFO: Expecting 2560 events.
[18:40:09.258] <TB0> INFO: 2560 events read in total (291ms).
[18:40:09.259] <TB0> INFO: Test took 1190ms.
[18:40:09.720] <TB0> INFO: PixTestPhOptimization::doTest() done, duration: 639 seconds
[18:40:09.720] <TB0> INFO: PH scale (per ROC): 48 66 54 61 63 61 46 66 37 64 66 51 51 47 51 65
[18:40:09.720] <TB0> INFO: PH offset (per ROC): 111 118 113 132 127 122 102 132 97 119 115 112 109 105 105 124
[18:40:09.725] <TB0> INFO: Decoding statistics:
[18:40:09.725] <TB0> INFO: General information:
[18:40:09.725] <TB0> INFO: 16bit words read: 127886
[18:40:09.725] <TB0> INFO: valid events total: 20480
[18:40:09.725] <TB0> INFO: empty events: 17977
[18:40:09.725] <TB0> INFO: valid events with pixels: 2503
[18:40:09.725] <TB0> INFO: valid pixel hits: 2503
[18:40:09.725] <TB0> INFO: Event errors: 0
[18:40:09.725] <TB0> INFO: start marker: 0
[18:40:09.725] <TB0> INFO: stop marker: 0
[18:40:09.725] <TB0> INFO: overflow: 0
[18:40:09.725] <TB0> INFO: invalid 5bit words: 0
[18:40:09.725] <TB0> INFO: invalid XOR eye diagram: 0
[18:40:09.725] <TB0> INFO: frame (failed synchr.): 0
[18:40:09.725] <TB0> INFO: idle data (no TBM trl): 0
[18:40:09.725] <TB0> INFO: no data (only TBM hdr): 0
[18:40:09.725] <TB0> INFO: TBM errors: 0
[18:40:09.725] <TB0> INFO: flawed TBM headers: 0
[18:40:09.725] <TB0> INFO: flawed TBM trailers: 0
[18:40:09.725] <TB0> INFO: event ID mismatches: 0
[18:40:09.725] <TB0> INFO: ROC errors: 0
[18:40:09.725] <TB0> INFO: missing ROC header(s): 0
[18:40:09.725] <TB0> INFO: misplaced readback start: 0
[18:40:09.725] <TB0> INFO: Pixel decoding errors: 0
[18:40:09.725] <TB0> INFO: pixel data incomplete: 0
[18:40:09.725] <TB0> INFO: pixel address: 0
[18:40:09.725] <TB0> INFO: pulse height fill bit: 0
[18:40:09.725] <TB0> INFO: buffer corruption: 0
[18:40:09.995] <TB0> INFO: ######################################################################
[18:40:09.995] <TB0> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[18:40:09.995] <TB0> INFO: ######################################################################
[18:40:10.006] <TB0> INFO: scanning low vcal = 10
[18:40:10.243] <TB0> INFO: Expecting 41600 events.
[18:40:13.815] <TB0> INFO: 41600 events read in total (2980ms).
[18:40:13.815] <TB0> INFO: Test took 3808ms.
[18:40:13.816] <TB0> INFO: scanning low vcal = 20
[18:40:14.113] <TB0> INFO: Expecting 41600 events.
[18:40:17.680] <TB0> INFO: 41600 events read in total (2975ms).
[18:40:17.680] <TB0> INFO: Test took 3863ms.
[18:40:17.681] <TB0> INFO: scanning low vcal = 30
[18:40:17.979] <TB0> INFO: Expecting 41600 events.
[18:40:21.593] <TB0> INFO: 41600 events read in total (3023ms).
[18:40:21.593] <TB0> INFO: Test took 3911ms.
[18:40:21.595] <TB0> INFO: scanning low vcal = 40
[18:40:21.875] <TB0> INFO: Expecting 41600 events.
[18:40:25.778] <TB0> INFO: 41600 events read in total (3312ms).
[18:40:25.779] <TB0> INFO: Test took 4183ms.
[18:40:25.782] <TB0> INFO: scanning low vcal = 50
[18:40:26.059] <TB0> INFO: Expecting 41600 events.
[18:40:29.988] <TB0> INFO: 41600 events read in total (3338ms).
[18:40:29.988] <TB0> INFO: Test took 4206ms.
[18:40:29.991] <TB0> INFO: scanning low vcal = 60
[18:40:30.271] <TB0> INFO: Expecting 41600 events.
[18:40:34.191] <TB0> INFO: 41600 events read in total (3328ms).
[18:40:34.192] <TB0> INFO: Test took 4201ms.
[18:40:34.194] <TB0> INFO: scanning low vcal = 70
[18:40:34.471] <TB0> INFO: Expecting 41600 events.
[18:40:38.392] <TB0> INFO: 41600 events read in total (3329ms).
[18:40:38.392] <TB0> INFO: Test took 4198ms.
[18:40:38.395] <TB0> INFO: scanning low vcal = 80
[18:40:38.672] <TB0> INFO: Expecting 41600 events.
[18:40:42.624] <TB0> INFO: 41600 events read in total (3361ms).
[18:40:42.625] <TB0> INFO: Test took 4230ms.
[18:40:42.628] <TB0> INFO: scanning low vcal = 90
[18:40:42.904] <TB0> INFO: Expecting 41600 events.
[18:40:46.841] <TB0> INFO: 41600 events read in total (3345ms).
[18:40:46.841] <TB0> INFO: Test took 4213ms.
[18:40:46.844] <TB0> INFO: scanning low vcal = 100
[18:40:47.121] <TB0> INFO: Expecting 41600 events.
[18:40:51.063] <TB0> INFO: 41600 events read in total (3351ms).
[18:40:51.064] <TB0> INFO: Test took 4220ms.
[18:40:51.067] <TB0> INFO: scanning low vcal = 110
[18:40:51.343] <TB0> INFO: Expecting 41600 events.
[18:40:55.322] <TB0> INFO: 41600 events read in total (3387ms).
[18:40:55.323] <TB0> INFO: Test took 4256ms.
[18:40:55.325] <TB0> INFO: scanning low vcal = 120
[18:40:55.602] <TB0> INFO: Expecting 41600 events.
[18:40:59.557] <TB0> INFO: 41600 events read in total (3345ms).
[18:40:59.558] <TB0> INFO: Test took 4233ms.
[18:40:59.561] <TB0> INFO: scanning low vcal = 130
[18:40:59.837] <TB0> INFO: Expecting 41600 events.
[18:41:03.789] <TB0> INFO: 41600 events read in total (3360ms).
[18:41:03.789] <TB0> INFO: Test took 4228ms.
[18:41:03.792] <TB0> INFO: scanning low vcal = 140
[18:41:04.069] <TB0> INFO: Expecting 41600 events.
[18:41:07.990] <TB0> INFO: 41600 events read in total (3330ms).
[18:41:07.991] <TB0> INFO: Test took 4199ms.
[18:41:07.994] <TB0> INFO: scanning low vcal = 150
[18:41:08.270] <TB0> INFO: Expecting 41600 events.
[18:41:12.177] <TB0> INFO: 41600 events read in total (3315ms).
[18:41:12.178] <TB0> INFO: Test took 4184ms.
[18:41:12.180] <TB0> INFO: scanning low vcal = 160
[18:41:12.457] <TB0> INFO: Expecting 41600 events.
[18:41:16.388] <TB0> INFO: 41600 events read in total (3339ms).
[18:41:16.388] <TB0> INFO: Test took 4207ms.
[18:41:16.391] <TB0> INFO: scanning low vcal = 170
[18:41:16.667] <TB0> INFO: Expecting 41600 events.
[18:41:20.621] <TB0> INFO: 41600 events read in total (3362ms).
[18:41:20.622] <TB0> INFO: Test took 4231ms.
[18:41:20.625] <TB0> INFO: scanning low vcal = 180
[18:41:20.902] <TB0> INFO: Expecting 41600 events.
[18:41:24.836] <TB0> INFO: 41600 events read in total (3343ms).
[18:41:24.837] <TB0> INFO: Test took 4212ms.
[18:41:24.839] <TB0> INFO: scanning low vcal = 190
[18:41:25.116] <TB0> INFO: Expecting 41600 events.
[18:41:29.058] <TB0> INFO: 41600 events read in total (3351ms).
[18:41:29.058] <TB0> INFO: Test took 4219ms.
[18:41:29.061] <TB0> INFO: scanning low vcal = 200
[18:41:29.337] <TB0> INFO: Expecting 41600 events.
[18:41:33.285] <TB0> INFO: 41600 events read in total (3356ms).
[18:41:33.285] <TB0> INFO: Test took 4224ms.
[18:41:33.288] <TB0> INFO: scanning low vcal = 210
[18:41:33.565] <TB0> INFO: Expecting 41600 events.
[18:41:37.478] <TB0> INFO: 41600 events read in total (3322ms).
[18:41:37.479] <TB0> INFO: Test took 4191ms.
[18:41:37.482] <TB0> INFO: scanning low vcal = 220
[18:41:37.759] <TB0> INFO: Expecting 41600 events.
[18:41:41.679] <TB0> INFO: 41600 events read in total (3329ms).
[18:41:41.680] <TB0> INFO: Test took 4198ms.
[18:41:41.682] <TB0> INFO: scanning low vcal = 230
[18:41:41.959] <TB0> INFO: Expecting 41600 events.
[18:41:45.876] <TB0> INFO: 41600 events read in total (3326ms).
[18:41:45.876] <TB0> INFO: Test took 4194ms.
[18:41:45.879] <TB0> INFO: scanning low vcal = 240
[18:41:46.155] <TB0> INFO: Expecting 41600 events.
[18:41:50.087] <TB0> INFO: 41600 events read in total (3340ms).
[18:41:50.088] <TB0> INFO: Test took 4209ms.
[18:41:50.090] <TB0> INFO: scanning low vcal = 250
[18:41:50.367] <TB0> INFO: Expecting 41600 events.
[18:41:54.311] <TB0> INFO: 41600 events read in total (3352ms).
[18:41:54.312] <TB0> INFO: Test took 4222ms.
[18:41:54.316] <TB0> INFO: scanning high vcal = 30 (= 210 in low range)
[18:41:54.592] <TB0> INFO: Expecting 41600 events.
[18:41:58.553] <TB0> INFO: 41600 events read in total (3370ms).
[18:41:58.553] <TB0> INFO: Test took 4237ms.
[18:41:58.556] <TB0> INFO: scanning high vcal = 50 (= 350 in low range)
[18:41:58.833] <TB0> INFO: Expecting 41600 events.
[18:42:02.744] <TB0> INFO: 41600 events read in total (3320ms).
[18:42:02.745] <TB0> INFO: Test took 4189ms.
[18:42:02.748] <TB0> INFO: scanning high vcal = 70 (= 490 in low range)
[18:42:03.025] <TB0> INFO: Expecting 41600 events.
[18:42:06.977] <TB0> INFO: 41600 events read in total (3361ms).
[18:42:06.978] <TB0> INFO: Test took 4230ms.
[18:42:06.980] <TB0> INFO: scanning high vcal = 90 (= 630 in low range)
[18:42:07.257] <TB0> INFO: Expecting 41600 events.
[18:42:11.177] <TB0> INFO: 41600 events read in total (3329ms).
[18:42:11.178] <TB0> INFO: Test took 4198ms.
[18:42:11.180] <TB0> INFO: scanning high vcal = 200 (= 1400 in low range)
[18:42:11.457] <TB0> INFO: Expecting 41600 events.
[18:42:15.385] <TB0> INFO: 41600 events read in total (3336ms).
[18:42:15.386] <TB0> INFO: Test took 4206ms.
[18:42:15.935] <TB0> INFO: PixTestGainPedestal::measure() done
[18:42:53.002] <TB0> INFO: PixTestGainPedestal::fit() done
[18:42:53.002] <TB0> INFO: non-linearity mean: 0.915 0.981 0.963 0.983 0.975 0.982 0.928 0.982 0.941 0.984 0.985 0.935 0.925 0.941 0.918 0.980
[18:42:53.002] <TB0> INFO: non-linearity RMS: 0.097 0.004 0.022 0.004 0.004 0.003 0.088 0.004 0.175 0.004 0.003 0.078 0.071 0.088 0.143 0.003
[18:42:53.002] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[18:42:54.016] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[18:42:54.030] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[18:42:54.043] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[18:42:54.057] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[18:42:54.071] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[18:42:54.085] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[18:42:54.099] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[18:42:54.113] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[18:42:54.126] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[18:42:54.140] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[18:42:54.154] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[18:42:54.168] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[18:42:54.182] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[18:42:54.195] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[18:42:54.209] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1093_FullQualification_2016-10-26_16h26m_1477492000//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[18:42:54.223] <TB0> INFO: PixTestGainPedestal::fullTest() done, duration: 164 seconds
[18:42:54.223] <TB0> INFO: Decoding statistics:
[18:42:54.223] <TB0> INFO: General information:
[18:42:54.223] <TB0> INFO: 16bit words read: 3327918
[18:42:54.223] <TB0> INFO: valid events total: 332800
[18:42:54.223] <TB0> INFO: empty events: 0
[18:42:54.223] <TB0> INFO: valid events with pixels: 332800
[18:42:54.223] <TB0> INFO: valid pixel hits: 665559
[18:42:54.223] <TB0> INFO: Event errors: 0
[18:42:54.223] <TB0> INFO: start marker: 0
[18:42:54.223] <TB0> INFO: stop marker: 0
[18:42:54.223] <TB0> INFO: overflow: 0
[18:42:54.223] <TB0> INFO: invalid 5bit words: 0
[18:42:54.223] <TB0> INFO: invalid XOR eye diagram: 0
[18:42:54.223] <TB0> INFO: frame (failed synchr.): 0
[18:42:54.223] <TB0> INFO: idle data (no TBM trl): 0
[18:42:54.223] <TB0> INFO: no data (only TBM hdr): 0
[18:42:54.223] <TB0> INFO: TBM errors: 0
[18:42:54.223] <TB0> INFO: flawed TBM headers: 0
[18:42:54.223] <TB0> INFO: flawed TBM trailers: 0
[18:42:54.223] <TB0> INFO: event ID mismatches: 0
[18:42:54.223] <TB0> INFO: ROC errors: 0
[18:42:54.223] <TB0> INFO: missing ROC header(s): 0
[18:42:54.223] <TB0> INFO: misplaced readback start: 0
[18:42:54.223] <TB0> INFO: Pixel decoding errors: 0
[18:42:54.223] <TB0> INFO: pixel data incomplete: 0
[18:42:54.223] <TB0> INFO: pixel address: 0
[18:42:54.223] <TB0> INFO: pulse height fill bit: 0
[18:42:54.223] <TB0> INFO: buffer corruption: 0
[18:42:54.237] <TB0> INFO: Decoding statistics:
[18:42:54.237] <TB0> INFO: General information:
[18:42:54.237] <TB0> INFO: 16bit words read: 3457340
[18:42:54.237] <TB0> INFO: valid events total: 353536
[18:42:54.237] <TB0> INFO: empty events: 18233
[18:42:54.238] <TB0> INFO: valid events with pixels: 335303
[18:42:54.238] <TB0> INFO: valid pixel hits: 668062
[18:42:54.238] <TB0> INFO: Event errors: 0
[18:42:54.238] <TB0> INFO: start marker: 0
[18:42:54.238] <TB0> INFO: stop marker: 0
[18:42:54.238] <TB0> INFO: overflow: 0
[18:42:54.238] <TB0> INFO: invalid 5bit words: 0
[18:42:54.238] <TB0> INFO: invalid XOR eye diagram: 0
[18:42:54.238] <TB0> INFO: frame (failed synchr.): 0
[18:42:54.238] <TB0> INFO: idle data (no TBM trl): 0
[18:42:54.238] <TB0> INFO: no data (only TBM hdr): 0
[18:42:54.238] <TB0> INFO: TBM errors: 0
[18:42:54.238] <TB0> INFO: flawed TBM headers: 0
[18:42:54.238] <TB0> INFO: flawed TBM trailers: 0
[18:42:54.238] <TB0> INFO: event ID mismatches: 0
[18:42:54.238] <TB0> INFO: ROC errors: 0
[18:42:54.238] <TB0> INFO: missing ROC header(s): 0
[18:42:54.238] <TB0> INFO: misplaced readback start: 0
[18:42:54.238] <TB0> INFO: Pixel decoding errors: 0
[18:42:54.238] <TB0> INFO: pixel data incomplete: 0
[18:42:54.238] <TB0> INFO: pixel address: 0
[18:42:54.238] <TB0> INFO: pulse height fill bit: 0
[18:42:54.238] <TB0> INFO: buffer corruption: 0
[18:42:54.238] <TB0> INFO: enter test to run
[18:42:54.238] <TB0> INFO: test: exit no parameter change
[18:42:54.276] <TB0> QUIET: Connection to board 73 closed.
[18:42:54.276] <TB0> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud