Test Date: 2016-10-21 18:29
Analysis date: 2016-10-24 09:32
Logfile
LogfileView
[20:57:44.980] <TB0> INFO: *** Welcome to pxar ***
[20:57:44.980] <TB0> INFO: *** Today: 2016/10/21
[20:57:44.986] <TB0> INFO: *** Version: c8ba-dirty
[20:57:44.986] <TB0> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C15.dat
[20:57:44.986] <TB0> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//tbmParameters_C1b.dat
[20:57:44.987] <TB0> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//defaultMaskFile.dat
[20:57:44.987] <TB0> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters_C15.dat
[20:57:45.045] <TB0> INFO: clk: 4
[20:57:45.045] <TB0> INFO: ctr: 4
[20:57:45.045] <TB0> INFO: sda: 19
[20:57:45.045] <TB0> INFO: tin: 9
[20:57:45.045] <TB0> INFO: level: 15
[20:57:45.045] <TB0> INFO: triggerdelay: 0
[20:57:45.045] <TB0> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[20:57:45.045] <TB0> INFO: Log level: INFO
[20:57:45.054] <TB0> INFO: Found DTB DTB_WRQ4OZ
[20:57:45.064] <TB0> QUIET: Connection to board DTB_WRQ4OZ opened.
[20:57:45.066] <TB0> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 71
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WRQ4OZ
MAC address: 40D855118047
Hostname: pixelDTB071
Comment:
------------------------------------------------------
[20:57:45.068] <TB0> INFO: RPC call hashes of host and DTB match: 486171790
[20:57:46.554] <TB0> INFO: DUT info:
[20:57:46.554] <TB0> INFO: The DUT currently contains the following objects:
[20:57:46.554] <TB0> INFO: 4 TBM Cores tbm10c (4 ON)
[20:57:46.554] <TB0> INFO: TBM Core alpha (0): 7 registers set
[20:57:46.554] <TB0> INFO: TBM Core beta (1): 7 registers set
[20:57:46.554] <TB0> INFO: TBM Core alpha (2): 7 registers set
[20:57:46.554] <TB0> INFO: TBM Core beta (3): 7 registers set
[20:57:46.554] <TB0> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[20:57:46.554] <TB0> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.554] <TB0> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.554] <TB0> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.554] <TB0> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.554] <TB0> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.554] <TB0> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.554] <TB0> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.555] <TB0> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.555] <TB0> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.555] <TB0> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.555] <TB0> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.555] <TB0> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.555] <TB0> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.555] <TB0> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.555] <TB0> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.555] <TB0> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[20:57:46.955] <TB0> INFO: enter 'restricted' command line mode
[20:57:46.955] <TB0> INFO: enter test to run
[20:57:46.955] <TB0> INFO: test: pretest no parameter change
[20:57:46.956] <TB0> INFO: running: pretest
[20:57:46.960] <TB0> INFO: ######################################################################
[20:57:46.960] <TB0> INFO: PixTestPretest::doTest()
[20:57:46.960] <TB0> INFO: ######################################################################
[20:57:46.961] <TB0> INFO: ----------------------------------------------------------------------
[20:57:46.961] <TB0> INFO: PixTestPretest::programROC()
[20:57:46.961] <TB0> INFO: ----------------------------------------------------------------------
[20:58:04.974] <TB0> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[20:58:04.974] <TB0> INFO: IA differences per ROC: 18.5 18.5 19.3 17.7 19.3 17.7 16.1 18.5 18.5 20.1 20.9 17.7 20.1 18.5 20.9 19.3
[20:58:05.041] <TB0> INFO: ----------------------------------------------------------------------
[20:58:05.041] <TB0> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[20:58:05.041] <TB0> INFO: ----------------------------------------------------------------------
[20:58:26.317] <TB0> INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[20:58:26.318] <TB0> INFO: i(loss) [mA/ROC]: 20.1 20.9 19.3 19.3 19.3 20.1 19.3 20.1 20.9 20.1 20.1 19.3 20.1 19.3 19.3 20.9
[20:58:26.351] <TB0> INFO: ----------------------------------------------------------------------
[20:58:26.351] <TB0> INFO: PixTestPretest::findTiming()
[20:58:26.351] <TB0> INFO: ----------------------------------------------------------------------
[20:58:26.351] <TB0> INFO: PixTestCmd::init()
[20:58:26.913] <TB0> WARNING: Not unmasking DUT, not setting Calibrate bits!

[20:58:58.801] <TB0> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[20:58:58.801] <TB0> INFO: (success/tries = 100/100), width = 3
[20:59:00.314] <TB0> INFO: ----------------------------------------------------------------------
[20:59:00.314] <TB0> INFO: PixTestPretest::findWorkingPixel()
[20:59:00.314] <TB0> INFO: ----------------------------------------------------------------------
[20:59:00.410] <TB0> INFO: Expecting 231680 events.
[20:59:10.348] <TB0> INFO: 231680 events read in total (9347ms).
[20:59:10.358] <TB0> INFO: Test took 10038ms.
[20:59:10.611] <TB0> INFO: Found working pixel in all ROCs: col/row = 12/22
[20:59:10.645] <TB0> INFO: ----------------------------------------------------------------------
[20:59:10.645] <TB0> INFO: PixTestPretest::setVthrCompCalDel()
[20:59:10.645] <TB0> INFO: ----------------------------------------------------------------------
[20:59:10.739] <TB0> INFO: Expecting 231680 events.
[20:59:20.532] <TB0> INFO: 231680 events read in total (9201ms).
[20:59:20.543] <TB0> INFO: Test took 9893ms.
[20:59:20.810] <TB0> INFO: PixTestPretest::setVthrCompCalDel() done
[20:59:20.810] <TB0> INFO: CalDel: 96 87 122 90 87 93 78 81 80 86 86 90 85 82 69 87
[20:59:20.810] <TB0> INFO: VthrComp: 55 51 52 51 55 51 51 51 51 51 53 51 54 51 56 51
[20:59:20.813] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C0.dat
[20:59:20.814] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C1.dat
[20:59:20.814] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C2.dat
[20:59:20.814] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C3.dat
[20:59:20.814] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C4.dat
[20:59:20.815] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C5.dat
[20:59:20.815] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C6.dat
[20:59:20.815] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C7.dat
[20:59:20.815] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C8.dat
[20:59:20.815] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C9.dat
[20:59:20.815] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C10.dat
[20:59:20.816] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C11.dat
[20:59:20.816] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C12.dat
[20:59:20.816] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C13.dat
[20:59:20.816] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C14.dat
[20:59:20.816] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters_C15.dat
[20:59:20.816] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//tbmParameters_C0a.dat
[20:59:20.816] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//tbmParameters_C0b.dat
[20:59:20.816] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//tbmParameters_C1a.dat
[20:59:20.816] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//tbmParameters_C1b.dat
[20:59:20.816] <TB0> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[20:59:20.871] <TB0> INFO: enter test to run
[20:59:20.871] <TB0> INFO: test: FullTest no parameter change
[20:59:20.871] <TB0> INFO: running: fulltest
[20:59:20.872] <TB0> INFO: ######################################################################
[20:59:20.872] <TB0> INFO: PixTestFullTest::doTest()
[20:59:20.872] <TB0> INFO: ######################################################################
[20:59:20.873] <TB0> INFO: ######################################################################
[20:59:20.873] <TB0> INFO: PixTestAlive::doTest()
[20:59:20.873] <TB0> INFO: ######################################################################
[20:59:20.874] <TB0> INFO: ----------------------------------------------------------------------
[20:59:20.874] <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)
[20:59:20.874] <TB0> INFO: ----------------------------------------------------------------------
[20:59:21.115] <TB0> INFO: Expecting 41600 events.
[20:59:24.655] <TB0> INFO: 41600 events read in total (2948ms).
[20:59:24.656] <TB0> INFO: Test took 3781ms.
[20:59:24.890] <TB0> INFO: PixTestAlive::aliveTest() done
[20:59:24.890] <TB0> INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 1 0 0 0
[20:59:24.892] <TB0> INFO: ----------------------------------------------------------------------
[20:59:24.892] <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)
[20:59:24.892] <TB0> INFO: ----------------------------------------------------------------------
[20:59:25.135] <TB0> INFO: Expecting 41600 events.
[20:59:28.066] <TB0> INFO: 41600 events read in total (2340ms).
[20:59:28.066] <TB0> INFO: Test took 3172ms.
[20:59:28.066] <TB0> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[20:59:28.306] <TB0> INFO: PixTestAlive::maskTest() done
[20:59:28.306] <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
[20:59:28.308] <TB0> INFO: ----------------------------------------------------------------------
[20:59:28.308] <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)
[20:59:28.308] <TB0> INFO: ----------------------------------------------------------------------
[20:59:28.554] <TB0> INFO: Expecting 41600 events.
[20:59:32.103] <TB0> INFO: 41600 events read in total (2957ms).
[20:59:32.104] <TB0> INFO: Test took 3794ms.
[20:59:32.338] <TB0> INFO: PixTestAlive::addressDecodingTest() done
[20:59:32.338] <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
[20:59:32.338] <TB0> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[20:59:32.338] <TB0> INFO: Decoding statistics:
[20:59:32.338] <TB0> INFO: General information:
[20:59:32.338] <TB0> INFO: 16bit words read: 0
[20:59:32.338] <TB0> INFO: valid events total: 0
[20:59:32.338] <TB0> INFO: empty events: 0
[20:59:32.338] <TB0> INFO: valid events with pixels: 0
[20:59:32.339] <TB0> INFO: valid pixel hits: 0
[20:59:32.339] <TB0> INFO: Event errors: 0
[20:59:32.339] <TB0> INFO: start marker: 0
[20:59:32.339] <TB0> INFO: stop marker: 0
[20:59:32.339] <TB0> INFO: overflow: 0
[20:59:32.339] <TB0> INFO: invalid 5bit words: 0
[20:59:32.339] <TB0> INFO: invalid XOR eye diagram: 0
[20:59:32.339] <TB0> INFO: frame (failed synchr.): 0
[20:59:32.339] <TB0> INFO: idle data (no TBM trl): 0
[20:59:32.339] <TB0> INFO: no data (only TBM hdr): 0
[20:59:32.339] <TB0> INFO: TBM errors: 0
[20:59:32.339] <TB0> INFO: flawed TBM headers: 0
[20:59:32.339] <TB0> INFO: flawed TBM trailers: 0
[20:59:32.339] <TB0> INFO: event ID mismatches: 0
[20:59:32.339] <TB0> INFO: ROC errors: 0
[20:59:32.339] <TB0> INFO: missing ROC header(s): 0
[20:59:32.339] <TB0> INFO: misplaced readback start: 0
[20:59:32.339] <TB0> INFO: Pixel decoding errors: 0
[20:59:32.339] <TB0> INFO: pixel data incomplete: 0
[20:59:32.339] <TB0> INFO: pixel address: 0
[20:59:32.339] <TB0> INFO: pulse height fill bit: 0
[20:59:32.339] <TB0> INFO: buffer corruption: 0
[20:59:32.347] <TB0> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C15.dat
[20:59:32.348] <TB0> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr_C15.dat
[20:59:32.348] <TB0> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[20:59:32.348] <TB0> INFO: ######################################################################
[20:59:32.348] <TB0> INFO: PixTestReadback::doTest()
[20:59:32.348] <TB0> INFO: ######################################################################
[20:59:32.348] <TB0> INFO: ----------------------------------------------------------------------
[20:59:32.348] <TB0> INFO: PixTestReadback::CalibrateVd()
[20:59:32.348] <TB0> INFO: ----------------------------------------------------------------------
[20:59:42.305] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C0.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C1.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C2.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C3.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C4.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C5.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C6.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C7.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C8.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C9.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C10.dat
[20:59:42.306] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C11.dat
[20:59:42.307] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C12.dat
[20:59:42.307] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C13.dat
[20:59:42.307] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C14.dat
[20:59:42.307] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C15.dat
[20:59:42.338] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[20:59:42.338] <TB0> INFO: ----------------------------------------------------------------------
[20:59:42.338] <TB0> INFO: PixTestReadback::CalibrateVa()
[20:59:42.338] <TB0> INFO: ----------------------------------------------------------------------
[20:59:52.261] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C0.dat
[20:59:52.261] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C1.dat
[20:59:52.261] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C2.dat
[20:59:52.261] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C3.dat
[20:59:52.261] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C4.dat
[20:59:52.261] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C5.dat
[20:59:52.261] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C6.dat
[20:59:52.262] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C7.dat
[20:59:52.262] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C8.dat
[20:59:52.262] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C9.dat
[20:59:52.262] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C10.dat
[20:59:52.262] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C11.dat
[20:59:52.262] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C12.dat
[20:59:52.262] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C13.dat
[20:59:52.262] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C14.dat
[20:59:52.262] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C15.dat
[20:59:52.290] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[20:59:52.290] <TB0> INFO: ----------------------------------------------------------------------
[20:59:52.290] <TB0> INFO: PixTestReadback::readbackVbg()
[20:59:52.290] <TB0> INFO: ----------------------------------------------------------------------
[20:59:59.952] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[20:59:59.952] <TB0> INFO: ----------------------------------------------------------------------
[20:59:59.952] <TB0> INFO: PixTestReadback::getCalibratedVbg()
[20:59:59.952] <TB0> INFO: ----------------------------------------------------------------------
[20:59:59.952] <TB0> INFO: Vbg will be calibrated using Vd calibration
[20:59:59.952] <TB0> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 158.6calibrated Vbg = 1.18523 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 156.8calibrated Vbg = 1.18915 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 154.7calibrated Vbg = 1.18473 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 162.3calibrated Vbg = 1.17505 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 157.9calibrated Vbg = 1.1823 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 166.7calibrated Vbg = 1.19315 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 150.7calibrated Vbg = 1.17625 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 152.5calibrated Vbg = 1.18777 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 149.4calibrated Vbg = 1.18169 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 157.4calibrated Vbg = 1.17919 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 160.1calibrated Vbg = 1.17158 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 151.1calibrated Vbg = 1.17142 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 160.1calibrated Vbg = 1.17464 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 161.8calibrated Vbg = 1.1794 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 162.5calibrated Vbg = 1.18449 :::*/*/*/*/
[20:59:59.953] <TB0> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 159calibrated Vbg = 1.1774 :::*/*/*/*/
[20:59:59.955] <TB0> INFO: ----------------------------------------------------------------------
[20:59:59.955] <TB0> INFO: PixTestReadback::CalibrateIa()
[20:59:59.955] <TB0> INFO: ----------------------------------------------------------------------
[21:02:40.818] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C0.dat
[21:02:40.818] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C1.dat
[21:02:40.818] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C2.dat
[21:02:40.818] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C3.dat
[21:02:40.818] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C4.dat
[21:02:40.818] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C5.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C6.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C7.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C8.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C9.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C10.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C11.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C12.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C13.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C14.dat
[21:02:40.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//readbackCal_C15.dat
[21:02:40.845] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[21:02:40.846] <TB0> INFO: PixTestReadback::doTest() done
[21:02:40.846] <TB0> INFO: Decoding statistics:
[21:02:40.846] <TB0> INFO: General information:
[21:02:40.846] <TB0> INFO: 16bit words read: 1536
[21:02:40.846] <TB0> INFO: valid events total: 256
[21:02:40.847] <TB0> INFO: empty events: 256
[21:02:40.847] <TB0> INFO: valid events with pixels: 0
[21:02:40.847] <TB0> INFO: valid pixel hits: 0
[21:02:40.847] <TB0> INFO: Event errors: 0
[21:02:40.847] <TB0> INFO: start marker: 0
[21:02:40.847] <TB0> INFO: stop marker: 0
[21:02:40.847] <TB0> INFO: overflow: 0
[21:02:40.847] <TB0> INFO: invalid 5bit words: 0
[21:02:40.847] <TB0> INFO: invalid XOR eye diagram: 0
[21:02:40.847] <TB0> INFO: frame (failed synchr.): 0
[21:02:40.847] <TB0> INFO: idle data (no TBM trl): 0
[21:02:40.847] <TB0> INFO: no data (only TBM hdr): 0
[21:02:40.847] <TB0> INFO: TBM errors: 0
[21:02:40.847] <TB0> INFO: flawed TBM headers: 0
[21:02:40.847] <TB0> INFO: flawed TBM trailers: 0
[21:02:40.847] <TB0> INFO: event ID mismatches: 0
[21:02:40.847] <TB0> INFO: ROC errors: 0
[21:02:40.847] <TB0> INFO: missing ROC header(s): 0
[21:02:40.847] <TB0> INFO: misplaced readback start: 0
[21:02:40.847] <TB0> INFO: Pixel decoding errors: 0
[21:02:40.847] <TB0> INFO: pixel data incomplete: 0
[21:02:40.847] <TB0> INFO: pixel address: 0
[21:02:40.847] <TB0> INFO: pulse height fill bit: 0
[21:02:40.847] <TB0> INFO: buffer corruption: 0
[21:02:40.895] <TB0> INFO: ######################################################################
[21:02:40.895] <TB0> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[21:02:40.895] <TB0> INFO: ######################################################################
[21:02:40.898] <TB0> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[21:02:40.914] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[21:02:40.914] <TB0> INFO: run 1 of 1
[21:02:41.176] <TB0> INFO: Expecting 3120000 events.
[21:03:12.560] <TB0> INFO: 667435 events read in total (30792ms).
[21:03:24.709] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (172) != TBM ID (129)

[21:03:24.850] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 172 172 129 172 172 172 172 172

[21:03:24.850] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (173)

[21:03:24.850] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[21:03:24.850] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b0 80b1 4180 262 23cd 4181 262 23ef e022 c000

[21:03:24.850] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0aa 8000 4180 262 23cc 4180 262 23ef e022 c000

[21:03:24.850] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ab 8040 4180 262 23cc 4180 262 23ef e022 c000

[21:03:24.850] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4180 23c9 4181 262 23ef e022 c000

[21:03:24.850] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ad 80c0 4181 262 23cc 4181 262 23ef e022 c000

[21:03:24.850] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ae 8000 4181 262 23cb 4182 262 23ef e022 c000

[21:03:24.850] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0af 8040 4182 262 23cd 4180 262 23ef e022 c000

[21:03:42.612] <TB0> INFO: 1328855 events read in total (60844ms).
[21:03:54.715] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (88) != TBM ID (129)

[21:03:54.853] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 88 88 129 88 88 88 88 88

[21:03:54.853] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (89)

[21:03:54.856] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[21:03:54.856] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05c 80b1 4181 4c2 27ef 4180 4c2 27ef e022 c000

[21:03:54.856] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a056 8000 4180 4c2 27ef 4180 4c2 27ef e022 c000

[21:03:54.856] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a057 8040 4180 4c2 27ef 4180 4c2 27ef e022 c000

[21:03:54.856] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4180 27ef 4181 4c2 27ef e022 c000

[21:03:54.856] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a059 80c0 4181 4c2 27ef 4181 4c2 27ef e022 c000

[21:03:54.856] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05a 8000 4181 4c2 27ef 4181 4c2 27ef e022 c000

[21:03:54.856] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05b 8040 4181 4c2 27ef 4181 4c2 27ef e022 c000

[21:04:12.587] <TB0> INFO: 1987870 events read in total (90819ms).
[21:04:24.750] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (159) != TBM ID (129)

[21:04:24.887] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 159 159 129 159 159 159 159 159

[21:04:24.888] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (160)

[21:04:24.888] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[21:04:24.888] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a3 8040 4180 4180 e022 c000

[21:04:24.888] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09d 80c0 4180 4181 e022 c000

[21:04:24.888] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09e 8000 4180 4182 e022 c000

[21:04:24.888] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4180 25ef 4180 e022 c000

[21:04:24.888] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a0 80b1 4180 4381 e022 c000

[21:04:24.888] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a1 80c0 4181 4180 e022 c000

[21:04:24.888] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a2 8000 4180 4181 e022 c000

[21:04:24.892] <TB0> WARNING: Channel 0 ROC 0: Readback start marker after 32 readouts!

[21:04:24.892] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[21:04:24.892] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b2 8000 4180 822 25ef 4181 e022 c000

[21:04:24.892] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ac 80b1 4181 4180 e022 c000

[21:04:24.892] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ad 80c0 4180 4181 e022 c000

[21:04:24.892] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ae 8000 4181 4182 822 25ef e022 c000

[21:04:24.892] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0af 8040 4182 822 25ef 4380 e022 c000

[21:04:24.892] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b0 80b1 4180 4181 e022 c000

[21:04:24.892] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b1 80c0 4181 822 25ef 4180 e022 c000

[21:04:42.822] <TB0> INFO: 2649315 events read in total (121054ms).
[21:04:51.564] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (100) != TBM ID (129)

[21:04:51.703] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 100 100 129 100 100 100 100 100

[21:04:51.703] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (101)

[21:04:51.703] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[21:04:51.703] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a068 80b1 4180 4180 e022 c000

[21:04:51.703] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a062 8000 4180 4181 e022 c000

[21:04:51.703] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a063 8040 4180 4180 e022 c000

[21:04:51.703] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4180 e022 c000

[21:04:51.703] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a065 80c0 4180 4180 e022 c000

[21:04:51.703] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a066 8000 4180 4180 e022 c000

[21:04:51.703] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a067 8040 4180 4180 e022 c000

[21:05:04.294] <TB0> INFO: 3120000 events read in total (142526ms).
[21:05:04.357] <TB0> INFO: Test took 143443ms.
[21:05:29.762] <TB0> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 168 seconds
[21:05:29.762] <TB0> INFO: number of dead bumps (per ROC): 1 2 3 4 5 0 3 1 0 0 1 2 2 0 0 0
[21:05:29.762] <TB0> INFO: separation cut (per ROC): 114 108 91 118 107 106 100 104 108 108 107 108 111 104 112 114
[21:05:29.762] <TB0> INFO: Decoding statistics:
[21:05:29.762] <TB0> INFO: General information:
[21:05:29.762] <TB0> INFO: 16bit words read: 0
[21:05:29.762] <TB0> INFO: valid events total: 0
[21:05:29.762] <TB0> INFO: empty events: 0
[21:05:29.762] <TB0> INFO: valid events with pixels: 0
[21:05:29.762] <TB0> INFO: valid pixel hits: 0
[21:05:29.762] <TB0> INFO: Event errors: 0
[21:05:29.762] <TB0> INFO: start marker: 0
[21:05:29.762] <TB0> INFO: stop marker: 0
[21:05:29.762] <TB0> INFO: overflow: 0
[21:05:29.762] <TB0> INFO: invalid 5bit words: 0
[21:05:29.762] <TB0> INFO: invalid XOR eye diagram: 0
[21:05:29.762] <TB0> INFO: frame (failed synchr.): 0
[21:05:29.762] <TB0> INFO: idle data (no TBM trl): 0
[21:05:29.762] <TB0> INFO: no data (only TBM hdr): 0
[21:05:29.762] <TB0> INFO: TBM errors: 0
[21:05:29.762] <TB0> INFO: flawed TBM headers: 0
[21:05:29.762] <TB0> INFO: flawed TBM trailers: 0
[21:05:29.762] <TB0> INFO: event ID mismatches: 0
[21:05:29.762] <TB0> INFO: ROC errors: 0
[21:05:29.762] <TB0> INFO: missing ROC header(s): 0
[21:05:29.762] <TB0> INFO: misplaced readback start: 0
[21:05:29.762] <TB0> INFO: Pixel decoding errors: 0
[21:05:29.762] <TB0> INFO: pixel data incomplete: 0
[21:05:29.762] <TB0> INFO: pixel address: 0
[21:05:29.762] <TB0> INFO: pulse height fill bit: 0
[21:05:29.762] <TB0> INFO: buffer corruption: 0
[21:05:29.800] <TB0> INFO: ######################################################################
[21:05:29.800] <TB0> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[21:05:29.800] <TB0> INFO: ######################################################################
[21:05:29.801] <TB0> INFO: ----------------------------------------------------------------------
[21:05:29.801] <TB0> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[21:05:29.801] <TB0> INFO: ----------------------------------------------------------------------
[21:05:29.801] <TB0> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[21:05:29.815] <TB0> INFO: dacScan split into 1 runs with ntrig = 50
[21:05:29.815] <TB0> INFO: run 1 of 1
[21:05:30.057] <TB0> INFO: Expecting 36608000 events.
[21:05:53.564] <TB0> INFO: 702200 events read in total (22915ms).
[21:06:16.797] <TB0> INFO: 1385550 events read in total (46148ms).
[21:06:39.673] <TB0> INFO: 2070650 events read in total (69024ms).
[21:07:02.974] <TB0> INFO: 2755550 events read in total (92325ms).
[21:07:26.080] <TB0> INFO: 3439950 events read in total (115431ms).
[21:07:48.948] <TB0> INFO: 4123950 events read in total (138299ms).
[21:08:11.720] <TB0> INFO: 4805650 events read in total (161071ms).
[21:08:34.665] <TB0> INFO: 5488300 events read in total (184016ms).
[21:08:57.684] <TB0> INFO: 6168050 events read in total (207036ms).
[21:09:20.864] <TB0> INFO: 6847150 events read in total (230215ms).
[21:09:43.971] <TB0> INFO: 7527650 events read in total (253322ms).
[21:10:06.942] <TB0> INFO: 8207700 events read in total (276293ms).
[21:10:29.851] <TB0> INFO: 8887250 events read in total (299202ms).
[21:10:52.658] <TB0> INFO: 9567200 events read in total (322009ms).
[21:11:15.303] <TB0> INFO: 10247300 events read in total (344654ms).
[21:11:38.232] <TB0> INFO: 10922950 events read in total (367583ms).
[21:12:01.182] <TB0> INFO: 11600200 events read in total (390533ms).
[21:12:23.910] <TB0> INFO: 12279250 events read in total (413261ms).
[21:12:46.718] <TB0> INFO: 12955600 events read in total (436069ms).
[21:13:09.586] <TB0> INFO: 13632600 events read in total (458937ms).
[21:13:32.228] <TB0> INFO: 14307950 events read in total (481579ms).
[21:13:55.127] <TB0> INFO: 14982800 events read in total (504478ms).
[21:14:18.016] <TB0> INFO: 15654300 events read in total (527367ms).
[21:14:40.896] <TB0> INFO: 16329050 events read in total (550247ms).
[21:15:03.663] <TB0> INFO: 17001500 events read in total (573014ms).
[21:15:26.444] <TB0> INFO: 17675900 events read in total (595795ms).
[21:15:49.191] <TB0> INFO: 18347600 events read in total (618542ms).
[21:16:11.886] <TB0> INFO: 19020150 events read in total (641237ms).
[21:16:34.957] <TB0> INFO: 19691500 events read in total (664308ms).
[21:16:57.619] <TB0> INFO: 20361550 events read in total (686970ms).
[21:17:20.318] <TB0> INFO: 21029800 events read in total (709669ms).
[21:17:43.070] <TB0> INFO: 21699100 events read in total (732421ms).
[21:18:05.836] <TB0> INFO: 22367200 events read in total (755187ms).
[21:18:28.322] <TB0> INFO: 23036000 events read in total (777673ms).
[21:18:50.907] <TB0> INFO: 23705200 events read in total (800258ms).
[21:19:13.596] <TB0> INFO: 24374350 events read in total (822947ms).
[21:19:36.678] <TB0> INFO: 25045600 events read in total (846029ms).
[21:19:59.471] <TB0> INFO: 25716550 events read in total (868822ms).
[21:20:22.040] <TB0> INFO: 26385750 events read in total (891391ms).
[21:20:44.833] <TB0> INFO: 27056650 events read in total (914184ms).
[21:21:07.543] <TB0> INFO: 27725950 events read in total (936894ms).
[21:21:30.184] <TB0> INFO: 28395250 events read in total (959535ms).
[21:21:52.632] <TB0> INFO: 29063950 events read in total (981983ms).
[21:22:15.355] <TB0> INFO: 29731700 events read in total (1004706ms).
[21:22:38.030] <TB0> INFO: 30401100 events read in total (1027381ms).
[21:23:00.476] <TB0> INFO: 31068100 events read in total (1049827ms).
[21:23:23.015] <TB0> INFO: 31736400 events read in total (1072366ms).
[21:23:45.770] <TB0> INFO: 32401350 events read in total (1095121ms).
[21:24:08.285] <TB0> INFO: 33070300 events read in total (1117636ms).
[21:24:30.989] <TB0> INFO: 33738700 events read in total (1140340ms).
[21:24:53.599] <TB0> INFO: 34407700 events read in total (1162950ms).
[21:25:16.273] <TB0> INFO: 35075100 events read in total (1185624ms).
[21:25:39.275] <TB0> INFO: 35744550 events read in total (1208626ms).
[21:26:01.874] <TB0> INFO: 36422200 events read in total (1231225ms).
[21:26:08.198] <TB0> INFO: 36608000 events read in total (1237549ms).
[21:26:08.259] <TB0> INFO: Test took 1238444ms.
[21:26:08.647] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:10.163] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:11.640] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:13.159] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:14.684] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:16.213] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:17.734] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:19.722] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:21.978] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:23.652] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:25.125] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:26.671] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:28.574] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:30.160] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:31.696] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:33.265] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[21:26:35.579] <TB0> INFO: PixTestScurves::scurves() done
[21:26:35.579] <TB0> INFO: Vcal mean: 134.00 130.34 115.56 119.12 131.98 123.17 121.18 119.42 125.97 129.12 132.44 125.76 131.08 123.36 132.14 139.95
[21:26:35.579] <TB0> INFO: Vcal RMS: 5.87 6.32 6.84 7.37 6.68 6.51 6.12 6.03 6.59 6.21 6.15 6.51 6.93 5.50 6.35 5.31
[21:26:35.579] <TB0> INFO: PixTestScurves::fullTest() done, duration: 1265 seconds
[21:26:35.579] <TB0> INFO: Decoding statistics:
[21:26:35.579] <TB0> INFO: General information:
[21:26:35.579] <TB0> INFO: 16bit words read: 0
[21:26:35.580] <TB0> INFO: valid events total: 0
[21:26:35.580] <TB0> INFO: empty events: 0
[21:26:35.580] <TB0> INFO: valid events with pixels: 0
[21:26:35.580] <TB0> INFO: valid pixel hits: 0
[21:26:35.580] <TB0> INFO: Event errors: 0
[21:26:35.580] <TB0> INFO: start marker: 0
[21:26:35.580] <TB0> INFO: stop marker: 0
[21:26:35.580] <TB0> INFO: overflow: 0
[21:26:35.580] <TB0> INFO: invalid 5bit words: 0
[21:26:35.580] <TB0> INFO: invalid XOR eye diagram: 0
[21:26:35.580] <TB0> INFO: frame (failed synchr.): 0
[21:26:35.580] <TB0> INFO: idle data (no TBM trl): 0
[21:26:35.580] <TB0> INFO: no data (only TBM hdr): 0
[21:26:35.580] <TB0> INFO: TBM errors: 0
[21:26:35.580] <TB0> INFO: flawed TBM headers: 0
[21:26:35.580] <TB0> INFO: flawed TBM trailers: 0
[21:26:35.580] <TB0> INFO: event ID mismatches: 0
[21:26:35.580] <TB0> INFO: ROC errors: 0
[21:26:35.580] <TB0> INFO: missing ROC header(s): 0
[21:26:35.580] <TB0> INFO: misplaced readback start: 0
[21:26:35.580] <TB0> INFO: Pixel decoding errors: 0
[21:26:35.580] <TB0> INFO: pixel data incomplete: 0
[21:26:35.580] <TB0> INFO: pixel address: 0
[21:26:35.580] <TB0> INFO: pulse height fill bit: 0
[21:26:35.580] <TB0> INFO: buffer corruption: 0
[21:26:35.673] <TB0> INFO: ######################################################################
[21:26:35.673] <TB0> INFO: PixTestTrim::doTest()
[21:26:35.673] <TB0> INFO: ######################################################################
[21:26:35.674] <TB0> INFO: ----------------------------------------------------------------------
[21:26:35.674] <TB0> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[21:26:35.674] <TB0> INFO: ----------------------------------------------------------------------
[21:26:35.743] <TB0> INFO: ---> VthrComp thr map (minimal VthrComp)
[21:26:35.743] <TB0> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[21:26:35.757] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[21:26:35.757] <TB0> INFO: run 1 of 1
[21:26:36.082] <TB0> INFO: Expecting 5025280 events.
[21:27:07.549] <TB0> INFO: 835288 events read in total (30869ms).
[21:27:37.931] <TB0> INFO: 1667688 events read in total (61251ms).
[21:28:08.212] <TB0> INFO: 2496408 events read in total (91532ms).
[21:28:38.885] <TB0> INFO: 3323096 events read in total (122205ms).
[21:29:09.431] <TB0> INFO: 4146336 events read in total (152751ms).
[21:29:39.527] <TB0> INFO: 4969016 events read in total (182847ms).
[21:29:41.887] <TB0> INFO: 5025280 events read in total (185207ms).
[21:29:41.939] <TB0> INFO: Test took 186182ms.
[21:29:57.176] <TB0> INFO: ROC 0 VthrComp = 132
[21:29:57.176] <TB0> INFO: ROC 1 VthrComp = 129
[21:29:57.177] <TB0> INFO: ROC 2 VthrComp = 108
[21:29:57.177] <TB0> INFO: ROC 3 VthrComp = 114
[21:29:57.177] <TB0> INFO: ROC 4 VthrComp = 130
[21:29:57.177] <TB0> INFO: ROC 5 VthrComp = 119
[21:29:57.177] <TB0> INFO: ROC 6 VthrComp = 116
[21:29:57.177] <TB0> INFO: ROC 7 VthrComp = 121
[21:29:57.178] <TB0> INFO: ROC 8 VthrComp = 130
[21:29:57.178] <TB0> INFO: ROC 9 VthrComp = 130
[21:29:57.187] <TB0> INFO: ROC 10 VthrComp = 131
[21:29:57.187] <TB0> INFO: ROC 11 VthrComp = 121
[21:29:57.187] <TB0> INFO: ROC 12 VthrComp = 133
[21:29:57.187] <TB0> INFO: ROC 13 VthrComp = 120
[21:29:57.187] <TB0> INFO: ROC 14 VthrComp = 131
[21:29:57.187] <TB0> INFO: ROC 15 VthrComp = 132
[21:29:57.425] <TB0> INFO: Expecting 41600 events.
[21:30:00.942] <TB0> INFO: 41600 events read in total (2925ms).
[21:30:00.943] <TB0> INFO: Test took 3754ms.
[21:30:00.952] <TB0> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[21:30:00.952] <TB0> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[21:30:00.963] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[21:30:00.963] <TB0> INFO: run 1 of 1
[21:30:01.241] <TB0> INFO: Expecting 5025280 events.
[21:30:27.883] <TB0> INFO: 594008 events read in total (26051ms).
[21:30:53.580] <TB0> INFO: 1187240 events read in total (51748ms).
[21:31:19.318] <TB0> INFO: 1779888 events read in total (77486ms).
[21:31:44.716] <TB0> INFO: 2370992 events read in total (102884ms).
[21:32:10.299] <TB0> INFO: 2960160 events read in total (128467ms).
[21:32:35.713] <TB0> INFO: 3547440 events read in total (153881ms).
[21:33:01.315] <TB0> INFO: 4133688 events read in total (179483ms).
[21:33:27.131] <TB0> INFO: 4719000 events read in total (205299ms).
[21:33:40.978] <TB0> INFO: 5025280 events read in total (219146ms).
[21:33:41.063] <TB0> INFO: Test took 220100ms.
[21:34:08.751] <TB0> INFO: roc 0 with ID = 0 has maximal Vcal 67.5057 for pixel 4/17 mean/min/max = 51.002/34.1853/67.8186
[21:34:08.751] <TB0> INFO: roc 1 with ID = 1 has maximal Vcal 63.6544 for pixel 6/78 mean/min/max = 48.2159/32.6863/63.7456
[21:34:08.752] <TB0> INFO: roc 2 with ID = 2 has maximal Vcal 68.0424 for pixel 3/1 mean/min/max = 50.8163/33.1127/68.5199
[21:34:08.752] <TB0> INFO: roc 3 with ID = 3 has maximal Vcal 64.5232 for pixel 23/18 mean/min/max = 48.17/31.2864/65.0536
[21:34:08.753] <TB0> INFO: roc 4 with ID = 4 has maximal Vcal 66.1069 for pixel 43/18 mean/min/max = 48.8525/31.489/66.2161
[21:34:08.753] <TB0> INFO: roc 5 with ID = 5 has maximal Vcal 63.381 for pixel 0/10 mean/min/max = 47.0376/30.6796/63.3957
[21:34:08.754] <TB0> INFO: roc 6 with ID = 6 has maximal Vcal 61.6264 for pixel 2/9 mean/min/max = 47.2162/32.6227/61.8097
[21:34:08.754] <TB0> INFO: roc 7 with ID = 7 has maximal Vcal 61.6406 for pixel 1/60 mean/min/max = 46.9004/31.9611/61.8396
[21:34:08.755] <TB0> INFO: roc 8 with ID = 8 has maximal Vcal 61.6295 for pixel 8/9 mean/min/max = 46.9913/32.1977/61.7849
[21:34:08.755] <TB0> INFO: roc 9 with ID = 9 has maximal Vcal 60.2046 for pixel 2/0 mean/min/max = 46.0865/31.8954/60.2776
[21:34:08.756] <TB0> INFO: roc 10 with ID = 10 has maximal Vcal 64.3462 for pixel 29/23 mean/min/max = 48.3063/32.0978/64.5149
[21:34:08.756] <TB0> INFO: roc 11 with ID = 11 has maximal Vcal 62.2551 for pixel 36/16 mean/min/max = 47.7162/32.8753/62.5571
[21:34:08.756] <TB0> INFO: roc 12 with ID = 12 has maximal Vcal 63.7725 for pixel 0/0 mean/min/max = 49.0731/34.1801/63.966
[21:34:08.757] <TB0> INFO: roc 13 with ID = 13 has maximal Vcal 60.443 for pixel 6/63 mean/min/max = 47.0927/33.6736/60.5117
[21:34:08.757] <TB0> INFO: roc 14 with ID = 14 has maximal Vcal 66.3369 for pixel 2/14 mean/min/max = 49.6407/32.8611/66.4203
[21:34:08.758] <TB0> INFO: roc 15 with ID = 15 has maximal Vcal 68.3505 for pixel 50/16 mean/min/max = 53.243/37.6407/68.8453
[21:34:08.758] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:34:08.847] <TB0> INFO: Expecting 411648 events.
[21:34:18.193] <TB0> INFO: 411648 events read in total (8755ms).
[21:34:18.203] <TB0> INFO: Expecting 411648 events.
[21:34:27.369] <TB0> INFO: 411648 events read in total (8763ms).
[21:34:27.381] <TB0> INFO: Expecting 411648 events.
[21:34:36.550] <TB0> INFO: 411648 events read in total (8766ms).
[21:34:36.563] <TB0> INFO: Expecting 411648 events.
[21:34:45.985] <TB0> INFO: 411648 events read in total (9019ms).
[21:34:45.001] <TB0> INFO: Expecting 411648 events.
[21:34:55.413] <TB0> INFO: 411648 events read in total (9009ms).
[21:34:55.431] <TB0> INFO: Expecting 411648 events.
[21:35:04.781] <TB0> INFO: 411648 events read in total (8946ms).
[21:35:04.803] <TB0> INFO: Expecting 411648 events.
[21:35:14.143] <TB0> INFO: 411648 events read in total (8937ms).
[21:35:14.167] <TB0> INFO: Expecting 411648 events.
[21:35:23.509] <TB0> INFO: 411648 events read in total (8939ms).
[21:35:23.537] <TB0> INFO: Expecting 411648 events.
[21:35:32.957] <TB0> INFO: 411648 events read in total (9017ms).
[21:35:32.987] <TB0> INFO: Expecting 411648 events.
[21:35:42.341] <TB0> INFO: 411648 events read in total (8951ms).
[21:35:42.379] <TB0> INFO: Expecting 411648 events.
[21:35:51.731] <TB0> INFO: 411648 events read in total (8948ms).
[21:35:51.767] <TB0> INFO: Expecting 411648 events.
[21:36:01.021] <TB0> INFO: 411648 events read in total (8851ms).
[21:36:01.062] <TB0> INFO: Expecting 411648 events.
[21:36:10.445] <TB0> INFO: 411648 events read in total (8980ms).
[21:36:10.486] <TB0> INFO: Expecting 411648 events.
[21:36:19.904] <TB0> INFO: 411648 events read in total (9015ms).
[21:36:19.962] <TB0> INFO: Expecting 411648 events.
[21:36:29.444] <TB0> INFO: 411648 events read in total (9079ms).
[21:36:29.492] <TB0> INFO: Expecting 411648 events.
[21:36:39.072] <TB0> INFO: 411648 events read in total (9177ms).
[21:36:39.124] <TB0> INFO: Test took 150366ms.
[21:36:39.802] <TB0> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[21:36:39.815] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[21:36:39.815] <TB0> INFO: run 1 of 1
[21:36:40.061] <TB0> INFO: Expecting 5025280 events.
[21:37:06.247] <TB0> INFO: 591760 events read in total (25594ms).
[21:37:32.043] <TB0> INFO: 1181232 events read in total (51390ms).
[21:37:58.327] <TB0> INFO: 1770744 events read in total (77674ms).
[21:38:24.584] <TB0> INFO: 2359488 events read in total (103931ms).
[21:38:50.553] <TB0> INFO: 2949488 events read in total (129900ms).
[21:39:16.593] <TB0> INFO: 3539992 events read in total (155940ms).
[21:39:42.506] <TB0> INFO: 4131456 events read in total (181853ms).
[21:40:08.450] <TB0> INFO: 4719416 events read in total (207797ms).
[21:40:22.322] <TB0> INFO: 5025280 events read in total (221669ms).
[21:40:22.456] <TB0> INFO: Test took 222642ms.
[21:40:46.716] <TB0> INFO: ---> TrimStepCorr4 extremal thresholds: 3.623008 .. 147.619692
[21:40:46.956] <TB0> INFO: Expecting 208000 events.
[21:40:56.410] <TB0> INFO: 208000 events read in total (8862ms).
[21:40:56.412] <TB0> INFO: Test took 9695ms.
[21:40:56.461] <TB0> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 3 .. 157 (-1/-1) hits flags = 528 (plus default)
[21:40:56.474] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[21:40:56.474] <TB0> INFO: run 1 of 1
[21:40:56.752] <TB0> INFO: Expecting 5158400 events.
[21:41:22.523] <TB0> INFO: 582032 events read in total (25179ms).
[21:41:47.986] <TB0> INFO: 1163512 events read in total (50643ms).
[21:42:13.718] <TB0> INFO: 1744944 events read in total (76375ms).
[21:42:39.343] <TB0> INFO: 2326624 events read in total (101999ms).
[21:43:05.131] <TB0> INFO: 2908584 events read in total (127787ms).
[21:43:30.458] <TB0> INFO: 3489696 events read in total (153114ms).
[21:43:56.164] <TB0> INFO: 4070648 events read in total (178820ms).
[21:44:22.234] <TB0> INFO: 4650800 events read in total (204890ms).
[21:44:44.355] <TB0> INFO: 5158400 events read in total (227011ms).
[21:44:44.450] <TB0> INFO: Test took 227976ms.
[21:45:11.887] <TB0> INFO: ---> TrimStepCorr2 extremal thresholds: 26.663614 .. 51.972323
[21:45:12.162] <TB0> INFO: Expecting 208000 events.
[21:45:21.892] <TB0> INFO: 208000 events read in total (9138ms).
[21:45:21.893] <TB0> INFO: Test took 10005ms.
[21:45:21.941] <TB0> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 61 (-1/-1) hits flags = 528 (plus default)
[21:45:21.955] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[21:45:21.955] <TB0> INFO: run 1 of 1
[21:45:22.233] <TB0> INFO: Expecting 1530880 events.
[21:45:50.794] <TB0> INFO: 645376 events read in total (27969ms).
[21:46:17.879] <TB0> INFO: 1288928 events read in total (55055ms).
[21:46:28.239] <TB0> INFO: 1530880 events read in total (65414ms).
[21:46:28.273] <TB0> INFO: Test took 66319ms.
[21:46:43.008] <TB0> INFO: ---> TrimStepCorr1a extremal thresholds: 29.603805 .. 56.073271
[21:46:43.249] <TB0> INFO: Expecting 208000 events.
[21:46:52.803] <TB0> INFO: 208000 events read in total (8962ms).
[21:46:52.804] <TB0> INFO: Test took 9794ms.
[21:46:52.853] <TB0> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 19 .. 66 (-1/-1) hits flags = 528 (plus default)
[21:46:52.866] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[21:46:52.866] <TB0> INFO: run 1 of 1
[21:46:53.145] <TB0> INFO: Expecting 1597440 events.
[21:47:20.436] <TB0> INFO: 620248 events read in total (26700ms).
[21:47:47.090] <TB0> INFO: 1239544 events read in total (53354ms).
[21:48:02.371] <TB0> INFO: 1597440 events read in total (68635ms).
[21:48:02.405] <TB0> INFO: Test took 69540ms.
[21:48:17.460] <TB0> INFO: ---> TrimStepCorr1b extremal thresholds: 26.999181 .. 61.902498
[21:48:17.735] <TB0> INFO: Expecting 208000 events.
[21:48:28.239] <TB0> INFO: 208000 events read in total (9913ms).
[21:48:28.240] <TB0> INFO: Test took 10779ms.
[21:48:28.306] <TB0> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 16 .. 71 (-1/-1) hits flags = 528 (plus default)
[21:48:28.321] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[21:48:28.321] <TB0> INFO: run 1 of 1
[21:48:28.599] <TB0> INFO: Expecting 1863680 events.
[21:48:55.675] <TB0> INFO: 619896 events read in total (26484ms).
[21:49:22.243] <TB0> INFO: 1239624 events read in total (53052ms).
[21:49:48.768] <TB0> INFO: 1859152 events read in total (79577ms).
[21:49:49.395] <TB0> INFO: 1863680 events read in total (80205ms).
[21:49:49.429] <TB0> INFO: Test took 81108ms.
[21:50:06.413] <TB0> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[21:50:06.413] <TB0> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[21:50:06.426] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[21:50:06.426] <TB0> INFO: run 1 of 1
[21:50:06.665] <TB0> INFO: Expecting 1364480 events.
[21:50:35.137] <TB0> INFO: 669080 events read in total (27881ms).
[21:51:03.348] <TB0> INFO: 1337520 events read in total (56092ms).
[21:51:04.932] <TB0> INFO: 1364480 events read in total (57677ms).
[21:51:04.969] <TB0> INFO: Test took 58543ms.
[21:51:20.195] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C0.dat
[21:51:20.195] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C1.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C2.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C3.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C4.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C5.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C6.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C7.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C8.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C9.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C10.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C11.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C12.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C13.dat
[21:51:20.196] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C14.dat
[21:51:20.197] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C15.dat
[21:51:20.197] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C0.dat
[21:51:20.203] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C1.dat
[21:51:20.210] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C2.dat
[21:51:20.216] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C3.dat
[21:51:20.222] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C4.dat
[21:51:20.229] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C5.dat
[21:51:20.235] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C6.dat
[21:51:20.241] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C7.dat
[21:51:20.246] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C8.dat
[21:51:20.251] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C9.dat
[21:51:20.256] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C10.dat
[21:51:20.260] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C11.dat
[21:51:20.265] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C12.dat
[21:51:20.270] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C13.dat
[21:51:20.274] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C14.dat
[21:51:20.279] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//trimParameters35_C15.dat
[21:51:20.284] <TB0> INFO: PixTestTrim::trimTest() done
[21:51:20.284] <TB0> INFO: vtrim: 173 146 120 138 148 120 118 141 160 136 155 134 130 141 159 182
[21:51:20.284] <TB0> INFO: vthrcomp: 132 129 108 114 130 119 116 121 130 130 131 121 133 120 131 132
[21:51:20.284] <TB0> INFO: vcal mean: 35.99 35.24 35.30 35.17 36.42 35.09 35.53 35.05 35.05 35.07 35.84 35.57 35.32 35.12 35.39 35.94
[21:51:20.284] <TB0> INFO: vcal RMS: 2.27 1.29 1.33 1.23 2.95 1.14 1.60 1.08 1.08 1.12 1.97 1.75 1.40 1.06 1.44 2.21
[21:51:20.284] <TB0> INFO: bits mean: 9.28 9.76 8.26 9.65 10.11 9.10 9.55 9.14 9.73 9.27 10.01 9.51 8.15 9.28 9.29 8.65
[21:51:20.284] <TB0> INFO: bits RMS: 2.44 2.40 2.84 2.54 2.46 2.99 2.66 2.76 2.55 2.85 2.49 2.65 2.77 2.53 2.58 2.27
[21:51:20.292] <TB0> INFO: ----------------------------------------------------------------------
[21:51:20.293] <TB0> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[21:51:20.293] <TB0> INFO: ----------------------------------------------------------------------
[21:51:20.296] <TB0> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[21:51:20.309] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[21:51:20.309] <TB0> INFO: run 1 of 1
[21:51:20.596] <TB0> INFO: Expecting 4160000 events.
[21:51:53.573] <TB0> INFO: 778665 events read in total (32385ms).
[21:52:25.691] <TB0> INFO: 1548490 events read in total (64503ms).
[21:52:57.714] <TB0> INFO: 2310100 events read in total (96526ms).
[21:53:29.778] <TB0> INFO: 3067075 events read in total (128590ms).
[21:54:01.803] <TB0> INFO: 3822010 events read in total (160615ms).
[21:54:16.324] <TB0> INFO: 4160000 events read in total (175136ms).
[21:54:16.406] <TB0> INFO: Test took 176098ms.
[21:54:41.918] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 251 (-1/-1) hits flags = 528 (plus default)
[21:54:41.933] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[21:54:41.933] <TB0> INFO: run 1 of 1
[21:54:42.174] <TB0> INFO: Expecting 5241600 events.
[21:55:13.429] <TB0> INFO: 692790 events read in total (30663ms).
[21:55:44.127] <TB0> INFO: 1380610 events read in total (61361ms).
[21:56:14.835] <TB0> INFO: 2066270 events read in total (92069ms).
[21:56:44.850] <TB0> INFO: 2748800 events read in total (122084ms).
[21:57:15.200] <TB0> INFO: 3427395 events read in total (152434ms).
[21:57:45.904] <TB0> INFO: 4107135 events read in total (183138ms).
[21:58:16.475] <TB0> INFO: 4785350 events read in total (213709ms).
[21:58:37.162] <TB0> INFO: 5241600 events read in total (234396ms).
[21:58:37.304] <TB0> INFO: Test took 235371ms.
[21:59:10.934] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 242 (-1/-1) hits flags = 528 (plus default)
[21:59:10.948] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[21:59:10.948] <TB0> INFO: run 1 of 1
[21:59:11.186] <TB0> INFO: Expecting 5054400 events.
[21:59:42.399] <TB0> INFO: 700875 events read in total (30622ms).
[22:00:13.173] <TB0> INFO: 1396155 events read in total (61396ms).
[22:00:43.625] <TB0> INFO: 2088775 events read in total (91848ms).
[22:01:14.201] <TB0> INFO: 2778235 events read in total (122424ms).
[22:01:44.181] <TB0> INFO: 3464545 events read in total (152404ms).
[22:02:14.560] <TB0> INFO: 4150685 events read in total (182783ms).
[22:02:44.625] <TB0> INFO: 4835925 events read in total (212848ms).
[22:02:54.219] <TB0> INFO: 5054400 events read in total (222442ms).
[22:02:54.401] <TB0> INFO: Test took 223453ms.
[22:03:26.652] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 247 (-1/-1) hits flags = 528 (plus default)
[22:03:26.665] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[22:03:26.666] <TB0> INFO: run 1 of 1
[22:03:26.903] <TB0> INFO: Expecting 5158400 events.
[22:03:58.130] <TB0> INFO: 696385 events read in total (30636ms).
[22:04:28.626] <TB0> INFO: 1387410 events read in total (61132ms).
[22:04:59.290] <TB0> INFO: 2076175 events read in total (91796ms).
[22:05:29.421] <TB0> INFO: 2761710 events read in total (121927ms).
[22:05:59.503] <TB0> INFO: 3443945 events read in total (152009ms).
[22:06:29.714] <TB0> INFO: 4126640 events read in total (182220ms).
[22:07:00.454] <TB0> INFO: 4808215 events read in total (212960ms).
[22:07:16.307] <TB0> INFO: 5158400 events read in total (228813ms).
[22:07:16.528] <TB0> INFO: Test took 229862ms.
[22:07:45.955] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 251 (-1/-1) hits flags = 528 (plus default)
[22:07:45.970] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[22:07:45.970] <TB0> INFO: run 1 of 1
[22:07:46.222] <TB0> INFO: Expecting 5241600 events.
[22:08:18.216] <TB0> INFO: 692855 events read in total (31402ms).
[22:08:48.823] <TB0> INFO: 1380730 events read in total (62009ms).
[22:09:19.161] <TB0> INFO: 2066605 events read in total (92347ms).
[22:09:50.130] <TB0> INFO: 2749250 events read in total (123316ms).
[22:10:20.890] <TB0> INFO: 3428510 events read in total (154076ms).
[22:10:50.813] <TB0> INFO: 4108485 events read in total (183999ms).
[22:11:20.422] <TB0> INFO: 4786800 events read in total (213608ms).
[22:11:41.056] <TB0> INFO: 5241600 events read in total (234242ms).
[22:11:41.239] <TB0> INFO: Test took 235269ms.
[22:12:12.714] <TB0> INFO: PixTestTrim::trimBitTest() done
[22:12:12.715] <TB0> INFO: PixTestTrim::doTest() done, duration: 2737 seconds
[22:12:12.715] <TB0> INFO: Decoding statistics:
[22:12:12.715] <TB0> INFO: General information:
[22:12:12.715] <TB0> INFO: 16bit words read: 0
[22:12:12.715] <TB0> INFO: valid events total: 0
[22:12:12.715] <TB0> INFO: empty events: 0
[22:12:12.715] <TB0> INFO: valid events with pixels: 0
[22:12:12.715] <TB0> INFO: valid pixel hits: 0
[22:12:12.715] <TB0> INFO: Event errors: 0
[22:12:12.715] <TB0> INFO: start marker: 0
[22:12:12.715] <TB0> INFO: stop marker: 0
[22:12:12.715] <TB0> INFO: overflow: 0
[22:12:12.715] <TB0> INFO: invalid 5bit words: 0
[22:12:12.715] <TB0> INFO: invalid XOR eye diagram: 0
[22:12:12.715] <TB0> INFO: frame (failed synchr.): 0
[22:12:12.715] <TB0> INFO: idle data (no TBM trl): 0
[22:12:12.715] <TB0> INFO: no data (only TBM hdr): 0
[22:12:12.715] <TB0> INFO: TBM errors: 0
[22:12:12.715] <TB0> INFO: flawed TBM headers: 0
[22:12:12.715] <TB0> INFO: flawed TBM trailers: 0
[22:12:12.715] <TB0> INFO: event ID mismatches: 0
[22:12:12.715] <TB0> INFO: ROC errors: 0
[22:12:12.715] <TB0> INFO: missing ROC header(s): 0
[22:12:12.715] <TB0> INFO: misplaced readback start: 0
[22:12:12.715] <TB0> INFO: Pixel decoding errors: 0
[22:12:12.715] <TB0> INFO: pixel data incomplete: 0
[22:12:12.715] <TB0> INFO: pixel address: 0
[22:12:12.715] <TB0> INFO: pulse height fill bit: 0
[22:12:12.715] <TB0> INFO: buffer corruption: 0
[22:12:13.321] <TB0> INFO: ######################################################################
[22:12:13.321] <TB0> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[22:12:13.321] <TB0> INFO: ######################################################################
[22:12:13.565] <TB0> INFO: Expecting 41600 events.
[22:12:17.047] <TB0> INFO: 41600 events read in total (2891ms).
[22:12:17.047] <TB0> INFO: Test took 3725ms.
[22:12:17.487] <TB0> INFO: Expecting 41600 events.
[22:12:21.103] <TB0> INFO: 41600 events read in total (3024ms).
[22:12:21.104] <TB0> INFO: Test took 3855ms.
[22:12:21.415] <TB0> INFO: Expecting 41600 events.
[22:12:24.939] <TB0> INFO: 41600 events read in total (2932ms).
[22:12:24.940] <TB0> INFO: Test took 3809ms.
[22:12:25.229] <TB0> INFO: Expecting 41600 events.
[22:12:28.752] <TB0> INFO: 41600 events read in total (2931ms).
[22:12:28.753] <TB0> INFO: Test took 3789ms.
[22:12:29.042] <TB0> INFO: Expecting 41600 events.
[22:12:32.521] <TB0> INFO: 41600 events read in total (2888ms).
[22:12:32.522] <TB0> INFO: Test took 3745ms.
[22:12:32.810] <TB0> INFO: Expecting 41600 events.
[22:12:36.298] <TB0> INFO: 41600 events read in total (2896ms).
[22:12:36.299] <TB0> INFO: Test took 3753ms.
[22:12:36.587] <TB0> INFO: Expecting 41600 events.
[22:12:40.146] <TB0> INFO: 41600 events read in total (2967ms).
[22:12:40.147] <TB0> INFO: Test took 3825ms.
[22:12:40.437] <TB0> INFO: Expecting 41600 events.
[22:12:43.958] <TB0> INFO: 41600 events read in total (2930ms).
[22:12:43.958] <TB0> INFO: Test took 3786ms.
[22:12:44.249] <TB0> INFO: Expecting 41600 events.
[22:12:47.811] <TB0> INFO: 41600 events read in total (2970ms).
[22:12:47.812] <TB0> INFO: Test took 3828ms.
[22:12:48.101] <TB0> INFO: Expecting 41600 events.
[22:12:51.637] <TB0> INFO: 41600 events read in total (2944ms).
[22:12:51.638] <TB0> INFO: Test took 3802ms.
[22:12:51.927] <TB0> INFO: Expecting 41600 events.
[22:12:55.458] <TB0> INFO: 41600 events read in total (2940ms).
[22:12:55.460] <TB0> INFO: Test took 3798ms.
[22:12:55.752] <TB0> INFO: Expecting 41600 events.
[22:12:59.299] <TB0> INFO: 41600 events read in total (2955ms).
[22:12:59.300] <TB0> INFO: Test took 3813ms.
[22:12:59.590] <TB0> INFO: Expecting 41600 events.
[22:13:03.066] <TB0> INFO: 41600 events read in total (2884ms).
[22:13:03.067] <TB0> INFO: Test took 3743ms.
[22:13:03.365] <TB0> INFO: Expecting 41600 events.
[22:13:06.886] <TB0> INFO: 41600 events read in total (2922ms).
[22:13:06.887] <TB0> INFO: Test took 3796ms.
[22:13:07.208] <TB0> INFO: Expecting 41600 events.
[22:13:10.761] <TB0> INFO: 41600 events read in total (2961ms).
[22:13:10.762] <TB0> INFO: Test took 3851ms.
[22:13:11.052] <TB0> INFO: Expecting 41600 events.
[22:13:14.766] <TB0> INFO: 41600 events read in total (3122ms).
[22:13:14.767] <TB0> INFO: Test took 3981ms.
[22:13:15.056] <TB0> INFO: Expecting 41600 events.
[22:13:18.573] <TB0> INFO: 41600 events read in total (2926ms).
[22:13:18.574] <TB0> INFO: Test took 3783ms.
[22:13:18.866] <TB0> INFO: Expecting 41600 events.
[22:13:22.353] <TB0> INFO: 41600 events read in total (2895ms).
[22:13:22.354] <TB0> INFO: Test took 3753ms.
[22:13:22.644] <TB0> INFO: Expecting 41600 events.
[22:13:26.186] <TB0> INFO: 41600 events read in total (2951ms).
[22:13:26.187] <TB0> INFO: Test took 3809ms.
[22:13:26.477] <TB0> INFO: Expecting 41600 events.
[22:13:29.998] <TB0> INFO: 41600 events read in total (2929ms).
[22:13:29.999] <TB0> INFO: Test took 3788ms.
[22:13:30.288] <TB0> INFO: Expecting 41600 events.
[22:13:33.840] <TB0> INFO: 41600 events read in total (2960ms).
[22:13:33.841] <TB0> INFO: Test took 3818ms.
[22:13:34.131] <TB0> INFO: Expecting 41600 events.
[22:13:37.676] <TB0> INFO: 41600 events read in total (2954ms).
[22:13:37.677] <TB0> INFO: Test took 3811ms.
[22:13:37.980] <TB0> INFO: Expecting 41600 events.
[22:13:41.474] <TB0> INFO: 41600 events read in total (2902ms).
[22:13:41.475] <TB0> INFO: Test took 3774ms.
[22:13:41.765] <TB0> INFO: Expecting 41600 events.
[22:13:45.429] <TB0> INFO: 41600 events read in total (3072ms).
[22:13:45.430] <TB0> INFO: Test took 3930ms.
[22:13:45.720] <TB0> INFO: Expecting 41600 events.
[22:13:49.199] <TB0> INFO: 41600 events read in total (2887ms).
[22:13:49.200] <TB0> INFO: Test took 3746ms.
[22:13:49.490] <TB0> INFO: Expecting 41600 events.
[22:13:52.969] <TB0> INFO: 41600 events read in total (2888ms).
[22:13:52.970] <TB0> INFO: Test took 3745ms.
[22:13:53.270] <TB0> INFO: Expecting 41600 events.
[22:13:56.831] <TB0> INFO: 41600 events read in total (2970ms).
[22:13:56.832] <TB0> INFO: Test took 3839ms.
[22:13:57.133] <TB0> INFO: Expecting 41600 events.
[22:14:00.691] <TB0> INFO: 41600 events read in total (2967ms).
[22:14:00.692] <TB0> INFO: Test took 3834ms.
[22:14:00.986] <TB0> INFO: Expecting 41600 events.
[22:14:04.472] <TB0> INFO: 41600 events read in total (2895ms).
[22:14:04.472] <TB0> INFO: Test took 3755ms.
[22:14:04.762] <TB0> INFO: Expecting 2560 events.
[22:14:05.657] <TB0> INFO: 2560 events read in total (303ms).
[22:14:05.658] <TB0> INFO: Test took 1173ms.
[22:14:05.965] <TB0> INFO: Expecting 2560 events.
[22:14:06.856] <TB0> INFO: 2560 events read in total (299ms).
[22:14:06.856] <TB0> INFO: Test took 1198ms.
[22:14:07.165] <TB0> INFO: Expecting 2560 events.
[22:14:08.055] <TB0> INFO: 2560 events read in total (299ms).
[22:14:08.055] <TB0> INFO: Test took 1198ms.
[22:14:08.362] <TB0> INFO: Expecting 2560 events.
[22:14:09.255] <TB0> INFO: 2560 events read in total (301ms).
[22:14:09.256] <TB0> INFO: Test took 1201ms.
[22:14:09.563] <TB0> INFO: Expecting 2560 events.
[22:14:10.444] <TB0> INFO: 2560 events read in total (290ms).
[22:14:10.445] <TB0> INFO: Test took 1189ms.
[22:14:10.751] <TB0> INFO: Expecting 2560 events.
[22:14:11.634] <TB0> INFO: 2560 events read in total (291ms).
[22:14:11.634] <TB0> INFO: Test took 1189ms.
[22:14:11.942] <TB0> INFO: Expecting 2560 events.
[22:14:12.832] <TB0> INFO: 2560 events read in total (298ms).
[22:14:12.833] <TB0> INFO: Test took 1198ms.
[22:14:13.141] <TB0> INFO: Expecting 2560 events.
[22:14:14.031] <TB0> INFO: 2560 events read in total (299ms).
[22:14:14.032] <TB0> INFO: Test took 1199ms.
[22:14:14.339] <TB0> INFO: Expecting 2560 events.
[22:14:15.231] <TB0> INFO: 2560 events read in total (300ms).
[22:14:15.231] <TB0> INFO: Test took 1199ms.
[22:14:15.538] <TB0> INFO: Expecting 2560 events.
[22:14:16.428] <TB0> INFO: 2560 events read in total (298ms).
[22:14:16.428] <TB0> INFO: Test took 1196ms.
[22:14:16.737] <TB0> INFO: Expecting 2560 events.
[22:14:17.625] <TB0> INFO: 2560 events read in total (297ms).
[22:14:17.626] <TB0> INFO: Test took 1197ms.
[22:14:17.934] <TB0> INFO: Expecting 2560 events.
[22:14:18.815] <TB0> INFO: 2560 events read in total (289ms).
[22:14:18.816] <TB0> INFO: Test took 1190ms.
[22:14:19.124] <TB0> INFO: Expecting 2560 events.
[22:14:20.009] <TB0> INFO: 2560 events read in total (294ms).
[22:14:20.010] <TB0> INFO: Test took 1192ms.
[22:14:20.317] <TB0> INFO: Expecting 2560 events.
[22:14:21.204] <TB0> INFO: 2560 events read in total (296ms).
[22:14:21.205] <TB0> INFO: Test took 1194ms.
[22:14:21.511] <TB0> INFO: Expecting 2560 events.
[22:14:22.404] <TB0> INFO: 2560 events read in total (301ms).
[22:14:22.404] <TB0> INFO: Test took 1199ms.
[22:14:22.711] <TB0> INFO: Expecting 2560 events.
[22:14:23.598] <TB0> INFO: 2560 events read in total (295ms).
[22:14:23.598] <TB0> INFO: Test took 1194ms.
[22:14:23.603] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:14:23.908] <TB0> INFO: Expecting 655360 events.
[22:14:38.647] <TB0> INFO: 655360 events read in total (14148ms).
[22:14:38.659] <TB0> INFO: Expecting 655360 events.
[22:14:53.371] <TB0> INFO: 655360 events read in total (14309ms).
[22:14:53.387] <TB0> INFO: Expecting 655360 events.
[22:15:08.042] <TB0> INFO: 655360 events read in total (14252ms).
[22:15:08.063] <TB0> INFO: Expecting 655360 events.
[22:15:22.620] <TB0> INFO: 655360 events read in total (14154ms).
[22:15:22.647] <TB0> INFO: Expecting 655360 events.
[22:15:37.393] <TB0> INFO: 655360 events read in total (14343ms).
[22:15:37.432] <TB0> INFO: Expecting 655360 events.
[22:15:52.105] <TB0> INFO: 655360 events read in total (14270ms).
[22:15:52.142] <TB0> INFO: Expecting 655360 events.
[22:16:06.924] <TB0> INFO: 655360 events read in total (14379ms).
[22:16:06.994] <TB0> INFO: Expecting 655360 events.
[22:16:21.486] <TB0> INFO: 655360 events read in total (14090ms).
[22:16:21.530] <TB0> INFO: Expecting 655360 events.
[22:16:36.102] <TB0> INFO: 655360 events read in total (14169ms).
[22:16:36.218] <TB0> INFO: Expecting 655360 events.
[22:16:50.564] <TB0> INFO: 655360 events read in total (13943ms).
[22:16:50.617] <TB0> INFO: Expecting 655360 events.
[22:17:05.048] <TB0> INFO: 655360 events read in total (14028ms).
[22:17:05.140] <TB0> INFO: Expecting 655360 events.
[22:17:19.587] <TB0> INFO: 655360 events read in total (14044ms).
[22:17:19.661] <TB0> INFO: Expecting 655360 events.
[22:17:34.255] <TB0> INFO: 655360 events read in total (14191ms).
[22:17:34.353] <TB0> INFO: Expecting 655360 events.
[22:17:48.850] <TB0> INFO: 655360 events read in total (14094ms).
[22:17:49.056] <TB0> INFO: Expecting 655360 events.
[22:18:03.431] <TB0> INFO: 655360 events read in total (13972ms).
[22:18:03.559] <TB0> INFO: Expecting 655360 events.
[22:18:17.908] <TB0> INFO: 655360 events read in total (13946ms).
[22:18:18.096] <TB0> INFO: Test took 234493ms.
[22:18:18.197] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:18:18.452] <TB0> INFO: Expecting 655360 events.
[22:18:33.129] <TB0> INFO: 655360 events read in total (14085ms).
[22:18:33.141] <TB0> INFO: Expecting 655360 events.
[22:18:47.443] <TB0> INFO: 655360 events read in total (13899ms).
[22:18:47.459] <TB0> INFO: Expecting 655360 events.
[22:19:01.737] <TB0> INFO: 655360 events read in total (13875ms).
[22:19:01.758] <TB0> INFO: Expecting 655360 events.
[22:19:16.289] <TB0> INFO: 655360 events read in total (14128ms).
[22:19:16.320] <TB0> INFO: Expecting 655360 events.
[22:19:30.749] <TB0> INFO: 655360 events read in total (14025ms).
[22:19:30.778] <TB0> INFO: Expecting 655360 events.
[22:19:45.472] <TB0> INFO: 655360 events read in total (14291ms).
[22:19:45.510] <TB0> INFO: Expecting 655360 events.
[22:19:59.965] <TB0> INFO: 655360 events read in total (14052ms).
[22:20:00.012] <TB0> INFO: Expecting 655360 events.
[22:20:14.478] <TB0> INFO: 655360 events read in total (14063ms).
[22:20:14.521] <TB0> INFO: Expecting 655360 events.
[22:20:28.958] <TB0> INFO: 655360 events read in total (14034ms).
[22:20:28.006] <TB0> INFO: Expecting 655360 events.
[22:20:43.430] <TB0> INFO: 655360 events read in total (14021ms).
[22:20:43.500] <TB0> INFO: Expecting 655360 events.
[22:20:57.946] <TB0> INFO: 655360 events read in total (14042ms).
[22:20:58.019] <TB0> INFO: Expecting 655360 events.
[22:21:12.441] <TB0> INFO: 655360 events read in total (14019ms).
[22:21:12.536] <TB0> INFO: Expecting 655360 events.
[22:21:27.103] <TB0> INFO: 655360 events read in total (14164ms).
[22:21:27.205] <TB0> INFO: Expecting 655360 events.
[22:21:41.721] <TB0> INFO: 655360 events read in total (14114ms).
[22:21:41.860] <TB0> INFO: Expecting 655360 events.
[22:21:56.769] <TB0> INFO: 655360 events read in total (14506ms).
[22:21:56.925] <TB0> INFO: Expecting 655360 events.
[22:22:11.027] <TB0> INFO: 655360 events read in total (13699ms).
[22:22:11.125] <TB0> INFO: Test took 232928ms.
[22:22:11.340] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.350] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[22:22:11.361] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[22:22:11.372] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[22:22:11.383] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.394] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.405] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.416] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.427] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.438] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.449] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.460] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.471] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.482] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.492] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[22:22:11.503] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.514] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[22:22:11.525] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[22:22:11.537] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[22:22:11.548] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.559] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.570] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[22:22:11.581] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[22:22:11.591] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[22:22:11.603] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[22:22:11.614] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[22:22:11.624] <TB0> INFO: safety margin for low PH: adding 6, margin is now 26
[22:22:11.635] <TB0> INFO: safety margin for low PH: adding 7, margin is now 27
[22:22:11.647] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.658] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[22:22:11.670] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[22:22:11.712] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C0.dat
[22:22:11.712] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C1.dat
[22:22:11.712] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C2.dat
[22:22:11.712] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C3.dat
[22:22:11.712] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C4.dat
[22:22:11.712] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C5.dat
[22:22:11.712] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C6.dat
[22:22:11.712] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C7.dat
[22:22:11.713] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C8.dat
[22:22:11.713] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C9.dat
[22:22:11.713] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C10.dat
[22:22:11.713] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C11.dat
[22:22:11.713] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C12.dat
[22:22:11.713] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C13.dat
[22:22:11.713] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C14.dat
[22:22:11.713] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//dacParameters35_C15.dat
[22:22:12.042] <TB0> INFO: Expecting 41600 events.
[22:22:15.128] <TB0> INFO: 41600 events read in total (2495ms).
[22:22:15.129] <TB0> INFO: Test took 3412ms.
[22:22:15.577] <TB0> INFO: Expecting 41600 events.
[22:22:18.580] <TB0> INFO: 41600 events read in total (2412ms).
[22:22:18.581] <TB0> INFO: Test took 3241ms.
[22:22:19.028] <TB0> INFO: Expecting 41600 events.
[22:22:22.276] <TB0> INFO: 41600 events read in total (2656ms).
[22:22:22.276] <TB0> INFO: Test took 3484ms.
[22:22:22.496] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:22.585] <TB0> INFO: Expecting 2560 events.
[22:22:23.468] <TB0> INFO: 2560 events read in total (291ms).
[22:22:23.468] <TB0> INFO: Test took 972ms.
[22:22:23.470] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:23.776] <TB0> INFO: Expecting 2560 events.
[22:22:24.662] <TB0> INFO: 2560 events read in total (294ms).
[22:22:24.663] <TB0> INFO: Test took 1193ms.
[22:22:24.666] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:24.971] <TB0> INFO: Expecting 2560 events.
[22:22:25.854] <TB0> INFO: 2560 events read in total (292ms).
[22:22:25.854] <TB0> INFO: Test took 1189ms.
[22:22:25.856] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:26.163] <TB0> INFO: Expecting 2560 events.
[22:22:27.048] <TB0> INFO: 2560 events read in total (294ms).
[22:22:27.048] <TB0> INFO: Test took 1192ms.
[22:22:27.050] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:27.356] <TB0> INFO: Expecting 2560 events.
[22:22:28.240] <TB0> INFO: 2560 events read in total (292ms).
[22:22:28.240] <TB0> INFO: Test took 1190ms.
[22:22:28.242] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:28.549] <TB0> INFO: Expecting 2560 events.
[22:22:29.432] <TB0> INFO: 2560 events read in total (292ms).
[22:22:29.433] <TB0> INFO: Test took 1191ms.
[22:22:29.435] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:29.741] <TB0> INFO: Expecting 2560 events.
[22:22:30.627] <TB0> INFO: 2560 events read in total (295ms).
[22:22:30.627] <TB0> INFO: Test took 1192ms.
[22:22:30.629] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:30.936] <TB0> INFO: Expecting 2560 events.
[22:22:31.820] <TB0> INFO: 2560 events read in total (292ms).
[22:22:31.820] <TB0> INFO: Test took 1191ms.
[22:22:31.822] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:32.128] <TB0> INFO: Expecting 2560 events.
[22:22:33.012] <TB0> INFO: 2560 events read in total (292ms).
[22:22:33.013] <TB0> INFO: Test took 1191ms.
[22:22:33.016] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:33.325] <TB0> INFO: Expecting 2560 events.
[22:22:34.208] <TB0> INFO: 2560 events read in total (291ms).
[22:22:34.208] <TB0> INFO: Test took 1192ms.
[22:22:34.210] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:34.517] <TB0> INFO: Expecting 2560 events.
[22:22:35.401] <TB0> INFO: 2560 events read in total (293ms).
[22:22:35.402] <TB0> INFO: Test took 1192ms.
[22:22:35.405] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:35.710] <TB0> INFO: Expecting 2560 events.
[22:22:36.590] <TB0> INFO: 2560 events read in total (288ms).
[22:22:36.591] <TB0> INFO: Test took 1186ms.
[22:22:36.593] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:36.899] <TB0> INFO: Expecting 2560 events.
[22:22:37.784] <TB0> INFO: 2560 events read in total (293ms).
[22:22:37.785] <TB0> INFO: Test took 1192ms.
[22:22:37.787] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:38.093] <TB0> INFO: Expecting 2560 events.
[22:22:38.981] <TB0> INFO: 2560 events read in total (296ms).
[22:22:38.982] <TB0> INFO: Test took 1195ms.
[22:22:38.984] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:39.290] <TB0> INFO: Expecting 2560 events.
[22:22:40.181] <TB0> INFO: 2560 events read in total (299ms).
[22:22:40.182] <TB0> INFO: Test took 1198ms.
[22:22:40.186] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:40.490] <TB0> INFO: Expecting 2560 events.
[22:22:41.377] <TB0> INFO: 2560 events read in total (295ms).
[22:22:41.377] <TB0> INFO: Test took 1191ms.
[22:22:41.379] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:41.685] <TB0> INFO: Expecting 2560 events.
[22:22:42.569] <TB0> INFO: 2560 events read in total (292ms).
[22:22:42.569] <TB0> INFO: Test took 1190ms.
[22:22:42.572] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:42.878] <TB0> INFO: Expecting 2560 events.
[22:22:43.769] <TB0> INFO: 2560 events read in total (300ms).
[22:22:43.770] <TB0> INFO: Test took 1198ms.
[22:22:43.773] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:44.078] <TB0> INFO: Expecting 2560 events.
[22:22:44.962] <TB0> INFO: 2560 events read in total (293ms).
[22:22:44.963] <TB0> INFO: Test took 1190ms.
[22:22:44.965] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:45.271] <TB0> INFO: Expecting 2560 events.
[22:22:46.159] <TB0> INFO: 2560 events read in total (297ms).
[22:22:46.160] <TB0> INFO: Test took 1195ms.
[22:22:46.163] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:46.468] <TB0> INFO: Expecting 2560 events.
[22:22:47.349] <TB0> INFO: 2560 events read in total (289ms).
[22:22:47.349] <TB0> INFO: Test took 1187ms.
[22:22:47.352] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:47.658] <TB0> INFO: Expecting 2560 events.
[22:22:48.546] <TB0> INFO: 2560 events read in total (297ms).
[22:22:48.546] <TB0> INFO: Test took 1194ms.
[22:22:48.549] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:48.854] <TB0> INFO: Expecting 2560 events.
[22:22:49.741] <TB0> INFO: 2560 events read in total (295ms).
[22:22:49.741] <TB0> INFO: Test took 1192ms.
[22:22:49.744] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:50.048] <TB0> INFO: Expecting 2560 events.
[22:22:50.932] <TB0> INFO: 2560 events read in total (292ms).
[22:22:50.932] <TB0> INFO: Test took 1189ms.
[22:22:50.934] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:51.241] <TB0> INFO: Expecting 2560 events.
[22:22:52.135] <TB0> INFO: 2560 events read in total (302ms).
[22:22:52.135] <TB0> INFO: Test took 1201ms.
[22:22:52.138] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:52.443] <TB0> INFO: Expecting 2560 events.
[22:22:53.331] <TB0> INFO: 2560 events read in total (296ms).
[22:22:53.331] <TB0> INFO: Test took 1194ms.
[22:22:53.333] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:53.640] <TB0> INFO: Expecting 2560 events.
[22:22:54.535] <TB0> INFO: 2560 events read in total (303ms).
[22:22:54.535] <TB0> INFO: Test took 1202ms.
[22:22:54.538] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:54.844] <TB0> INFO: Expecting 2560 events.
[22:22:55.734] <TB0> INFO: 2560 events read in total (298ms).
[22:22:55.734] <TB0> INFO: Test took 1196ms.
[22:22:55.737] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:56.043] <TB0> INFO: Expecting 2560 events.
[22:22:56.931] <TB0> INFO: 2560 events read in total (297ms).
[22:22:56.931] <TB0> INFO: Test took 1194ms.
[22:22:56.934] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:57.240] <TB0> INFO: Expecting 2560 events.
[22:22:58.129] <TB0> INFO: 2560 events read in total (298ms).
[22:22:58.129] <TB0> INFO: Test took 1196ms.
[22:22:58.132] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:58.438] <TB0> INFO: Expecting 2560 events.
[22:22:59.333] <TB0> INFO: 2560 events read in total (304ms).
[22:22:59.333] <TB0> INFO: Test took 1201ms.
[22:22:59.336] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[22:22:59.641] <TB0> INFO: Expecting 2560 events.
[22:23:00.535] <TB0> INFO: 2560 events read in total (302ms).
[22:23:00.535] <TB0> INFO: Test took 1199ms.
[22:23:00.006] <TB0> INFO: PixTestPhOptimization::doTest() done, duration: 647 seconds
[22:23:00.006] <TB0> INFO: PH scale (per ROC): 41 51 26 46 42 41 44 44 32 30 43 32 53 47 37 47
[22:23:00.006] <TB0> INFO: PH offset (per ROC): 96 120 107 96 121 90 112 112 101 96 121 114 118 113 102 122
[22:23:01.014] <TB0> INFO: Decoding statistics:
[22:23:01.014] <TB0> INFO: General information:
[22:23:01.014] <TB0> INFO: 16bit words read: 127878
[22:23:01.014] <TB0> INFO: valid events total: 20480
[22:23:01.014] <TB0> INFO: empty events: 17981
[22:23:01.014] <TB0> INFO: valid events with pixels: 2499
[22:23:01.014] <TB0> INFO: valid pixel hits: 2499
[22:23:01.014] <TB0> INFO: Event errors: 0
[22:23:01.014] <TB0> INFO: start marker: 0
[22:23:01.014] <TB0> INFO: stop marker: 0
[22:23:01.014] <TB0> INFO: overflow: 0
[22:23:01.015] <TB0> INFO: invalid 5bit words: 0
[22:23:01.015] <TB0> INFO: invalid XOR eye diagram: 0
[22:23:01.015] <TB0> INFO: frame (failed synchr.): 0
[22:23:01.015] <TB0> INFO: idle data (no TBM trl): 0
[22:23:01.015] <TB0> INFO: no data (only TBM hdr): 0
[22:23:01.015] <TB0> INFO: TBM errors: 0
[22:23:01.015] <TB0> INFO: flawed TBM headers: 0
[22:23:01.015] <TB0> INFO: flawed TBM trailers: 0
[22:23:01.015] <TB0> INFO: event ID mismatches: 0
[22:23:01.015] <TB0> INFO: ROC errors: 0
[22:23:01.015] <TB0> INFO: missing ROC header(s): 0
[22:23:01.015] <TB0> INFO: misplaced readback start: 0
[22:23:01.015] <TB0> INFO: Pixel decoding errors: 0
[22:23:01.015] <TB0> INFO: pixel data incomplete: 0
[22:23:01.015] <TB0> INFO: pixel address: 0
[22:23:01.015] <TB0> INFO: pulse height fill bit: 0
[22:23:01.015] <TB0> INFO: buffer corruption: 0
[22:23:01.173] <TB0> INFO: ######################################################################
[22:23:01.173] <TB0> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[22:23:01.173] <TB0> INFO: ######################################################################
[22:23:01.189] <TB0> INFO: scanning low vcal = 10
[22:23:01.448] <TB0> INFO: Expecting 41600 events.
[22:23:05.075] <TB0> INFO: 41600 events read in total (3035ms).
[22:23:05.075] <TB0> INFO: Test took 3886ms.
[22:23:05.077] <TB0> INFO: scanning low vcal = 20
[22:23:05.372] <TB0> INFO: Expecting 41600 events.
[22:23:08.987] <TB0> INFO: 41600 events read in total (3024ms).
[22:23:08.988] <TB0> INFO: Test took 3911ms.
[22:23:08.989] <TB0> INFO: scanning low vcal = 30
[22:23:09.285] <TB0> INFO: Expecting 41600 events.
[22:23:12.945] <TB0> INFO: 41600 events read in total (3068ms).
[22:23:12.946] <TB0> INFO: Test took 3956ms.
[22:23:12.948] <TB0> INFO: scanning low vcal = 40
[22:23:13.226] <TB0> INFO: Expecting 41600 events.
[22:23:17.209] <TB0> INFO: 41600 events read in total (3392ms).
[22:23:17.210] <TB0> INFO: Test took 4261ms.
[22:23:17.213] <TB0> INFO: scanning low vcal = 50
[22:23:17.489] <TB0> INFO: Expecting 41600 events.
[22:23:21.517] <TB0> INFO: 41600 events read in total (3436ms).
[22:23:21.517] <TB0> INFO: Test took 4304ms.
[22:23:21.521] <TB0> INFO: scanning low vcal = 60
[22:23:21.797] <TB0> INFO: Expecting 41600 events.
[22:23:25.799] <TB0> INFO: 41600 events read in total (3411ms).
[22:23:25.800] <TB0> INFO: Test took 4279ms.
[22:23:25.804] <TB0> INFO: scanning low vcal = 70
[22:23:26.106] <TB0> INFO: Expecting 41600 events.
[22:23:30.109] <TB0> INFO: 41600 events read in total (3412ms).
[22:23:30.110] <TB0> INFO: Test took 4306ms.
[22:23:30.113] <TB0> INFO: scanning low vcal = 80
[22:23:30.389] <TB0> INFO: Expecting 41600 events.
[22:23:34.491] <TB0> INFO: 41600 events read in total (3510ms).
[22:23:34.492] <TB0> INFO: Test took 4379ms.
[22:23:34.495] <TB0> INFO: scanning low vcal = 90
[22:23:34.772] <TB0> INFO: Expecting 41600 events.
[22:23:38.822] <TB0> INFO: 41600 events read in total (3459ms).
[22:23:38.823] <TB0> INFO: Test took 4328ms.
[22:23:38.828] <TB0> INFO: scanning low vcal = 100
[22:23:39.103] <TB0> INFO: Expecting 41600 events.
[22:23:43.127] <TB0> INFO: 41600 events read in total (3433ms).
[22:23:43.127] <TB0> INFO: Test took 4299ms.
[22:23:43.131] <TB0> INFO: scanning low vcal = 110
[22:23:43.430] <TB0> INFO: Expecting 41600 events.
[22:23:47.442] <TB0> INFO: 41600 events read in total (3420ms).
[22:23:47.443] <TB0> INFO: Test took 4312ms.
[22:23:47.446] <TB0> INFO: scanning low vcal = 120
[22:23:47.727] <TB0> INFO: Expecting 41600 events.
[22:23:51.808] <TB0> INFO: 41600 events read in total (3489ms).
[22:23:51.809] <TB0> INFO: Test took 4363ms.
[22:23:51.812] <TB0> INFO: scanning low vcal = 130
[22:23:52.109] <TB0> INFO: Expecting 41600 events.
[22:23:56.140] <TB0> INFO: 41600 events read in total (3439ms).
[22:23:56.140] <TB0> INFO: Test took 4328ms.
[22:23:56.143] <TB0> INFO: scanning low vcal = 140
[22:23:56.420] <TB0> INFO: Expecting 41600 events.
[22:24:00.439] <TB0> INFO: 41600 events read in total (3427ms).
[22:24:00.440] <TB0> INFO: Test took 4297ms.
[22:24:00.442] <TB0> INFO: scanning low vcal = 150
[22:24:00.719] <TB0> INFO: Expecting 41600 events.
[22:24:04.766] <TB0> INFO: 41600 events read in total (3455ms).
[22:24:04.767] <TB0> INFO: Test took 4325ms.
[22:24:04.770] <TB0> INFO: scanning low vcal = 160
[22:24:05.046] <TB0> INFO: Expecting 41600 events.
[22:24:09.056] <TB0> INFO: 41600 events read in total (3418ms).
[22:24:09.056] <TB0> INFO: Test took 4286ms.
[22:24:09.059] <TB0> INFO: scanning low vcal = 170
[22:24:09.336] <TB0> INFO: Expecting 41600 events.
[22:24:13.360] <TB0> INFO: 41600 events read in total (3433ms).
[22:24:13.361] <TB0> INFO: Test took 4302ms.
[22:24:13.366] <TB0> INFO: scanning low vcal = 180
[22:24:13.640] <TB0> INFO: Expecting 41600 events.
[22:24:17.700] <TB0> INFO: 41600 events read in total (3468ms).
[22:24:17.701] <TB0> INFO: Test took 4335ms.
[22:24:17.704] <TB0> INFO: scanning low vcal = 190
[22:24:17.002] <TB0> INFO: Expecting 41600 events.
[22:24:22.127] <TB0> INFO: 41600 events read in total (3534ms).
[22:24:22.128] <TB0> INFO: Test took 4424ms.
[22:24:22.131] <TB0> INFO: scanning low vcal = 200
[22:24:22.457] <TB0> INFO: Expecting 41600 events.
[22:24:26.424] <TB0> INFO: 41600 events read in total (3376ms).
[22:24:26.425] <TB0> INFO: Test took 4293ms.
[22:24:26.428] <TB0> INFO: scanning low vcal = 210
[22:24:26.704] <TB0> INFO: Expecting 41600 events.
[22:24:30.726] <TB0> INFO: 41600 events read in total (3430ms).
[22:24:30.727] <TB0> INFO: Test took 4299ms.
[22:24:30.731] <TB0> INFO: scanning low vcal = 220
[22:24:30.007] <TB0> INFO: Expecting 41600 events.
[22:24:34.994] <TB0> INFO: 41600 events read in total (3396ms).
[22:24:34.995] <TB0> INFO: Test took 4264ms.
[22:24:34.998] <TB0> INFO: scanning low vcal = 230
[22:24:35.274] <TB0> INFO: Expecting 41600 events.
[22:24:39.265] <TB0> INFO: 41600 events read in total (3399ms).
[22:24:39.266] <TB0> INFO: Test took 4268ms.
[22:24:39.269] <TB0> INFO: scanning low vcal = 240
[22:24:39.546] <TB0> INFO: Expecting 41600 events.
[22:24:43.596] <TB0> INFO: 41600 events read in total (3459ms).
[22:24:43.597] <TB0> INFO: Test took 4327ms.
[22:24:43.600] <TB0> INFO: scanning low vcal = 250
[22:24:43.877] <TB0> INFO: Expecting 41600 events.
[22:24:47.919] <TB0> INFO: 41600 events read in total (3450ms).
[22:24:47.920] <TB0> INFO: Test took 4320ms.
[22:24:47.925] <TB0> INFO: scanning high vcal = 30 (= 210 in low range)
[22:24:48.200] <TB0> INFO: Expecting 41600 events.
[22:24:52.176] <TB0> INFO: 41600 events read in total (3384ms).
[22:24:52.176] <TB0> INFO: Test took 4251ms.
[22:24:52.179] <TB0> INFO: scanning high vcal = 50 (= 350 in low range)
[22:24:52.456] <TB0> INFO: Expecting 41600 events.
[22:24:56.472] <TB0> INFO: 41600 events read in total (3424ms).
[22:24:56.473] <TB0> INFO: Test took 4294ms.
[22:24:56.477] <TB0> INFO: scanning high vcal = 70 (= 490 in low range)
[22:24:56.792] <TB0> INFO: Expecting 41600 events.
[22:25:00.749] <TB0> INFO: 41600 events read in total (3365ms).
[22:25:00.750] <TB0> INFO: Test took 4273ms.
[22:25:00.754] <TB0> INFO: scanning high vcal = 90 (= 630 in low range)
[22:25:01.069] <TB0> INFO: Expecting 41600 events.
[22:25:05.053] <TB0> INFO: 41600 events read in total (3392ms).
[22:25:05.054] <TB0> INFO: Test took 4300ms.
[22:25:05.057] <TB0> INFO: scanning high vcal = 200 (= 1400 in low range)
[22:25:05.333] <TB0> INFO: Expecting 41600 events.
[22:25:09.359] <TB0> INFO: 41600 events read in total (3434ms).
[22:25:09.360] <TB0> INFO: Test took 4303ms.
[22:25:09.768] <TB0> INFO: PixTestGainPedestal::measure() done
[22:25:42.809] <TB0> INFO: PixTestGainPedestal::fit() done
[22:25:42.809] <TB0> INFO: non-linearity mean: 0.955 0.981 1.064 0.958 0.975 0.937 0.960 0.933 0.919 1.030 0.964 0.954 0.980 0.975 0.949 0.982
[22:25:42.809] <TB0> INFO: non-linearity RMS: 0.055 0.005 0.137 0.042 0.009 0.104 0.036 0.077 0.088 0.155 0.025 0.163 0.011 0.007 0.059 0.003
[22:25:42.809] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C0.dat
[22:25:42.822] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C1.dat
[22:25:42.836] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C2.dat
[22:25:42.849] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C3.dat
[22:25:42.863] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C4.dat
[22:25:42.876] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C5.dat
[22:25:42.889] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C6.dat
[22:25:42.903] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C7.dat
[22:25:42.916] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C8.dat
[22:25:42.930] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C9.dat
[22:25:42.943] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C10.dat
[22:25:42.956] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C11.dat
[22:25:42.970] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C12.dat
[22:25:42.983] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C13.dat
[22:25:42.996] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C14.dat
[22:25:43.009] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1040_FullQualification_2016-10-21_18h29m_1477067371//003_Fulltest_p17//phCalibrationFitErr35_C15.dat
[22:25:43.023] <TB0> INFO: PixTestGainPedestal::fullTest() done, duration: 161 seconds
[22:25:43.023] <TB0> INFO: Decoding statistics:
[22:25:43.023] <TB0> INFO: General information:
[22:25:43.023] <TB0> INFO: 16bit words read: 3216748
[22:25:43.023] <TB0> INFO: valid events total: 332800
[22:25:43.023] <TB0> INFO: empty events: 3595
[22:25:43.023] <TB0> INFO: valid events with pixels: 329205
[22:25:43.023] <TB0> INFO: valid pixel hits: 609974
[22:25:43.023] <TB0> INFO: Event errors: 0
[22:25:43.023] <TB0> INFO: start marker: 0
[22:25:43.023] <TB0> INFO: stop marker: 0
[22:25:43.023] <TB0> INFO: overflow: 0
[22:25:43.023] <TB0> INFO: invalid 5bit words: 0
[22:25:43.023] <TB0> INFO: invalid XOR eye diagram: 0
[22:25:43.023] <TB0> INFO: frame (failed synchr.): 0
[22:25:43.023] <TB0> INFO: idle data (no TBM trl): 0
[22:25:43.023] <TB0> INFO: no data (only TBM hdr): 0
[22:25:43.023] <TB0> INFO: TBM errors: 0
[22:25:43.023] <TB0> INFO: flawed TBM headers: 0
[22:25:43.023] <TB0> INFO: flawed TBM trailers: 0
[22:25:43.023] <TB0> INFO: event ID mismatches: 0
[22:25:43.023] <TB0> INFO: ROC errors: 0
[22:25:43.023] <TB0> INFO: missing ROC header(s): 0
[22:25:43.023] <TB0> INFO: misplaced readback start: 0
[22:25:43.023] <TB0> INFO: Pixel decoding errors: 0
[22:25:43.023] <TB0> INFO: pixel data incomplete: 0
[22:25:43.023] <TB0> INFO: pixel address: 0
[22:25:43.023] <TB0> INFO: pulse height fill bit: 0
[22:25:43.023] <TB0> INFO: buffer corruption: 0
[22:25:43.038] <TB0> INFO: Decoding statistics:
[22:25:43.038] <TB0> INFO: General information:
[22:25:43.038] <TB0> INFO: 16bit words read: 3346162
[22:25:43.038] <TB0> INFO: valid events total: 353536
[22:25:43.038] <TB0> INFO: empty events: 21832
[22:25:43.038] <TB0> INFO: valid events with pixels: 331704
[22:25:43.038] <TB0> INFO: valid pixel hits: 612473
[22:25:43.038] <TB0> INFO: Event errors: 0
[22:25:43.038] <TB0> INFO: start marker: 0
[22:25:43.038] <TB0> INFO: stop marker: 0
[22:25:43.038] <TB0> INFO: overflow: 0
[22:25:43.038] <TB0> INFO: invalid 5bit words: 0
[22:25:43.038] <TB0> INFO: invalid XOR eye diagram: 0
[22:25:43.038] <TB0> INFO: frame (failed synchr.): 0
[22:25:43.038] <TB0> INFO: idle data (no TBM trl): 0
[22:25:43.038] <TB0> INFO: no data (only TBM hdr): 0
[22:25:43.038] <TB0> INFO: TBM errors: 0
[22:25:43.038] <TB0> INFO: flawed TBM headers: 0
[22:25:43.039] <TB0> INFO: flawed TBM trailers: 0
[22:25:43.039] <TB0> INFO: event ID mismatches: 0
[22:25:43.039] <TB0> INFO: ROC errors: 0
[22:25:43.039] <TB0> INFO: missing ROC header(s): 0
[22:25:43.039] <TB0> INFO: misplaced readback start: 0
[22:25:43.039] <TB0> INFO: Pixel decoding errors: 0
[22:25:43.039] <TB0> INFO: pixel data incomplete: 0
[22:25:43.039] <TB0> INFO: pixel address: 0
[22:25:43.039] <TB0> INFO: pulse height fill bit: 0
[22:25:43.039] <TB0> INFO: buffer corruption: 0
[22:25:43.039] <TB0> INFO: enter test to run
[22:25:43.039] <TB0> INFO: test: exit no parameter change
[22:25:43.155] <TB0> QUIET: Connection to board 71 closed.
[22:25:43.156] <TB0> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud