Test Date: 2016-10-19 14:13
Analysis date: 2016-10-19 19:51
Logfile
LogfileView
[15:04:56.208] <TB3> INFO: *** Welcome to pxar ***
[15:04:56.208] <TB3> INFO: *** Today: 2016/10/19
[15:04:56.214] <TB3> INFO: *** Version: c8ba-dirty
[15:04:56.214] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C15.dat
[15:04:56.215] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//tbmParameters_C1b.dat
[15:04:56.215] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//defaultMaskFile.dat
[15:04:56.215] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters_C15.dat
[15:04:56.279] <TB3> INFO: clk: 4
[15:04:56.279] <TB3> INFO: ctr: 4
[15:04:56.279] <TB3> INFO: sda: 19
[15:04:56.279] <TB3> INFO: tin: 9
[15:04:56.279] <TB3> INFO: level: 15
[15:04:56.279] <TB3> INFO: triggerdelay: 0
[15:04:56.279] <TB3> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[15:04:56.279] <TB3> INFO: Log level: INFO
[15:04:56.288] <TB3> INFO: Found DTB DTB_WWVASW
[15:04:56.296] <TB3> QUIET: Connection to board DTB_WWVASW opened.
[15:04:56.298] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 126
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWVASW
MAC address: 40D85511807E
Hostname: pixelDTB126
Comment:
------------------------------------------------------
[15:04:56.300] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[15:04:57.797] <TB3> INFO: DUT info:
[15:04:57.797] <TB3> INFO: The DUT currently contains the following objects:
[15:04:57.797] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[15:04:57.797] <TB3> INFO: TBM Core alpha (0): 7 registers set
[15:04:57.797] <TB3> INFO: TBM Core beta (1): 7 registers set
[15:04:57.797] <TB3> INFO: TBM Core alpha (2): 7 registers set
[15:04:57.797] <TB3> INFO: TBM Core beta (3): 7 registers set
[15:04:57.797] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[15:04:57.797] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.797] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.797] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.797] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.797] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.797] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.797] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.798] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.798] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.798] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.798] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.798] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.798] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.798] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.798] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:57.798] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:04:58.199] <TB3> INFO: enter 'restricted' command line mode
[15:04:58.199] <TB3> INFO: enter test to run
[15:04:58.199] <TB3> INFO: test: pretest no parameter change
[15:04:58.199] <TB3> INFO: running: pretest
[15:04:58.205] <TB3> INFO: ######################################################################
[15:04:58.205] <TB3> INFO: PixTestPretest::doTest()
[15:04:58.205] <TB3> INFO: ######################################################################
[15:04:58.207] <TB3> INFO: ----------------------------------------------------------------------
[15:04:58.207] <TB3> INFO: PixTestPretest::programROC()
[15:04:58.207] <TB3> INFO: ----------------------------------------------------------------------
[15:05:16.221] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[15:05:16.221] <TB3> INFO: IA differences per ROC: 16.9 20.1 19.3 19.3 19.3 20.1 20.9 20.9 19.3 16.9 20.1 19.3 20.1 20.9 22.5 19.3
[15:05:16.277] <TB3> INFO: ----------------------------------------------------------------------
[15:05:16.277] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[15:05:16.277] <TB3> INFO: ----------------------------------------------------------------------
[15:05:22.575] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 394.7 mA = 24.6687 mA/ROC
[15:05:22.575] <TB3> INFO: i(loss) [mA/ROC]: 20.1 20.1 20.1 20.1 20.1 19.3 20.1 20.1 20.1 20.1 20.1 19.3 20.1 20.1 20.1 19.3
[15:05:22.604] <TB3> INFO: ----------------------------------------------------------------------
[15:05:22.604] <TB3> INFO: PixTestPretest::findTiming()
[15:05:22.604] <TB3> INFO: ----------------------------------------------------------------------
[15:05:22.604] <TB3> INFO: PixTestCmd::init()
[15:05:23.176] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!

[15:05:54.808] <TB3> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[15:05:54.808] <TB3> INFO: (success/tries = 100/100), width = 4
[15:05:56.309] <TB3> INFO: ----------------------------------------------------------------------
[15:05:56.309] <TB3> INFO: PixTestPretest::findWorkingPixel()
[15:05:56.309] <TB3> INFO: ----------------------------------------------------------------------
[15:05:56.404] <TB3> INFO: Expecting 231680 events.
[15:06:06.487] <TB3> INFO: 231680 events read in total (9491ms).
[15:06:06.496] <TB3> INFO: Test took 10182ms.
[15:06:06.737] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[15:06:06.773] <TB3> INFO: ----------------------------------------------------------------------
[15:06:06.773] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[15:06:06.773] <TB3> INFO: ----------------------------------------------------------------------
[15:06:06.867] <TB3> INFO: Expecting 231680 events.
[15:06:16.809] <TB3> INFO: 231680 events read in total (9350ms).
[15:06:16.818] <TB3> INFO: Test took 10040ms.
[15:06:17.087] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[15:06:17.087] <TB3> INFO: CalDel: 78 88 107 125 97 101 94 101 82 85 94 96 118 96 116 105
[15:06:17.087] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[15:06:17.094] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C0.dat
[15:06:17.094] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C1.dat
[15:06:17.094] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C2.dat
[15:06:17.094] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C3.dat
[15:06:17.094] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C4.dat
[15:06:17.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C5.dat
[15:06:17.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C6.dat
[15:06:17.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C7.dat
[15:06:17.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C8.dat
[15:06:17.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C9.dat
[15:06:17.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C10.dat
[15:06:17.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C11.dat
[15:06:17.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C12.dat
[15:06:17.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C13.dat
[15:06:17.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C14.dat
[15:06:17.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters_C15.dat
[15:06:17.096] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//tbmParameters_C0a.dat
[15:06:17.096] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//tbmParameters_C0b.dat
[15:06:17.096] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//tbmParameters_C1a.dat
[15:06:17.096] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//tbmParameters_C1b.dat
[15:06:17.096] <TB3> INFO: PixTestPretest::doTest() done, duration: 78 seconds
[15:06:17.148] <TB3> INFO: enter test to run
[15:06:17.148] <TB3> INFO: test: FullTest no parameter change
[15:06:17.148] <TB3> INFO: running: fulltest
[15:06:17.148] <TB3> INFO: ######################################################################
[15:06:17.148] <TB3> INFO: PixTestFullTest::doTest()
[15:06:17.148] <TB3> INFO: ######################################################################
[15:06:17.149] <TB3> INFO: ######################################################################
[15:06:17.149] <TB3> INFO: PixTestAlive::doTest()
[15:06:17.149] <TB3> INFO: ######################################################################
[15:06:17.151] <TB3> INFO: ----------------------------------------------------------------------
[15:06:17.151] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:06:17.151] <TB3> INFO: ----------------------------------------------------------------------
[15:06:17.387] <TB3> INFO: Expecting 41600 events.
[15:06:20.881] <TB3> INFO: 41600 events read in total (2902ms).
[15:06:20.881] <TB3> INFO: Test took 3729ms.
[15:06:21.112] <TB3> INFO: PixTestAlive::aliveTest() done
[15:06:21.112] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0
[15:06:21.113] <TB3> INFO: ----------------------------------------------------------------------
[15:06:21.113] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:06:21.113] <TB3> INFO: ----------------------------------------------------------------------
[15:06:21.358] <TB3> INFO: Expecting 41600 events.
[15:06:24.356] <TB3> INFO: 41600 events read in total (2406ms).
[15:06:24.356] <TB3> INFO: Test took 3239ms.
[15:06:24.357] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[15:06:24.594] <TB3> INFO: PixTestAlive::maskTest() done
[15:06:24.594] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:06:24.596] <TB3> INFO: ----------------------------------------------------------------------
[15:06:24.596] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:06:24.596] <TB3> INFO: ----------------------------------------------------------------------
[15:06:24.838] <TB3> INFO: Expecting 41600 events.
[15:06:28.453] <TB3> INFO: 41600 events read in total (3023ms).
[15:06:28.454] <TB3> INFO: Test took 3856ms.
[15:06:28.689] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[15:06:28.689] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:06:28.689] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[15:06:28.689] <TB3> INFO: Decoding statistics:
[15:06:28.689] <TB3> INFO: General information:
[15:06:28.689] <TB3> INFO: 16bit words read: 0
[15:06:28.689] <TB3> INFO: valid events total: 0
[15:06:28.689] <TB3> INFO: empty events: 0
[15:06:28.689] <TB3> INFO: valid events with pixels: 0
[15:06:28.689] <TB3> INFO: valid pixel hits: 0
[15:06:28.689] <TB3> INFO: Event errors: 0
[15:06:28.689] <TB3> INFO: start marker: 0
[15:06:28.689] <TB3> INFO: stop marker: 0
[15:06:28.689] <TB3> INFO: overflow: 0
[15:06:28.689] <TB3> INFO: invalid 5bit words: 0
[15:06:28.689] <TB3> INFO: invalid XOR eye diagram: 0
[15:06:28.689] <TB3> INFO: frame (failed synchr.): 0
[15:06:28.689] <TB3> INFO: idle data (no TBM trl): 0
[15:06:28.689] <TB3> INFO: no data (only TBM hdr): 0
[15:06:28.689] <TB3> INFO: TBM errors: 0
[15:06:28.689] <TB3> INFO: flawed TBM headers: 0
[15:06:28.689] <TB3> INFO: flawed TBM trailers: 0
[15:06:28.689] <TB3> INFO: event ID mismatches: 0
[15:06:28.689] <TB3> INFO: ROC errors: 0
[15:06:28.689] <TB3> INFO: missing ROC header(s): 0
[15:06:28.689] <TB3> INFO: misplaced readback start: 0
[15:06:28.690] <TB3> INFO: Pixel decoding errors: 0
[15:06:28.690] <TB3> INFO: pixel data incomplete: 0
[15:06:28.690] <TB3> INFO: pixel address: 0
[15:06:28.690] <TB3> INFO: pulse height fill bit: 0
[15:06:28.690] <TB3> INFO: buffer corruption: 0
[15:06:28.697] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C15.dat
[15:06:28.698] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[15:06:28.698] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[15:06:28.698] <TB3> INFO: ######################################################################
[15:06:28.698] <TB3> INFO: PixTestReadback::doTest()
[15:06:28.698] <TB3> INFO: ######################################################################
[15:06:28.698] <TB3> INFO: ----------------------------------------------------------------------
[15:06:28.698] <TB3> INFO: PixTestReadback::CalibrateVd()
[15:06:28.698] <TB3> INFO: ----------------------------------------------------------------------
[15:06:38.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C0.dat
[15:06:38.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C1.dat
[15:06:38.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C2.dat
[15:06:38.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C3.dat
[15:06:38.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C4.dat
[15:06:38.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C5.dat
[15:06:38.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C6.dat
[15:06:38.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C7.dat
[15:06:38.675] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C8.dat
[15:06:38.676] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C9.dat
[15:06:38.676] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C10.dat
[15:06:38.676] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C11.dat
[15:06:38.676] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C12.dat
[15:06:38.676] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C13.dat
[15:06:38.676] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C14.dat
[15:06:38.676] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C15.dat
[15:06:38.707] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[15:06:38.707] <TB3> INFO: ----------------------------------------------------------------------
[15:06:38.707] <TB3> INFO: PixTestReadback::CalibrateVa()
[15:06:38.707] <TB3> INFO: ----------------------------------------------------------------------
[15:06:48.644] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C0.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C1.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C2.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C3.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C4.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C5.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C6.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C7.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C8.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C9.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C10.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C11.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C12.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C13.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C14.dat
[15:06:48.645] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C15.dat
[15:06:48.678] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[15:06:48.678] <TB3> INFO: ----------------------------------------------------------------------
[15:06:48.678] <TB3> INFO: PixTestReadback::readbackVbg()
[15:06:48.678] <TB3> INFO: ----------------------------------------------------------------------
[15:06:56.353] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[15:06:56.353] <TB3> INFO: ----------------------------------------------------------------------
[15:06:56.353] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[15:06:56.353] <TB3> INFO: ----------------------------------------------------------------------
[15:06:56.353] <TB3> INFO: Vbg will be calibrated using Vd calibration
[15:06:56.353] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 158.4calibrated Vbg = 1.19717 :::*/*/*/*/
[15:06:56.353] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 163calibrated Vbg = 1.19863 :::*/*/*/*/
[15:06:56.353] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 150.9calibrated Vbg = 1.19537 :::*/*/*/*/
[15:06:56.353] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 153.6calibrated Vbg = 1.19187 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 168.4calibrated Vbg = 1.18851 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 148calibrated Vbg = 1.19638 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 157.2calibrated Vbg = 1.20056 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 147.7calibrated Vbg = 1.19379 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 159.2calibrated Vbg = 1.19134 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 156calibrated Vbg = 1.18919 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 152.2calibrated Vbg = 1.18737 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 151.1calibrated Vbg = 1.18513 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 146.7calibrated Vbg = 1.18754 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 152.6calibrated Vbg = 1.19836 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 149.9calibrated Vbg = 1.19695 :::*/*/*/*/
[15:06:56.354] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 158.3calibrated Vbg = 1.19164 :::*/*/*/*/
[15:06:56.356] <TB3> INFO: ----------------------------------------------------------------------
[15:06:56.356] <TB3> INFO: PixTestReadback::CalibrateIa()
[15:06:56.356] <TB3> INFO: ----------------------------------------------------------------------
[15:09:37.161] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C0.dat
[15:09:37.161] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C1.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C2.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C3.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C4.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C5.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C6.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C7.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C8.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C9.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C10.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C11.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C12.dat
[15:09:37.162] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C13.dat
[15:09:37.163] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C14.dat
[15:09:37.163] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//readbackCal_C15.dat
[15:09:37.191] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[15:09:37.193] <TB3> INFO: PixTestReadback::doTest() done
[15:09:37.193] <TB3> INFO: Decoding statistics:
[15:09:37.193] <TB3> INFO: General information:
[15:09:37.193] <TB3> INFO: 16bit words read: 1558
[15:09:37.193] <TB3> INFO: valid events total: 256
[15:09:37.193] <TB3> INFO: empty events: 245
[15:09:37.193] <TB3> INFO: valid events with pixels: 11
[15:09:37.193] <TB3> INFO: valid pixel hits: 11
[15:09:37.193] <TB3> INFO: Event errors: 0
[15:09:37.193] <TB3> INFO: start marker: 0
[15:09:37.193] <TB3> INFO: stop marker: 0
[15:09:37.193] <TB3> INFO: overflow: 0
[15:09:37.193] <TB3> INFO: invalid 5bit words: 0
[15:09:37.193] <TB3> INFO: invalid XOR eye diagram: 0
[15:09:37.193] <TB3> INFO: frame (failed synchr.): 0
[15:09:37.193] <TB3> INFO: idle data (no TBM trl): 0
[15:09:37.193] <TB3> INFO: no data (only TBM hdr): 0
[15:09:37.193] <TB3> INFO: TBM errors: 0
[15:09:37.193] <TB3> INFO: flawed TBM headers: 0
[15:09:37.193] <TB3> INFO: flawed TBM trailers: 0
[15:09:37.193] <TB3> INFO: event ID mismatches: 0
[15:09:37.193] <TB3> INFO: ROC errors: 0
[15:09:37.193] <TB3> INFO: missing ROC header(s): 0
[15:09:37.193] <TB3> INFO: misplaced readback start: 0
[15:09:37.193] <TB3> INFO: Pixel decoding errors: 0
[15:09:37.193] <TB3> INFO: pixel data incomplete: 0
[15:09:37.193] <TB3> INFO: pixel address: 0
[15:09:37.193] <TB3> INFO: pulse height fill bit: 0
[15:09:37.193] <TB3> INFO: buffer corruption: 0
[15:09:37.242] <TB3> INFO: ######################################################################
[15:09:37.242] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[15:09:37.242] <TB3> INFO: ######################################################################
[15:09:37.244] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[15:09:37.258] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[15:09:37.258] <TB3> INFO: run 1 of 1
[15:09:37.514] <TB3> INFO: Expecting 3120000 events.
[15:10:08.319] <TB3> INFO: 660735 events read in total (30213ms).
[15:10:20.355] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (128) != TBM ID (129)

[15:10:20.491] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 128 128 129 128 128 128 128 128

[15:10:20.491] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (129)

[15:10:20.491] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[15:10:20.491] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a084 80b1 4180 260 21ef 4180 260 21ef e022 c000

[15:10:20.491] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07e 8000 4181 260 21ef 4181 260 21ef e022 c000

[15:10:20.491] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07f 8040 4183 260 21ef 4183 260 21ef e022 c000

[15:10:20.491] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4181 21ef 4300 260 21ef e022 c000

[15:10:20.491] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4381 260 21ef 4301 260 21ef e022 c000

[15:10:20.491] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a082 8000 4380 260 21ef 4380 260 21ef e022 c000

[15:10:20.491] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a083 8040 4180 260 21ef 4181 260 21ef e022 c000

[15:10:38.163] <TB3> INFO: 1315215 events read in total (60057ms).
[15:10:50.131] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (16) != TBM ID (129)

[15:10:50.272] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 16 16 129 16 16 16 16 16

[15:10:50.272] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (17)

[15:10:50.272] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[15:10:50.272] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a014 80b1 4180 4b2 23ef 4380 4b2 23ef e022 c000

[15:10:50.272] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00e 8000 4180 4b2 23ef 4180 4b2 23ef e022 c000

[15:10:50.272] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00f 8040 4183 4b2 23ef 4183 4b2 23ef e022 c000

[15:10:50.272] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4181 23ef 4180 4b2 23ef e022 c000

[15:10:50.272] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a011 80c0 4181 4b2 23ef 4181 4b2 23ef e022 c000

[15:10:50.272] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a012 8000 4300 4b2 23ef 4380 4b2 23ef e022 c000

[15:10:50.272] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a013 8040 4380 4b2 23ef 4301 4b2 23ef e022 c000

[15:11:08.103] <TB3> INFO: 1966125 events read in total (89997ms).
[15:11:20.060] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (174) != TBM ID (129)

[15:11:20.199] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 174 174 129 174 174 174 174 174

[15:11:20.199] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (175)

[15:11:20.200] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[15:11:20.200] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b2 8000 4380 4380 80e 2bef e022 c000

[15:11:20.200] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ac 80b1 4180 80e 2bef 4180 80e 2bef e022 c000

[15:11:20.200] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ad 80c0 4181 80e 2bef 4181 80e 2bef e022 c000

[15:11:20.200] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4181 2bef 4381 80e 2bef e022 c000

[15:11:20.200] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0af 8040 4383 80e 2bef 4183 80e 2bef e022 c000

[15:11:20.200] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b0 80b1 4180 80e 2bef 4180 80e 2bef e022 c000

[15:11:20.200] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b1 80c0 4381 80e 2bef 4181 80e 2bef e022 c000

[15:11:38.028] <TB3> INFO: 2616640 events read in total (119922ms).
[15:11:47.359] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (193) != TBM ID (129)

[15:11:47.506] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 193 193 129 193 193 193 193 193

[15:11:47.507] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (194)

[15:11:47.507] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[15:11:47.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c5 80c0 4180 a6c 21ef 4180 a6c 21ef e022 c000

[15:11:47.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bf 8040 4182 a6c 21ef 4182 a6c 21ef e022 c000

[15:11:47.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c0 80b1 4180 a6c 21ef 4180 a6c 21ef e022 c000

[15:11:47.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4181 21ef 4181 a6c 21ef e022 c000

[15:11:47.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c2 8000 4380 a6c 21ef 4380 a6c 21ef e022 c000

[15:11:47.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c3 8040 4180 a6c 21ef 4181 a6c 21ef e022 c000

[15:11:47.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c4 80b1 4180 a6c 21ef 4180 a6c 21ef e022 c000

[15:12:01.337] <TB3> INFO: 3120000 events read in total (143231ms).
[15:12:01.414] <TB3> INFO: Test took 144156ms.
[15:12:26.833] <TB3> INFO: PixTestBBMap::doTest() done with 4 decoding errors: , duration: 169 seconds
[15:12:26.833] <TB3> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 1 0 0 0
[15:12:26.833] <TB3> INFO: separation cut (per ROC): 107 125 96 103 109 108 99 110 113 108 113 107 103 109 107 102
[15:12:26.833] <TB3> INFO: Decoding statistics:
[15:12:26.833] <TB3> INFO: General information:
[15:12:26.833] <TB3> INFO: 16bit words read: 0
[15:12:26.833] <TB3> INFO: valid events total: 0
[15:12:26.833] <TB3> INFO: empty events: 0
[15:12:26.833] <TB3> INFO: valid events with pixels: 0
[15:12:26.833] <TB3> INFO: valid pixel hits: 0
[15:12:26.833] <TB3> INFO: Event errors: 0
[15:12:26.833] <TB3> INFO: start marker: 0
[15:12:26.833] <TB3> INFO: stop marker: 0
[15:12:26.833] <TB3> INFO: overflow: 0
[15:12:26.833] <TB3> INFO: invalid 5bit words: 0
[15:12:26.833] <TB3> INFO: invalid XOR eye diagram: 0
[15:12:26.833] <TB3> INFO: frame (failed synchr.): 0
[15:12:26.833] <TB3> INFO: idle data (no TBM trl): 0
[15:12:26.833] <TB3> INFO: no data (only TBM hdr): 0
[15:12:26.833] <TB3> INFO: TBM errors: 0
[15:12:26.833] <TB3> INFO: flawed TBM headers: 0
[15:12:26.833] <TB3> INFO: flawed TBM trailers: 0
[15:12:26.833] <TB3> INFO: event ID mismatches: 0
[15:12:26.833] <TB3> INFO: ROC errors: 0
[15:12:26.833] <TB3> INFO: missing ROC header(s): 0
[15:12:26.833] <TB3> INFO: misplaced readback start: 0
[15:12:26.833] <TB3> INFO: Pixel decoding errors: 0
[15:12:26.833] <TB3> INFO: pixel data incomplete: 0
[15:12:26.833] <TB3> INFO: pixel address: 0
[15:12:26.833] <TB3> INFO: pulse height fill bit: 0
[15:12:26.833] <TB3> INFO: buffer corruption: 0
[15:12:26.883] <TB3> INFO: ######################################################################
[15:12:26.883] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[15:12:26.883] <TB3> INFO: ######################################################################
[15:12:26.883] <TB3> INFO: ----------------------------------------------------------------------
[15:12:26.883] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[15:12:26.883] <TB3> INFO: ----------------------------------------------------------------------
[15:12:26.883] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[15:12:26.895] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[15:12:26.895] <TB3> INFO: run 1 of 1
[15:12:27.133] <TB3> INFO: Expecting 36608000 events.
[15:12:50.718] <TB3> INFO: 669750 events read in total (22993ms).
[15:13:13.468] <TB3> INFO: 1328150 events read in total (45743ms).
[15:13:36.102] <TB3> INFO: 1986300 events read in total (68377ms).
[15:13:59.071] <TB3> INFO: 2644600 events read in total (91346ms).
[15:14:21.558] <TB3> INFO: 3303300 events read in total (113833ms).
[15:14:44.665] <TB3> INFO: 3961350 events read in total (136940ms).
[15:15:07.502] <TB3> INFO: 4618700 events read in total (159777ms).
[15:15:30.231] <TB3> INFO: 5276400 events read in total (182506ms).
[15:15:53.003] <TB3> INFO: 5932100 events read in total (205278ms).
[15:16:15.727] <TB3> INFO: 6589800 events read in total (228002ms).
[15:16:38.404] <TB3> INFO: 7247150 events read in total (250679ms).
[15:17:00.970] <TB3> INFO: 7902050 events read in total (273245ms).
[15:17:24.230] <TB3> INFO: 8558900 events read in total (296505ms).
[15:17:47.162] <TB3> INFO: 9214950 events read in total (319437ms).
[15:18:10.265] <TB3> INFO: 9870850 events read in total (342540ms).
[15:18:32.913] <TB3> INFO: 10525200 events read in total (365188ms).
[15:18:55.729] <TB3> INFO: 11179100 events read in total (388004ms).
[15:19:18.507] <TB3> INFO: 11832900 events read in total (410782ms).
[15:19:41.316] <TB3> INFO: 12486600 events read in total (433591ms).
[15:20:03.997] <TB3> INFO: 13138600 events read in total (456272ms).
[15:20:26.978] <TB3> INFO: 13791850 events read in total (479253ms).
[15:20:49.920] <TB3> INFO: 14444650 events read in total (502195ms).
[15:21:12.649] <TB3> INFO: 15097700 events read in total (524924ms).
[15:21:35.768] <TB3> INFO: 15750000 events read in total (548043ms).
[15:21:58.710] <TB3> INFO: 16402500 events read in total (570985ms).
[15:22:21.506] <TB3> INFO: 17054700 events read in total (593781ms).
[15:22:44.496] <TB3> INFO: 17707550 events read in total (616771ms).
[15:23:07.337] <TB3> INFO: 18357250 events read in total (639612ms).
[15:23:29.981] <TB3> INFO: 19006850 events read in total (662256ms).
[15:23:52.509] <TB3> INFO: 19655700 events read in total (684784ms).
[15:24:15.607] <TB3> INFO: 20304250 events read in total (707882ms).
[15:24:38.265] <TB3> INFO: 20952000 events read in total (730540ms).
[15:25:00.980] <TB3> INFO: 21601350 events read in total (753255ms).
[15:25:23.840] <TB3> INFO: 22250500 events read in total (776115ms).
[15:25:46.475] <TB3> INFO: 22896850 events read in total (798751ms).
[15:26:08.970] <TB3> INFO: 23544550 events read in total (821245ms).
[15:26:31.612] <TB3> INFO: 24191100 events read in total (843887ms).
[15:26:54.703] <TB3> INFO: 24839700 events read in total (866978ms).
[15:27:17.680] <TB3> INFO: 25488000 events read in total (889955ms).
[15:27:40.422] <TB3> INFO: 26135150 events read in total (912697ms).
[15:28:03.063] <TB3> INFO: 26782000 events read in total (935338ms).
[15:28:25.955] <TB3> INFO: 27425750 events read in total (958230ms).
[15:28:48.750] <TB3> INFO: 28070050 events read in total (981025ms).
[15:29:11.296] <TB3> INFO: 28715900 events read in total (1003571ms).
[15:29:33.704] <TB3> INFO: 29361250 events read in total (1025979ms).
[15:29:56.259] <TB3> INFO: 30005800 events read in total (1048534ms).
[15:30:19.075] <TB3> INFO: 30651150 events read in total (1071350ms).
[15:30:42.121] <TB3> INFO: 31296700 events read in total (1094396ms).
[15:31:04.634] <TB3> INFO: 31942000 events read in total (1116909ms).
[15:31:27.240] <TB3> INFO: 32588250 events read in total (1139515ms).
[15:31:50.105] <TB3> INFO: 33233800 events read in total (1162380ms).
[15:32:12.593] <TB3> INFO: 33878500 events read in total (1184868ms).
[15:32:35.041] <TB3> INFO: 34527250 events read in total (1207316ms).
[15:32:57.497] <TB3> INFO: 35171700 events read in total (1229772ms).
[15:33:19.688] <TB3> INFO: 35819350 events read in total (1251963ms).
[15:33:42.184] <TB3> INFO: 36475450 events read in total (1274459ms).
[15:33:46.978] <TB3> INFO: 36608000 events read in total (1279253ms).
[15:33:47.067] <TB3> INFO: Test took 1280172ms.
[15:33:47.714] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:33:50.090] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:33:52.122] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:33:54.326] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:33:56.416] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:33:58.462] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:00.393] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:02.451] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:04.238] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:05.941] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:07.919] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:09.534] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:11.361] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:12.774] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:14.238] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:15.684] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[15:34:17.214] <TB3> INFO: PixTestScurves::scurves() done
[15:34:17.214] <TB3> INFO: Vcal mean: 114.33 121.70 105.00 111.04 108.06 107.75 107.90 113.55 105.63 104.74 121.20 106.02 105.63 114.01 112.38 102.79
[15:34:17.214] <TB3> INFO: Vcal RMS: 5.79 6.29 5.05 4.62 4.86 5.00 5.47 5.08 5.30 5.51 6.21 5.01 5.20 5.03 5.09 5.47
[15:34:17.214] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1310 seconds
[15:34:17.214] <TB3> INFO: Decoding statistics:
[15:34:17.214] <TB3> INFO: General information:
[15:34:17.214] <TB3> INFO: 16bit words read: 0
[15:34:17.214] <TB3> INFO: valid events total: 0
[15:34:17.214] <TB3> INFO: empty events: 0
[15:34:17.214] <TB3> INFO: valid events with pixels: 0
[15:34:17.214] <TB3> INFO: valid pixel hits: 0
[15:34:17.214] <TB3> INFO: Event errors: 0
[15:34:17.214] <TB3> INFO: start marker: 0
[15:34:17.214] <TB3> INFO: stop marker: 0
[15:34:17.214] <TB3> INFO: overflow: 0
[15:34:17.214] <TB3> INFO: invalid 5bit words: 0
[15:34:17.214] <TB3> INFO: invalid XOR eye diagram: 0
[15:34:17.214] <TB3> INFO: frame (failed synchr.): 0
[15:34:17.214] <TB3> INFO: idle data (no TBM trl): 0
[15:34:17.214] <TB3> INFO: no data (only TBM hdr): 0
[15:34:17.214] <TB3> INFO: TBM errors: 0
[15:34:17.214] <TB3> INFO: flawed TBM headers: 0
[15:34:17.214] <TB3> INFO: flawed TBM trailers: 0
[15:34:17.214] <TB3> INFO: event ID mismatches: 0
[15:34:17.214] <TB3> INFO: ROC errors: 0
[15:34:17.214] <TB3> INFO: missing ROC header(s): 0
[15:34:17.214] <TB3> INFO: misplaced readback start: 0
[15:34:17.214] <TB3> INFO: Pixel decoding errors: 0
[15:34:17.214] <TB3> INFO: pixel data incomplete: 0
[15:34:17.214] <TB3> INFO: pixel address: 0
[15:34:17.214] <TB3> INFO: pulse height fill bit: 0
[15:34:17.214] <TB3> INFO: buffer corruption: 0
[15:34:17.280] <TB3> INFO: ######################################################################
[15:34:17.280] <TB3> INFO: PixTestTrim::doTest()
[15:34:17.280] <TB3> INFO: ######################################################################
[15:34:17.281] <TB3> INFO: ----------------------------------------------------------------------
[15:34:17.281] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[15:34:17.281] <TB3> INFO: ----------------------------------------------------------------------
[15:34:17.323] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[15:34:17.323] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:34:17.335] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:34:17.335] <TB3> INFO: run 1 of 1
[15:34:17.571] <TB3> INFO: Expecting 5025280 events.
[15:34:48.129] <TB3> INFO: 815624 events read in total (29955ms).
[15:35:18.388] <TB3> INFO: 1628280 events read in total (60214ms).
[15:35:48.404] <TB3> INFO: 2439064 events read in total (90230ms).
[15:36:18.413] <TB3> INFO: 3243648 events read in total (120239ms).
[15:36:47.782] <TB3> INFO: 4043568 events read in total (149608ms).
[15:37:17.135] <TB3> INFO: 4841544 events read in total (178961ms).
[15:37:24.551] <TB3> INFO: 5025280 events read in total (186377ms).
[15:37:24.605] <TB3> INFO: Test took 187270ms.
[15:37:44.624] <TB3> INFO: ROC 0 VthrComp = 126
[15:37:44.624] <TB3> INFO: ROC 1 VthrComp = 133
[15:37:44.624] <TB3> INFO: ROC 2 VthrComp = 110
[15:37:44.624] <TB3> INFO: ROC 3 VthrComp = 121
[15:37:44.625] <TB3> INFO: ROC 4 VthrComp = 119
[15:37:44.625] <TB3> INFO: ROC 5 VthrComp = 120
[15:37:44.625] <TB3> INFO: ROC 6 VthrComp = 113
[15:37:44.625] <TB3> INFO: ROC 7 VthrComp = 127
[15:37:44.625] <TB3> INFO: ROC 8 VthrComp = 120
[15:37:44.625] <TB3> INFO: ROC 9 VthrComp = 119
[15:37:44.626] <TB3> INFO: ROC 10 VthrComp = 130
[15:37:44.626] <TB3> INFO: ROC 11 VthrComp = 119
[15:37:44.626] <TB3> INFO: ROC 12 VthrComp = 118
[15:37:44.626] <TB3> INFO: ROC 13 VthrComp = 131
[15:37:44.626] <TB3> INFO: ROC 14 VthrComp = 128
[15:37:44.627] <TB3> INFO: ROC 15 VthrComp = 114
[15:37:44.864] <TB3> INFO: Expecting 41600 events.
[15:37:48.344] <TB3> INFO: 41600 events read in total (2889ms).
[15:37:48.345] <TB3> INFO: Test took 3717ms.
[15:37:48.354] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[15:37:48.354] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:37:48.366] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:37:48.366] <TB3> INFO: run 1 of 1
[15:37:48.644] <TB3> INFO: Expecting 5025280 events.
[15:38:15.021] <TB3> INFO: 588784 events read in total (25785ms).
[15:38:40.382] <TB3> INFO: 1176216 events read in total (51146ms).
[15:39:06.568] <TB3> INFO: 1763760 events read in total (77333ms).
[15:39:32.574] <TB3> INFO: 2350488 events read in total (103338ms).
[15:39:58.129] <TB3> INFO: 2935672 events read in total (128893ms).
[15:40:23.719] <TB3> INFO: 3519504 events read in total (154483ms).
[15:40:49.729] <TB3> INFO: 4102088 events read in total (180493ms).
[15:41:15.540] <TB3> INFO: 4684344 events read in total (206305ms).
[15:41:31.207] <TB3> INFO: 5025280 events read in total (221972ms).
[15:41:31.275] <TB3> INFO: Test took 222909ms.
[15:41:59.303] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 60.7065 for pixel 20/78 mean/min/max = 46.0967/31.486/60.7075
[15:41:59.303] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 61.153 for pixel 13/3 mean/min/max = 47.6552/34.0121/61.2983
[15:41:59.304] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 59.189 for pixel 24/72 mean/min/max = 46.9226/34.6263/59.2189
[15:41:59.304] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 58.3949 for pixel 49/8 mean/min/max = 45.0258/31.6444/58.4071
[15:41:59.304] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 56.6252 for pixel 22/79 mean/min/max = 44.1237/31.5942/56.6532
[15:41:59.305] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 57.3614 for pixel 22/31 mean/min/max = 44.8398/32.3154/57.3643
[15:41:59.305] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 62.2196 for pixel 4/1 mean/min/max = 46.6595/30.9887/62.3303
[15:41:59.305] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 57.9032 for pixel 9/9 mean/min/max = 44.0481/30.0314/58.0648
[15:41:59.306] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 57.1583 for pixel 5/77 mean/min/max = 44.4825/31.8015/57.1634
[15:41:59.306] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 57.771 for pixel 2/1 mean/min/max = 44.8334/31.4382/58.2285
[15:41:59.306] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 60.0111 for pixel 11/60 mean/min/max = 45.9614/31.2734/60.6494
[15:41:59.307] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 56.4537 for pixel 10/11 mean/min/max = 44.1362/31.7597/56.5127
[15:41:59.307] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 57.0497 for pixel 6/74 mean/min/max = 44.4515/31.7774/57.1257
[15:41:59.307] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 56.7376 for pixel 6/6 mean/min/max = 44.2693/31.677/56.8615
[15:41:59.308] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 58.407 for pixel 9/12 mean/min/max = 45.4226/32.3827/58.4624
[15:41:59.308] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 58.0407 for pixel 4/70 mean/min/max = 45.028/31.7295/58.3264
[15:41:59.308] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:41:59.397] <TB3> INFO: Expecting 411648 events.
[15:42:08.963] <TB3> INFO: 411648 events read in total (8974ms).
[15:42:08.970] <TB3> INFO: Expecting 411648 events.
[15:42:18.446] <TB3> INFO: 411648 events read in total (9072ms).
[15:42:18.459] <TB3> INFO: Expecting 411648 events.
[15:42:27.850] <TB3> INFO: 411648 events read in total (8988ms).
[15:42:27.863] <TB3> INFO: Expecting 411648 events.
[15:42:37.246] <TB3> INFO: 411648 events read in total (8980ms).
[15:42:37.264] <TB3> INFO: Expecting 411648 events.
[15:42:46.657] <TB3> INFO: 411648 events read in total (8991ms).
[15:42:46.677] <TB3> INFO: Expecting 411648 events.
[15:42:56.163] <TB3> INFO: 411648 events read in total (9083ms).
[15:42:56.186] <TB3> INFO: Expecting 411648 events.
[15:43:05.544] <TB3> INFO: 411648 events read in total (8955ms).
[15:43:05.570] <TB3> INFO: Expecting 411648 events.
[15:43:14.885] <TB3> INFO: 411648 events read in total (8912ms).
[15:43:14.912] <TB3> INFO: Expecting 411648 events.
[15:43:24.249] <TB3> INFO: 411648 events read in total (8934ms).
[15:43:24.283] <TB3> INFO: Expecting 411648 events.
[15:43:33.638] <TB3> INFO: 411648 events read in total (8952ms).
[15:43:33.672] <TB3> INFO: Expecting 411648 events.
[15:43:42.934] <TB3> INFO: 411648 events read in total (8859ms).
[15:43:42.972] <TB3> INFO: Expecting 411648 events.
[15:43:52.317] <TB3> INFO: 411648 events read in total (8942ms).
[15:43:52.365] <TB3> INFO: Expecting 411648 events.
[15:44:01.539] <TB3> INFO: 411648 events read in total (8771ms).
[15:44:01.592] <TB3> INFO: Expecting 411648 events.
[15:44:10.850] <TB3> INFO: 411648 events read in total (8855ms).
[15:44:10.895] <TB3> INFO: Expecting 411648 events.
[15:44:20.186] <TB3> INFO: 411648 events read in total (8888ms).
[15:44:20.242] <TB3> INFO: Expecting 411648 events.
[15:44:29.582] <TB3> INFO: 411648 events read in total (8937ms).
[15:44:29.652] <TB3> INFO: Test took 150344ms.
[15:44:30.623] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[15:44:30.637] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:44:30.637] <TB3> INFO: run 1 of 1
[15:44:30.940] <TB3> INFO: Expecting 5025280 events.
[15:44:56.956] <TB3> INFO: 583248 events read in total (25424ms).
[15:45:22.946] <TB3> INFO: 1165560 events read in total (51414ms).
[15:45:48.513] <TB3> INFO: 1747528 events read in total (76982ms).
[15:46:14.786] <TB3> INFO: 2328480 events read in total (103254ms).
[15:46:41.234] <TB3> INFO: 2909560 events read in total (129702ms).
[15:47:07.218] <TB3> INFO: 3490632 events read in total (155686ms).
[15:47:32.888] <TB3> INFO: 4070512 events read in total (181356ms).
[15:47:58.925] <TB3> INFO: 4650584 events read in total (207393ms).
[15:48:16.531] <TB3> INFO: 5025280 events read in total (224999ms).
[15:48:16.705] <TB3> INFO: Test took 226069ms.
[15:48:42.184] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 4.980580 .. 135.014070
[15:48:42.499] <TB3> INFO: Expecting 208000 events.
[15:48:52.532] <TB3> INFO: 208000 events read in total (9442ms).
[15:48:52.533] <TB3> INFO: Test took 10347ms.
[15:48:52.580] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 4 .. 145 (-1/-1) hits flags = 528 (plus default)
[15:48:52.593] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:48:52.593] <TB3> INFO: run 1 of 1
[15:48:52.871] <TB3> INFO: Expecting 4725760 events.
[15:49:19.313] <TB3> INFO: 584136 events read in total (25850ms).
[15:49:44.886] <TB3> INFO: 1167760 events read in total (51423ms).
[15:50:10.316] <TB3> INFO: 1752232 events read in total (76853ms).
[15:50:36.492] <TB3> INFO: 2335984 events read in total (103029ms).
[15:51:02.544] <TB3> INFO: 2919600 events read in total (129081ms).
[15:51:27.785] <TB3> INFO: 3502160 events read in total (154322ms).
[15:51:53.444] <TB3> INFO: 4083808 events read in total (179981ms).
[15:52:18.698] <TB3> INFO: 4665376 events read in total (205235ms).
[15:52:21.702] <TB3> INFO: 4725760 events read in total (208239ms).
[15:52:21.958] <TB3> INFO: Test took 209365ms.
[15:52:49.321] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 26.950881 .. 42.780989
[15:52:49.607] <TB3> INFO: Expecting 208000 events.
[15:52:59.986] <TB3> INFO: 208000 events read in total (9787ms).
[15:52:59.987] <TB3> INFO: Test took 10664ms.
[15:53:00.033] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 52 (-1/-1) hits flags = 528 (plus default)
[15:53:00.046] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:53:00.046] <TB3> INFO: run 1 of 1
[15:53:00.325] <TB3> INFO: Expecting 1231360 events.
[15:53:29.465] <TB3> INFO: 676304 events read in total (28549ms).
[15:53:52.328] <TB3> INFO: 1231360 events read in total (51412ms).
[15:53:52.358] <TB3> INFO: Test took 52312ms.
[15:54:05.918] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 23.707130 .. 43.989274
[15:54:06.155] <TB3> INFO: Expecting 208000 events.
[15:54:16.274] <TB3> INFO: 208000 events read in total (9527ms).
[15:54:16.275] <TB3> INFO: Test took 10356ms.
[15:54:16.322] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 13 .. 53 (-1/-1) hits flags = 528 (plus default)
[15:54:16.335] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:54:16.335] <TB3> INFO: run 1 of 1
[15:54:16.613] <TB3> INFO: Expecting 1364480 events.
[15:54:46.744] <TB3> INFO: 683760 events read in total (29539ms).
[15:55:14.966] <TB3> INFO: 1364480 events read in total (57761ms).
[15:55:14.996] <TB3> INFO: Test took 58661ms.
[15:55:28.917] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 23.701273 .. 41.954794
[15:55:29.155] <TB3> INFO: Expecting 208000 events.
[15:55:38.997] <TB3> INFO: 208000 events read in total (9250ms).
[15:55:38.997] <TB3> INFO: Test took 10078ms.
[15:55:39.067] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 13 .. 51 (-1/-1) hits flags = 528 (plus default)
[15:55:39.084] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:55:39.084] <TB3> INFO: run 1 of 1
[15:55:39.365] <TB3> INFO: Expecting 1297920 events.
[15:56:07.809] <TB3> INFO: 694808 events read in total (27852ms).
[15:56:32.239] <TB3> INFO: 1297920 events read in total (52283ms).
[15:56:32.272] <TB3> INFO: Test took 53188ms.
[15:56:45.941] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[15:56:45.941] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[15:56:45.953] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[15:56:45.953] <TB3> INFO: run 1 of 1
[15:56:46.234] <TB3> INFO: Expecting 1364480 events.
[15:57:14.373] <TB3> INFO: 666912 events read in total (27547ms).
[15:57:41.879] <TB3> INFO: 1333504 events read in total (55053ms).
[15:57:43.556] <TB3> INFO: 1364480 events read in total (56730ms).
[15:57:43.581] <TB3> INFO: Test took 57627ms.
[15:57:58.831] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C0.dat
[15:57:58.831] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C1.dat
[15:57:58.831] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C2.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C3.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C4.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C5.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C6.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C7.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C8.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C9.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C10.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C11.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C12.dat
[15:57:58.832] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C13.dat
[15:57:58.833] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C14.dat
[15:57:58.833] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C15.dat
[15:57:58.833] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C0.dat
[15:57:58.840] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C1.dat
[15:57:58.847] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C2.dat
[15:57:58.854] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C3.dat
[15:57:58.861] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C4.dat
[15:57:58.868] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C5.dat
[15:57:58.875] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C6.dat
[15:57:58.882] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C7.dat
[15:57:58.889] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C8.dat
[15:57:58.896] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C9.dat
[15:57:58.903] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C10.dat
[15:57:58.910] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C11.dat
[15:57:58.917] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C12.dat
[15:57:58.924] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C13.dat
[15:57:58.931] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C14.dat
[15:57:58.938] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//trimParameters35_C15.dat
[15:57:58.945] <TB3> INFO: PixTestTrim::trimTest() done
[15:57:58.945] <TB3> INFO: vtrim: 140 154 135 134 119 130 148 124 145 129 147 119 118 133 140 130
[15:57:58.945] <TB3> INFO: vthrcomp: 126 133 110 121 119 120 113 127 120 119 130 119 118 131 128 114
[15:57:58.945] <TB3> INFO: vcal mean: 34.94 34.98 35.00 34.97 34.88 34.98 34.94 34.94 35.00 34.96 34.96 34.85 34.99 34.97 34.98 34.94
[15:57:58.945] <TB3> INFO: vcal RMS: 1.08 0.98 0.99 1.01 0.96 0.96 1.09 1.06 0.93 1.00 1.07 0.99 0.97 1.00 0.95 0.98
[15:57:58.945] <TB3> INFO: bits mean: 9.48 8.84 8.96 9.84 9.79 9.84 9.93 9.94 10.08 9.92 9.48 9.88 9.61 10.01 9.50 9.91
[15:57:58.945] <TB3> INFO: bits RMS: 2.72 2.49 2.47 2.63 2.68 2.55 2.56 2.87 2.52 2.64 2.81 2.64 2.76 2.59 2.63 2.58
[15:57:58.953] <TB3> INFO: ----------------------------------------------------------------------
[15:57:58.953] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[15:57:58.953] <TB3> INFO: ----------------------------------------------------------------------
[15:57:58.956] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[15:57:58.969] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[15:57:58.969] <TB3> INFO: run 1 of 1
[15:57:59.293] <TB3> INFO: Expecting 4160000 events.
[15:58:31.462] <TB3> INFO: 735130 events read in total (31577ms).
[15:59:02.932] <TB3> INFO: 1464315 events read in total (63047ms).
[15:59:34.438] <TB3> INFO: 2188710 events read in total (94553ms).
[16:00:05.743] <TB3> INFO: 2908635 events read in total (125858ms).
[16:00:36.788] <TB3> INFO: 3625180 events read in total (156903ms).
[16:01:00.350] <TB3> INFO: 4160000 events read in total (180465ms).
[16:01:00.423] <TB3> INFO: Test took 181455ms.
[16:01:26.822] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 192 (-1/-1) hits flags = 528 (plus default)
[16:01:26.835] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:01:26.835] <TB3> INFO: run 1 of 1
[16:01:27.071] <TB3> INFO: Expecting 4014400 events.
[16:01:59.097] <TB3> INFO: 720875 events read in total (31435ms).
[16:02:30.112] <TB3> INFO: 1435890 events read in total (62450ms).
[16:03:01.341] <TB3> INFO: 2146805 events read in total (93679ms).
[16:03:32.770] <TB3> INFO: 2853440 events read in total (125108ms).
[16:04:03.446] <TB3> INFO: 3556985 events read in total (155784ms).
[16:04:24.080] <TB3> INFO: 4014400 events read in total (176418ms).
[16:04:24.208] <TB3> INFO: Test took 177373ms.
[16:04:49.726] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 180 (-1/-1) hits flags = 528 (plus default)
[16:04:49.740] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:04:49.740] <TB3> INFO: run 1 of 1
[16:04:49.976] <TB3> INFO: Expecting 3764800 events.
[16:05:22.694] <TB3> INFO: 738355 events read in total (32126ms).
[16:05:54.371] <TB3> INFO: 1469635 events read in total (63803ms).
[16:06:26.085] <TB3> INFO: 2195750 events read in total (95517ms).
[16:06:57.913] <TB3> INFO: 2917160 events read in total (127345ms).
[16:07:29.221] <TB3> INFO: 3636980 events read in total (158653ms).
[16:07:34.002] <TB3> INFO: 3764800 events read in total (164434ms).
[16:07:35.067] <TB3> INFO: Test took 165327ms.
[16:08:00.155] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 181 (-1/-1) hits flags = 528 (plus default)
[16:08:00.168] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:08:00.168] <TB3> INFO: run 1 of 1
[16:08:00.405] <TB3> INFO: Expecting 3785600 events.
[16:08:33.189] <TB3> INFO: 737080 events read in total (32193ms).
[16:09:04.505] <TB3> INFO: 1467180 events read in total (63509ms).
[16:09:36.361] <TB3> INFO: 2192160 events read in total (95365ms).
[16:10:08.074] <TB3> INFO: 2912545 events read in total (127078ms).
[16:10:39.410] <TB3> INFO: 3630920 events read in total (158414ms).
[16:10:46.315] <TB3> INFO: 3785600 events read in total (165319ms).
[16:10:46.396] <TB3> INFO: Test took 166228ms.
[16:11:12.360] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 181 (-1/-1) hits flags = 528 (plus default)
[16:11:12.374] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:11:12.374] <TB3> INFO: run 1 of 1
[16:11:12.614] <TB3> INFO: Expecting 3785600 events.
[16:11:44.502] <TB3> INFO: 737215 events read in total (31296ms).
[16:12:16.294] <TB3> INFO: 1467500 events read in total (63088ms).
[16:12:47.983] <TB3> INFO: 2192500 events read in total (94777ms).
[16:13:19.549] <TB3> INFO: 2912780 events read in total (126343ms).
[16:13:51.044] <TB3> INFO: 3631375 events read in total (157838ms).
[16:13:57.811] <TB3> INFO: 3785600 events read in total (164605ms).
[16:13:57.907] <TB3> INFO: Test took 165532ms.
[16:14:22.304] <TB3> INFO: PixTestTrim::trimBitTest() done
[16:14:22.305] <TB3> INFO: PixTestTrim::doTest() done, duration: 2405 seconds
[16:14:22.305] <TB3> INFO: Decoding statistics:
[16:14:22.305] <TB3> INFO: General information:
[16:14:22.305] <TB3> INFO: 16bit words read: 0
[16:14:22.305] <TB3> INFO: valid events total: 0
[16:14:22.305] <TB3> INFO: empty events: 0
[16:14:22.305] <TB3> INFO: valid events with pixels: 0
[16:14:22.305] <TB3> INFO: valid pixel hits: 0
[16:14:22.305] <TB3> INFO: Event errors: 0
[16:14:22.305] <TB3> INFO: start marker: 0
[16:14:22.305] <TB3> INFO: stop marker: 0
[16:14:22.305] <TB3> INFO: overflow: 0
[16:14:22.305] <TB3> INFO: invalid 5bit words: 0
[16:14:22.305] <TB3> INFO: invalid XOR eye diagram: 0
[16:14:22.305] <TB3> INFO: frame (failed synchr.): 0
[16:14:22.305] <TB3> INFO: idle data (no TBM trl): 0
[16:14:22.305] <TB3> INFO: no data (only TBM hdr): 0
[16:14:22.305] <TB3> INFO: TBM errors: 0
[16:14:22.305] <TB3> INFO: flawed TBM headers: 0
[16:14:22.305] <TB3> INFO: flawed TBM trailers: 0
[16:14:22.305] <TB3> INFO: event ID mismatches: 0
[16:14:22.305] <TB3> INFO: ROC errors: 0
[16:14:22.305] <TB3> INFO: missing ROC header(s): 0
[16:14:22.305] <TB3> INFO: misplaced readback start: 0
[16:14:22.305] <TB3> INFO: Pixel decoding errors: 0
[16:14:22.305] <TB3> INFO: pixel data incomplete: 0
[16:14:22.305] <TB3> INFO: pixel address: 0
[16:14:22.305] <TB3> INFO: pulse height fill bit: 0
[16:14:22.305] <TB3> INFO: buffer corruption: 0
[16:14:22.912] <TB3> INFO: ######################################################################
[16:14:22.912] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[16:14:22.912] <TB3> INFO: ######################################################################
[16:14:23.154] <TB3> INFO: Expecting 41600 events.
[16:14:26.637] <TB3> INFO: 41600 events read in total (2891ms).
[16:14:26.638] <TB3> INFO: Test took 3725ms.
[16:14:27.085] <TB3> INFO: Expecting 41600 events.
[16:14:30.556] <TB3> INFO: 41600 events read in total (2879ms).
[16:14:30.557] <TB3> INFO: Test took 3713ms.
[16:14:30.849] <TB3> INFO: Expecting 41600 events.
[16:14:34.396] <TB3> INFO: 41600 events read in total (2955ms).
[16:14:34.397] <TB3> INFO: Test took 3813ms.
[16:14:34.696] <TB3> INFO: Expecting 41600 events.
[16:14:38.469] <TB3> INFO: 41600 events read in total (3182ms).
[16:14:38.470] <TB3> INFO: Test took 4049ms.
[16:14:38.761] <TB3> INFO: Expecting 41600 events.
[16:14:42.258] <TB3> INFO: 41600 events read in total (2905ms).
[16:14:42.258] <TB3> INFO: Test took 3761ms.
[16:14:42.552] <TB3> INFO: Expecting 41600 events.
[16:14:46.040] <TB3> INFO: 41600 events read in total (2896ms).
[16:14:46.041] <TB3> INFO: Test took 3759ms.
[16:14:46.331] <TB3> INFO: Expecting 41600 events.
[16:14:49.793] <TB3> INFO: 41600 events read in total (2870ms).
[16:14:49.794] <TB3> INFO: Test took 3728ms.
[16:14:50.082] <TB3> INFO: Expecting 41600 events.
[16:14:53.559] <TB3> INFO: 41600 events read in total (2885ms).
[16:14:53.560] <TB3> INFO: Test took 3742ms.
[16:14:53.850] <TB3> INFO: Expecting 41600 events.
[16:14:57.413] <TB3> INFO: 41600 events read in total (2972ms).
[16:14:57.415] <TB3> INFO: Test took 3830ms.
[16:14:57.709] <TB3> INFO: Expecting 41600 events.
[16:15:01.221] <TB3> INFO: 41600 events read in total (2921ms).
[16:15:01.221] <TB3> INFO: Test took 3777ms.
[16:15:01.510] <TB3> INFO: Expecting 41600 events.
[16:15:05.178] <TB3> INFO: 41600 events read in total (3076ms).
[16:15:05.179] <TB3> INFO: Test took 3934ms.
[16:15:05.469] <TB3> INFO: Expecting 41600 events.
[16:15:09.042] <TB3> INFO: 41600 events read in total (2982ms).
[16:15:09.043] <TB3> INFO: Test took 3839ms.
[16:15:09.342] <TB3> INFO: Expecting 41600 events.
[16:15:12.845] <TB3> INFO: 41600 events read in total (2911ms).
[16:15:12.846] <TB3> INFO: Test took 3779ms.
[16:15:13.151] <TB3> INFO: Expecting 41600 events.
[16:15:16.780] <TB3> INFO: 41600 events read in total (3038ms).
[16:15:16.781] <TB3> INFO: Test took 3911ms.
[16:15:17.075] <TB3> INFO: Expecting 41600 events.
[16:15:20.670] <TB3> INFO: 41600 events read in total (3004ms).
[16:15:20.671] <TB3> INFO: Test took 3865ms.
[16:15:20.963] <TB3> INFO: Expecting 41600 events.
[16:15:24.498] <TB3> INFO: 41600 events read in total (2943ms).
[16:15:24.500] <TB3> INFO: Test took 3801ms.
[16:15:24.805] <TB3> INFO: Expecting 41600 events.
[16:15:28.302] <TB3> INFO: 41600 events read in total (2905ms).
[16:15:28.303] <TB3> INFO: Test took 3778ms.
[16:15:28.592] <TB3> INFO: Expecting 41600 events.
[16:15:32.207] <TB3> INFO: 41600 events read in total (3023ms).
[16:15:32.208] <TB3> INFO: Test took 3881ms.
[16:15:32.548] <TB3> INFO: Expecting 41600 events.
[16:15:36.036] <TB3> INFO: 41600 events read in total (2896ms).
[16:15:36.037] <TB3> INFO: Test took 3801ms.
[16:15:36.326] <TB3> INFO: Expecting 41600 events.
[16:15:39.851] <TB3> INFO: 41600 events read in total (2933ms).
[16:15:39.852] <TB3> INFO: Test took 3791ms.
[16:15:40.184] <TB3> INFO: Expecting 41600 events.
[16:15:43.754] <TB3> INFO: 41600 events read in total (2979ms).
[16:15:43.755] <TB3> INFO: Test took 3876ms.
[16:15:44.047] <TB3> INFO: Expecting 41600 events.
[16:15:47.588] <TB3> INFO: 41600 events read in total (2950ms).
[16:15:47.589] <TB3> INFO: Test took 3807ms.
[16:15:47.879] <TB3> INFO: Expecting 41600 events.
[16:15:51.373] <TB3> INFO: 41600 events read in total (2903ms).
[16:15:51.374] <TB3> INFO: Test took 3760ms.
[16:15:51.703] <TB3> INFO: Expecting 41600 events.
[16:15:55.179] <TB3> INFO: 41600 events read in total (2885ms).
[16:15:55.180] <TB3> INFO: Test took 3782ms.
[16:15:55.483] <TB3> INFO: Expecting 41600 events.
[16:15:59.011] <TB3> INFO: 41600 events read in total (2937ms).
[16:15:59.012] <TB3> INFO: Test took 3808ms.
[16:15:59.301] <TB3> INFO: Expecting 41600 events.
[16:16:02.826] <TB3> INFO: 41600 events read in total (2933ms).
[16:16:02.827] <TB3> INFO: Test took 3791ms.
[16:16:03.116] <TB3> INFO: Expecting 41600 events.
[16:16:06.604] <TB3> INFO: 41600 events read in total (2896ms).
[16:16:06.605] <TB3> INFO: Test took 3754ms.
[16:16:06.894] <TB3> INFO: Expecting 41600 events.
[16:16:10.391] <TB3> INFO: 41600 events read in total (2906ms).
[16:16:10.392] <TB3> INFO: Test took 3763ms.
[16:16:10.681] <TB3> INFO: Expecting 41600 events.
[16:16:14.240] <TB3> INFO: 41600 events read in total (2968ms).
[16:16:14.240] <TB3> INFO: Test took 3824ms.
[16:16:14.529] <TB3> INFO: Expecting 41600 events.
[16:16:18.008] <TB3> INFO: 41600 events read in total (2887ms).
[16:16:18.009] <TB3> INFO: Test took 3745ms.
[16:16:18.299] <TB3> INFO: Expecting 41600 events.
[16:16:21.847] <TB3> INFO: 41600 events read in total (2956ms).
[16:16:21.847] <TB3> INFO: Test took 3813ms.
[16:16:22.136] <TB3> INFO: Expecting 2560 events.
[16:16:23.026] <TB3> INFO: 2560 events read in total (298ms).
[16:16:23.026] <TB3> INFO: Test took 1166ms.
[16:16:23.334] <TB3> INFO: Expecting 2560 events.
[16:16:24.220] <TB3> INFO: 2560 events read in total (294ms).
[16:16:24.221] <TB3> INFO: Test took 1194ms.
[16:16:24.527] <TB3> INFO: Expecting 2560 events.
[16:16:25.412] <TB3> INFO: 2560 events read in total (293ms).
[16:16:25.412] <TB3> INFO: Test took 1191ms.
[16:16:25.720] <TB3> INFO: Expecting 2560 events.
[16:16:26.607] <TB3> INFO: 2560 events read in total (295ms).
[16:16:26.607] <TB3> INFO: Test took 1194ms.
[16:16:26.913] <TB3> INFO: Expecting 2560 events.
[16:16:27.800] <TB3> INFO: 2560 events read in total (295ms).
[16:16:27.800] <TB3> INFO: Test took 1192ms.
[16:16:28.109] <TB3> INFO: Expecting 2560 events.
[16:16:28.989] <TB3> INFO: 2560 events read in total (288ms).
[16:16:28.989] <TB3> INFO: Test took 1188ms.
[16:16:29.297] <TB3> INFO: Expecting 2560 events.
[16:16:30.182] <TB3> INFO: 2560 events read in total (293ms).
[16:16:30.183] <TB3> INFO: Test took 1194ms.
[16:16:30.491] <TB3> INFO: Expecting 2560 events.
[16:16:31.378] <TB3> INFO: 2560 events read in total (295ms).
[16:16:31.379] <TB3> INFO: Test took 1195ms.
[16:16:31.685] <TB3> INFO: Expecting 2560 events.
[16:16:32.572] <TB3> INFO: 2560 events read in total (295ms).
[16:16:32.573] <TB3> INFO: Test took 1194ms.
[16:16:32.881] <TB3> INFO: Expecting 2560 events.
[16:16:33.767] <TB3> INFO: 2560 events read in total (295ms).
[16:16:33.767] <TB3> INFO: Test took 1193ms.
[16:16:34.075] <TB3> INFO: Expecting 2560 events.
[16:16:34.965] <TB3> INFO: 2560 events read in total (298ms).
[16:16:34.965] <TB3> INFO: Test took 1198ms.
[16:16:35.273] <TB3> INFO: Expecting 2560 events.
[16:16:36.150] <TB3> INFO: 2560 events read in total (286ms).
[16:16:36.151] <TB3> INFO: Test took 1185ms.
[16:16:36.459] <TB3> INFO: Expecting 2560 events.
[16:16:37.345] <TB3> INFO: 2560 events read in total (294ms).
[16:16:37.345] <TB3> INFO: Test took 1194ms.
[16:16:37.654] <TB3> INFO: Expecting 2560 events.
[16:16:38.548] <TB3> INFO: 2560 events read in total (303ms).
[16:16:38.549] <TB3> INFO: Test took 1204ms.
[16:16:38.856] <TB3> INFO: Expecting 2560 events.
[16:16:39.747] <TB3> INFO: 2560 events read in total (299ms).
[16:16:39.747] <TB3> INFO: Test took 1198ms.
[16:16:40.056] <TB3> INFO: Expecting 2560 events.
[16:16:40.949] <TB3> INFO: 2560 events read in total (301ms).
[16:16:40.949] <TB3> INFO: Test took 1201ms.
[16:16:40.952] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:16:41.259] <TB3> INFO: Expecting 655360 events.
[16:16:56.072] <TB3> INFO: 655360 events read in total (14221ms).
[16:16:56.084] <TB3> INFO: Expecting 655360 events.
[16:17:10.829] <TB3> INFO: 655360 events read in total (14342ms).
[16:17:10.845] <TB3> INFO: Expecting 655360 events.
[16:17:25.426] <TB3> INFO: 655360 events read in total (14178ms).
[16:17:25.450] <TB3> INFO: Expecting 655360 events.
[16:17:40.190] <TB3> INFO: 655360 events read in total (14337ms).
[16:17:40.222] <TB3> INFO: Expecting 655360 events.
[16:17:54.745] <TB3> INFO: 655360 events read in total (14120ms).
[16:17:54.775] <TB3> INFO: Expecting 655360 events.
[16:18:09.332] <TB3> INFO: 655360 events read in total (14154ms).
[16:18:09.365] <TB3> INFO: Expecting 655360 events.
[16:18:23.965] <TB3> INFO: 655360 events read in total (14197ms).
[16:18:24.018] <TB3> INFO: Expecting 655360 events.
[16:18:38.509] <TB3> INFO: 655360 events read in total (14087ms).
[16:18:38.556] <TB3> INFO: Expecting 655360 events.
[16:18:53.047] <TB3> INFO: 655360 events read in total (14088ms).
[16:18:53.103] <TB3> INFO: Expecting 655360 events.
[16:19:07.651] <TB3> INFO: 655360 events read in total (14145ms).
[16:19:07.702] <TB3> INFO: Expecting 655360 events.
[16:19:22.151] <TB3> INFO: 655360 events read in total (14045ms).
[16:19:22.306] <TB3> INFO: Expecting 655360 events.
[16:19:36.721] <TB3> INFO: 655360 events read in total (14012ms).
[16:19:36.794] <TB3> INFO: Expecting 655360 events.
[16:19:51.403] <TB3> INFO: 655360 events read in total (14206ms).
[16:19:51.482] <TB3> INFO: Expecting 655360 events.
[16:20:05.982] <TB3> INFO: 655360 events read in total (14097ms).
[16:20:06.177] <TB3> INFO: Expecting 655360 events.
[16:20:20.707] <TB3> INFO: 655360 events read in total (14127ms).
[16:20:20.798] <TB3> INFO: Expecting 655360 events.
[16:20:35.259] <TB3> INFO: 655360 events read in total (14058ms).
[16:20:35.479] <TB3> INFO: Test took 234527ms.
[16:20:35.573] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:20:35.831] <TB3> INFO: Expecting 655360 events.
[16:20:50.391] <TB3> INFO: 655360 events read in total (13968ms).
[16:20:50.405] <TB3> INFO: Expecting 655360 events.
[16:21:05.056] <TB3> INFO: 655360 events read in total (14248ms).
[16:21:05.072] <TB3> INFO: Expecting 655360 events.
[16:21:19.830] <TB3> INFO: 655360 events read in total (14355ms).
[16:21:19.851] <TB3> INFO: Expecting 655360 events.
[16:21:34.294] <TB3> INFO: 655360 events read in total (14040ms).
[16:21:34.320] <TB3> INFO: Expecting 655360 events.
[16:21:48.986] <TB3> INFO: 655360 events read in total (14263ms).
[16:21:49.015] <TB3> INFO: Expecting 655360 events.
[16:22:03.484] <TB3> INFO: 655360 events read in total (14066ms).
[16:22:03.518] <TB3> INFO: Expecting 655360 events.
[16:22:17.961] <TB3> INFO: 655360 events read in total (14040ms).
[16:22:17.998] <TB3> INFO: Expecting 655360 events.
[16:22:32.404] <TB3> INFO: 655360 events read in total (14003ms).
[16:22:32.447] <TB3> INFO: Expecting 655360 events.
[16:22:46.837] <TB3> INFO: 655360 events read in total (13986ms).
[16:22:46.884] <TB3> INFO: Expecting 655360 events.
[16:23:01.409] <TB3> INFO: 655360 events read in total (14122ms).
[16:23:01.459] <TB3> INFO: Expecting 655360 events.
[16:23:15.994] <TB3> INFO: 655360 events read in total (14132ms).
[16:23:16.060] <TB3> INFO: Expecting 655360 events.
[16:23:30.776] <TB3> INFO: 655360 events read in total (14313ms).
[16:23:30.850] <TB3> INFO: Expecting 655360 events.
[16:23:45.388] <TB3> INFO: 655360 events read in total (14135ms).
[16:23:45.594] <TB3> INFO: Expecting 655360 events.
[16:24:00.093] <TB3> INFO: 655360 events read in total (14096ms).
[16:24:00.178] <TB3> INFO: Expecting 655360 events.
[16:24:15.005] <TB3> INFO: 655360 events read in total (14424ms).
[16:24:15.297] <TB3> INFO: Expecting 655360 events.
[16:24:29.841] <TB3> INFO: 655360 events read in total (14140ms).
[16:24:29.937] <TB3> INFO: Test took 234364ms.
[16:24:30.106] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.112] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.118] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.124] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.130] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[16:24:30.136] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[16:24:30.141] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[16:24:30.147] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[16:24:30.155] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.165] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.176] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.187] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.197] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[16:24:30.203] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.209] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.215] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.221] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.227] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.237] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.248] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.259] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[16:24:30.297] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C0.dat
[16:24:30.297] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C1.dat
[16:24:30.298] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C2.dat
[16:24:30.298] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C3.dat
[16:24:30.298] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C4.dat
[16:24:30.298] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C5.dat
[16:24:30.298] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C6.dat
[16:24:30.298] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C7.dat
[16:24:30.299] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C8.dat
[16:24:30.299] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C9.dat
[16:24:30.299] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C10.dat
[16:24:30.299] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C11.dat
[16:24:30.299] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C12.dat
[16:24:30.299] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C13.dat
[16:24:30.300] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C14.dat
[16:24:30.300] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//dacParameters35_C15.dat
[16:24:30.543] <TB3> INFO: Expecting 41600 events.
[16:24:33.682] <TB3> INFO: 41600 events read in total (2547ms).
[16:24:33.683] <TB3> INFO: Test took 3380ms.
[16:24:34.135] <TB3> INFO: Expecting 41600 events.
[16:24:37.262] <TB3> INFO: 41600 events read in total (2535ms).
[16:24:37.263] <TB3> INFO: Test took 3368ms.
[16:24:37.712] <TB3> INFO: Expecting 41600 events.
[16:24:40.839] <TB3> INFO: 41600 events read in total (2535ms).
[16:24:40.840] <TB3> INFO: Test took 3366ms.
[16:24:41.060] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:41.149] <TB3> INFO: Expecting 2560 events.
[16:24:42.034] <TB3> INFO: 2560 events read in total (293ms).
[16:24:42.034] <TB3> INFO: Test took 974ms.
[16:24:42.037] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:42.342] <TB3> INFO: Expecting 2560 events.
[16:24:43.231] <TB3> INFO: 2560 events read in total (297ms).
[16:24:43.231] <TB3> INFO: Test took 1194ms.
[16:24:43.234] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:43.540] <TB3> INFO: Expecting 2560 events.
[16:24:44.435] <TB3> INFO: 2560 events read in total (305ms).
[16:24:44.436] <TB3> INFO: Test took 1202ms.
[16:24:44.439] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:44.744] <TB3> INFO: Expecting 2560 events.
[16:24:45.630] <TB3> INFO: 2560 events read in total (295ms).
[16:24:45.630] <TB3> INFO: Test took 1191ms.
[16:24:45.632] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:45.939] <TB3> INFO: Expecting 2560 events.
[16:24:46.826] <TB3> INFO: 2560 events read in total (295ms).
[16:24:46.827] <TB3> INFO: Test took 1195ms.
[16:24:46.829] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:47.136] <TB3> INFO: Expecting 2560 events.
[16:24:48.020] <TB3> INFO: 2560 events read in total (293ms).
[16:24:48.020] <TB3> INFO: Test took 1191ms.
[16:24:48.022] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:48.329] <TB3> INFO: Expecting 2560 events.
[16:24:49.218] <TB3> INFO: 2560 events read in total (297ms).
[16:24:49.218] <TB3> INFO: Test took 1196ms.
[16:24:49.220] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:49.527] <TB3> INFO: Expecting 2560 events.
[16:24:50.420] <TB3> INFO: 2560 events read in total (302ms).
[16:24:50.421] <TB3> INFO: Test took 1201ms.
[16:24:50.425] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:50.728] <TB3> INFO: Expecting 2560 events.
[16:24:51.608] <TB3> INFO: 2560 events read in total (288ms).
[16:24:51.608] <TB3> INFO: Test took 1183ms.
[16:24:51.610] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:51.916] <TB3> INFO: Expecting 2560 events.
[16:24:52.796] <TB3> INFO: 2560 events read in total (288ms).
[16:24:52.796] <TB3> INFO: Test took 1187ms.
[16:24:52.800] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:53.105] <TB3> INFO: Expecting 2560 events.
[16:24:53.992] <TB3> INFO: 2560 events read in total (296ms).
[16:24:53.993] <TB3> INFO: Test took 1194ms.
[16:24:53.996] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:54.301] <TB3> INFO: Expecting 2560 events.
[16:24:55.183] <TB3> INFO: 2560 events read in total (291ms).
[16:24:55.183] <TB3> INFO: Test took 1187ms.
[16:24:55.186] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:55.492] <TB3> INFO: Expecting 2560 events.
[16:24:56.384] <TB3> INFO: 2560 events read in total (300ms).
[16:24:56.385] <TB3> INFO: Test took 1200ms.
[16:24:56.389] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:56.692] <TB3> INFO: Expecting 2560 events.
[16:24:57.575] <TB3> INFO: 2560 events read in total (291ms).
[16:24:57.576] <TB3> INFO: Test took 1187ms.
[16:24:57.579] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:57.883] <TB3> INFO: Expecting 2560 events.
[16:24:58.769] <TB3> INFO: 2560 events read in total (294ms).
[16:24:58.770] <TB3> INFO: Test took 1191ms.
[16:24:58.772] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:24:59.078] <TB3> INFO: Expecting 2560 events.
[16:24:59.966] <TB3> INFO: 2560 events read in total (296ms).
[16:24:59.966] <TB3> INFO: Test took 1194ms.
[16:24:59.968] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:00.275] <TB3> INFO: Expecting 2560 events.
[16:25:01.162] <TB3> INFO: 2560 events read in total (295ms).
[16:25:01.162] <TB3> INFO: Test took 1194ms.
[16:25:01.164] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:01.471] <TB3> INFO: Expecting 2560 events.
[16:25:02.355] <TB3> INFO: 2560 events read in total (293ms).
[16:25:02.356] <TB3> INFO: Test took 1192ms.
[16:25:02.358] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:02.665] <TB3> INFO: Expecting 2560 events.
[16:25:03.554] <TB3> INFO: 2560 events read in total (298ms).
[16:25:03.554] <TB3> INFO: Test took 1196ms.
[16:25:03.558] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:03.862] <TB3> INFO: Expecting 2560 events.
[16:25:04.744] <TB3> INFO: 2560 events read in total (290ms).
[16:25:04.745] <TB3> INFO: Test took 1188ms.
[16:25:04.747] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:05.054] <TB3> INFO: Expecting 2560 events.
[16:25:05.943] <TB3> INFO: 2560 events read in total (297ms).
[16:25:05.943] <TB3> INFO: Test took 1196ms.
[16:25:05.947] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:06.251] <TB3> INFO: Expecting 2560 events.
[16:25:07.139] <TB3> INFO: 2560 events read in total (296ms).
[16:25:07.139] <TB3> INFO: Test took 1192ms.
[16:25:07.141] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:07.448] <TB3> INFO: Expecting 2560 events.
[16:25:08.330] <TB3> INFO: 2560 events read in total (291ms).
[16:25:08.331] <TB3> INFO: Test took 1190ms.
[16:25:08.333] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:08.640] <TB3> INFO: Expecting 2560 events.
[16:25:09.529] <TB3> INFO: 2560 events read in total (298ms).
[16:25:09.529] <TB3> INFO: Test took 1196ms.
[16:25:09.531] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:09.839] <TB3> INFO: Expecting 2560 events.
[16:25:10.737] <TB3> INFO: 2560 events read in total (306ms).
[16:25:10.737] <TB3> INFO: Test took 1206ms.
[16:25:10.742] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:11.046] <TB3> INFO: Expecting 2560 events.
[16:25:11.939] <TB3> INFO: 2560 events read in total (302ms).
[16:25:11.939] <TB3> INFO: Test took 1198ms.
[16:25:11.942] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:12.248] <TB3> INFO: Expecting 2560 events.
[16:25:13.144] <TB3> INFO: 2560 events read in total (304ms).
[16:25:13.144] <TB3> INFO: Test took 1203ms.
[16:25:13.147] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:13.453] <TB3> INFO: Expecting 2560 events.
[16:25:14.346] <TB3> INFO: 2560 events read in total (301ms).
[16:25:14.347] <TB3> INFO: Test took 1200ms.
[16:25:14.350] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:14.655] <TB3> INFO: Expecting 2560 events.
[16:25:15.546] <TB3> INFO: 2560 events read in total (299ms).
[16:25:15.546] <TB3> INFO: Test took 1196ms.
[16:25:15.549] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:15.856] <TB3> INFO: Expecting 2560 events.
[16:25:16.743] <TB3> INFO: 2560 events read in total (295ms).
[16:25:16.743] <TB3> INFO: Test took 1195ms.
[16:25:16.747] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:17.051] <TB3> INFO: Expecting 2560 events.
[16:25:17.944] <TB3> INFO: 2560 events read in total (301ms).
[16:25:17.945] <TB3> INFO: Test took 1198ms.
[16:25:17.948] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:25:18.253] <TB3> INFO: Expecting 2560 events.
[16:25:19.142] <TB3> INFO: 2560 events read in total (297ms).
[16:25:19.143] <TB3> INFO: Test took 1195ms.
[16:25:19.616] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 656 seconds
[16:25:19.616] <TB3> INFO: PH scale (per ROC): 59 68 75 49 47 45 65 49 63 64 50 57 64 58 57 45
[16:25:19.616] <TB3> INFO: PH offset (per ROC): 131 124 127 96 100 92 111 105 106 130 100 112 129 116 130 95
[16:25:19.626] <TB3> INFO: Decoding statistics:
[16:25:19.626] <TB3> INFO: General information:
[16:25:19.626] <TB3> INFO: 16bit words read: 127896
[16:25:19.626] <TB3> INFO: valid events total: 20480
[16:25:19.626] <TB3> INFO: empty events: 17972
[16:25:19.626] <TB3> INFO: valid events with pixels: 2508
[16:25:19.626] <TB3> INFO: valid pixel hits: 2508
[16:25:19.626] <TB3> INFO: Event errors: 0
[16:25:19.626] <TB3> INFO: start marker: 0
[16:25:19.626] <TB3> INFO: stop marker: 0
[16:25:19.626] <TB3> INFO: overflow: 0
[16:25:19.626] <TB3> INFO: invalid 5bit words: 0
[16:25:19.626] <TB3> INFO: invalid XOR eye diagram: 0
[16:25:19.626] <TB3> INFO: frame (failed synchr.): 0
[16:25:19.626] <TB3> INFO: idle data (no TBM trl): 0
[16:25:19.626] <TB3> INFO: no data (only TBM hdr): 0
[16:25:19.626] <TB3> INFO: TBM errors: 0
[16:25:19.626] <TB3> INFO: flawed TBM headers: 0
[16:25:19.626] <TB3> INFO: flawed TBM trailers: 0
[16:25:19.626] <TB3> INFO: event ID mismatches: 0
[16:25:19.626] <TB3> INFO: ROC errors: 0
[16:25:19.626] <TB3> INFO: missing ROC header(s): 0
[16:25:19.626] <TB3> INFO: misplaced readback start: 0
[16:25:19.626] <TB3> INFO: Pixel decoding errors: 0
[16:25:19.626] <TB3> INFO: pixel data incomplete: 0
[16:25:19.626] <TB3> INFO: pixel address: 0
[16:25:19.626] <TB3> INFO: pulse height fill bit: 0
[16:25:19.626] <TB3> INFO: buffer corruption: 0
[16:25:19.784] <TB3> INFO: ######################################################################
[16:25:19.784] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[16:25:19.784] <TB3> INFO: ######################################################################
[16:25:19.798] <TB3> INFO: scanning low vcal = 10
[16:25:20.048] <TB3> INFO: Expecting 41600 events.
[16:25:23.634] <TB3> INFO: 41600 events read in total (2994ms).
[16:25:23.635] <TB3> INFO: Test took 3837ms.
[16:25:23.636] <TB3> INFO: scanning low vcal = 20
[16:25:23.933] <TB3> INFO: Expecting 41600 events.
[16:25:27.554] <TB3> INFO: 41600 events read in total (3029ms).
[16:25:27.555] <TB3> INFO: Test took 3918ms.
[16:25:27.557] <TB3> INFO: scanning low vcal = 30
[16:25:27.852] <TB3> INFO: Expecting 41600 events.
[16:25:31.508] <TB3> INFO: 41600 events read in total (3064ms).
[16:25:31.508] <TB3> INFO: Test took 3951ms.
[16:25:31.511] <TB3> INFO: scanning low vcal = 40
[16:25:31.788] <TB3> INFO: Expecting 41600 events.
[16:25:35.766] <TB3> INFO: 41600 events read in total (3387ms).
[16:25:35.767] <TB3> INFO: Test took 4257ms.
[16:25:35.770] <TB3> INFO: scanning low vcal = 50
[16:25:36.048] <TB3> INFO: Expecting 41600 events.
[16:25:40.039] <TB3> INFO: 41600 events read in total (3399ms).
[16:25:40.040] <TB3> INFO: Test took 4269ms.
[16:25:40.043] <TB3> INFO: scanning low vcal = 60
[16:25:40.320] <TB3> INFO: Expecting 41600 events.
[16:25:44.359] <TB3> INFO: 41600 events read in total (3447ms).
[16:25:44.359] <TB3> INFO: Test took 4316ms.
[16:25:44.362] <TB3> INFO: scanning low vcal = 70
[16:25:44.640] <TB3> INFO: Expecting 41600 events.
[16:25:48.626] <TB3> INFO: 41600 events read in total (3395ms).
[16:25:48.626] <TB3> INFO: Test took 4264ms.
[16:25:48.630] <TB3> INFO: scanning low vcal = 80
[16:25:48.906] <TB3> INFO: Expecting 41600 events.
[16:25:52.916] <TB3> INFO: 41600 events read in total (3418ms).
[16:25:52.916] <TB3> INFO: Test took 4286ms.
[16:25:52.919] <TB3> INFO: scanning low vcal = 90
[16:25:53.197] <TB3> INFO: Expecting 41600 events.
[16:25:57.244] <TB3> INFO: 41600 events read in total (3455ms).
[16:25:57.245] <TB3> INFO: Test took 4326ms.
[16:25:57.249] <TB3> INFO: scanning low vcal = 100
[16:25:57.525] <TB3> INFO: Expecting 41600 events.
[16:26:01.535] <TB3> INFO: 41600 events read in total (3418ms).
[16:26:01.536] <TB3> INFO: Test took 4287ms.
[16:26:01.539] <TB3> INFO: scanning low vcal = 110
[16:26:01.816] <TB3> INFO: Expecting 41600 events.
[16:26:05.807] <TB3> INFO: 41600 events read in total (3400ms).
[16:26:05.808] <TB3> INFO: Test took 4269ms.
[16:26:05.811] <TB3> INFO: scanning low vcal = 120
[16:26:06.088] <TB3> INFO: Expecting 41600 events.
[16:26:10.072] <TB3> INFO: 41600 events read in total (3392ms).
[16:26:10.073] <TB3> INFO: Test took 4261ms.
[16:26:10.076] <TB3> INFO: scanning low vcal = 130
[16:26:10.369] <TB3> INFO: Expecting 41600 events.
[16:26:14.389] <TB3> INFO: 41600 events read in total (3429ms).
[16:26:14.390] <TB3> INFO: Test took 4314ms.
[16:26:14.393] <TB3> INFO: scanning low vcal = 140
[16:26:14.670] <TB3> INFO: Expecting 41600 events.
[16:26:18.679] <TB3> INFO: 41600 events read in total (3417ms).
[16:26:18.679] <TB3> INFO: Test took 4286ms.
[16:26:18.682] <TB3> INFO: scanning low vcal = 150
[16:26:18.960] <TB3> INFO: Expecting 41600 events.
[16:26:22.973] <TB3> INFO: 41600 events read in total (3422ms).
[16:26:22.975] <TB3> INFO: Test took 4293ms.
[16:26:22.978] <TB3> INFO: scanning low vcal = 160
[16:26:23.255] <TB3> INFO: Expecting 41600 events.
[16:26:27.300] <TB3> INFO: 41600 events read in total (3453ms).
[16:26:27.300] <TB3> INFO: Test took 4321ms.
[16:26:27.303] <TB3> INFO: scanning low vcal = 170
[16:26:27.581] <TB3> INFO: Expecting 41600 events.
[16:26:31.600] <TB3> INFO: 41600 events read in total (3428ms).
[16:26:31.600] <TB3> INFO: Test took 4297ms.
[16:26:31.605] <TB3> INFO: scanning low vcal = 180
[16:26:31.881] <TB3> INFO: Expecting 41600 events.
[16:26:35.927] <TB3> INFO: 41600 events read in total (3454ms).
[16:26:35.928] <TB3> INFO: Test took 4323ms.
[16:26:35.931] <TB3> INFO: scanning low vcal = 190
[16:26:36.208] <TB3> INFO: Expecting 41600 events.
[16:26:40.220] <TB3> INFO: 41600 events read in total (3420ms).
[16:26:40.221] <TB3> INFO: Test took 4290ms.
[16:26:40.224] <TB3> INFO: scanning low vcal = 200
[16:26:40.502] <TB3> INFO: Expecting 41600 events.
[16:26:44.538] <TB3> INFO: 41600 events read in total (3445ms).
[16:26:44.539] <TB3> INFO: Test took 4315ms.
[16:26:44.541] <TB3> INFO: scanning low vcal = 210
[16:26:44.819] <TB3> INFO: Expecting 41600 events.
[16:26:48.846] <TB3> INFO: 41600 events read in total (3435ms).
[16:26:48.847] <TB3> INFO: Test took 4305ms.
[16:26:48.850] <TB3> INFO: scanning low vcal = 220
[16:26:49.127] <TB3> INFO: Expecting 41600 events.
[16:26:53.180] <TB3> INFO: 41600 events read in total (3461ms).
[16:26:53.181] <TB3> INFO: Test took 4331ms.
[16:26:53.184] <TB3> INFO: scanning low vcal = 230
[16:26:53.461] <TB3> INFO: Expecting 41600 events.
[16:26:57.403] <TB3> INFO: 41600 events read in total (3350ms).
[16:26:57.403] <TB3> INFO: Test took 4219ms.
[16:26:57.406] <TB3> INFO: scanning low vcal = 240
[16:26:57.683] <TB3> INFO: Expecting 41600 events.
[16:27:01.627] <TB3> INFO: 41600 events read in total (3353ms).
[16:27:01.628] <TB3> INFO: Test took 4222ms.
[16:27:01.632] <TB3> INFO: scanning low vcal = 250
[16:27:01.907] <TB3> INFO: Expecting 41600 events.
[16:27:05.849] <TB3> INFO: 41600 events read in total (3350ms).
[16:27:05.850] <TB3> INFO: Test took 4218ms.
[16:27:05.854] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[16:27:06.130] <TB3> INFO: Expecting 41600 events.
[16:27:10.079] <TB3> INFO: 41600 events read in total (3358ms).
[16:27:10.080] <TB3> INFO: Test took 4225ms.
[16:27:10.083] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[16:27:10.404] <TB3> INFO: Expecting 41600 events.
[16:27:14.330] <TB3> INFO: 41600 events read in total (3334ms).
[16:27:14.331] <TB3> INFO: Test took 4248ms.
[16:27:14.334] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[16:27:14.610] <TB3> INFO: Expecting 41600 events.
[16:27:18.541] <TB3> INFO: 41600 events read in total (3340ms).
[16:27:18.542] <TB3> INFO: Test took 4207ms.
[16:27:18.545] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[16:27:18.821] <TB3> INFO: Expecting 41600 events.
[16:27:22.752] <TB3> INFO: 41600 events read in total (3339ms).
[16:27:22.753] <TB3> INFO: Test took 4208ms.
[16:27:22.756] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[16:27:23.033] <TB3> INFO: Expecting 41600 events.
[16:27:26.964] <TB3> INFO: 41600 events read in total (3340ms).
[16:27:26.964] <TB3> INFO: Test took 4209ms.
[16:27:27.395] <TB3> INFO: PixTestGainPedestal::measure() done
[16:27:59.785] <TB3> INFO: PixTestGainPedestal::fit() done
[16:27:59.786] <TB3> INFO: non-linearity mean: 0.980 0.980 0.988 0.932 0.930 0.941 0.979 0.937 0.964 0.983 0.900 0.971 0.981 0.979 0.972 0.855
[16:27:59.786] <TB3> INFO: non-linearity RMS: 0.004 0.003 0.003 0.090 0.171 0.165 0.008 0.049 0.020 0.004 0.120 0.010 0.005 0.005 0.005 0.136
[16:27:59.786] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[16:27:59.800] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[16:27:59.813] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[16:27:59.826] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[16:27:59.840] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[16:27:59.853] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[16:27:59.867] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[16:27:59.880] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[16:27:59.893] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[16:27:59.906] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[16:27:59.919] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[16:27:59.932] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[16:27:59.945] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[16:27:59.958] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[16:27:59.972] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[16:27:59.985] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[16:27:59.998] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 160 seconds
[16:27:59.998] <TB3> INFO: Decoding statistics:
[16:27:59.998] <TB3> INFO: General information:
[16:27:59.998] <TB3> INFO: 16bit words read: 3327974
[16:27:59.998] <TB3> INFO: valid events total: 332800
[16:27:59.998] <TB3> INFO: empty events: 0
[16:27:59.998] <TB3> INFO: valid events with pixels: 332800
[16:27:59.998] <TB3> INFO: valid pixel hits: 665587
[16:27:59.998] <TB3> INFO: Event errors: 0
[16:27:59.998] <TB3> INFO: start marker: 0
[16:27:59.998] <TB3> INFO: stop marker: 0
[16:27:59.998] <TB3> INFO: overflow: 0
[16:27:59.998] <TB3> INFO: invalid 5bit words: 0
[16:27:59.998] <TB3> INFO: invalid XOR eye diagram: 0
[16:27:59.998] <TB3> INFO: frame (failed synchr.): 0
[16:27:59.998] <TB3> INFO: idle data (no TBM trl): 0
[16:27:59.998] <TB3> INFO: no data (only TBM hdr): 0
[16:27:59.998] <TB3> INFO: TBM errors: 0
[16:27:59.998] <TB3> INFO: flawed TBM headers: 0
[16:27:59.998] <TB3> INFO: flawed TBM trailers: 0
[16:27:59.998] <TB3> INFO: event ID mismatches: 0
[16:27:59.998] <TB3> INFO: ROC errors: 0
[16:27:59.998] <TB3> INFO: missing ROC header(s): 0
[16:27:59.998] <TB3> INFO: misplaced readback start: 0
[16:27:59.998] <TB3> INFO: Pixel decoding errors: 0
[16:27:59.998] <TB3> INFO: pixel data incomplete: 0
[16:27:59.998] <TB3> INFO: pixel address: 0
[16:27:59.998] <TB3> INFO: pulse height fill bit: 0
[16:27:59.998] <TB3> INFO: buffer corruption: 0
[16:28:00.014] <TB3> INFO: Decoding statistics:
[16:28:00.014] <TB3> INFO: General information:
[16:28:00.014] <TB3> INFO: 16bit words read: 3457428
[16:28:00.014] <TB3> INFO: valid events total: 353536
[16:28:00.014] <TB3> INFO: empty events: 18217
[16:28:00.014] <TB3> INFO: valid events with pixels: 335319
[16:28:00.014] <TB3> INFO: valid pixel hits: 668106
[16:28:00.014] <TB3> INFO: Event errors: 0
[16:28:00.014] <TB3> INFO: start marker: 0
[16:28:00.014] <TB3> INFO: stop marker: 0
[16:28:00.014] <TB3> INFO: overflow: 0
[16:28:00.014] <TB3> INFO: invalid 5bit words: 0
[16:28:00.014] <TB3> INFO: invalid XOR eye diagram: 0
[16:28:00.014] <TB3> INFO: frame (failed synchr.): 0
[16:28:00.014] <TB3> INFO: idle data (no TBM trl): 0
[16:28:00.014] <TB3> INFO: no data (only TBM hdr): 0
[16:28:00.014] <TB3> INFO: TBM errors: 0
[16:28:00.014] <TB3> INFO: flawed TBM headers: 0
[16:28:00.014] <TB3> INFO: flawed TBM trailers: 0
[16:28:00.014] <TB3> INFO: event ID mismatches: 0
[16:28:00.014] <TB3> INFO: ROC errors: 0
[16:28:00.014] <TB3> INFO: missing ROC header(s): 0
[16:28:00.014] <TB3> INFO: misplaced readback start: 0
[16:28:00.014] <TB3> INFO: Pixel decoding errors: 0
[16:28:00.014] <TB3> INFO: pixel data incomplete: 0
[16:28:00.014] <TB3> INFO: pixel address: 0
[16:28:00.014] <TB3> INFO: pulse height fill bit: 0
[16:28:00.014] <TB3> INFO: buffer corruption: 0
[16:28:00.014] <TB3> INFO: enter test to run
[16:28:00.014] <TB3> INFO: test: exit no parameter change
[16:28:00.129] <TB3> QUIET: Connection to board 126 closed.
[16:28:00.130] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud