Test Date: 2016-10-25 10:38
Analysis date: 2016-10-25 15:01
Logfile
LogfileView
[10:57:35.720] <TB0> INFO: *** Welcome to pxar ***
[10:57:35.720] <TB0> INFO: *** Today: 2016/10/25
[10:57:35.726] <TB0> INFO: *** Version: c8ba-dirty
[10:57:35.726] <TB0> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C15.dat
[10:57:35.726] <TB0> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//tbmParameters_C1b.dat
[10:57:35.727] <TB0> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//defaultMaskFile.dat
[10:57:35.727] <TB0> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters_C15.dat
[10:57:35.787] <TB0> INFO: clk: 4
[10:57:35.787] <TB0> INFO: ctr: 4
[10:57:35.787] <TB0> INFO: sda: 19
[10:57:35.787] <TB0> INFO: tin: 9
[10:57:35.787] <TB0> INFO: level: 15
[10:57:35.787] <TB0> INFO: triggerdelay: 0
[10:57:35.787] <TB0> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[10:57:35.787] <TB0> INFO: Log level: INFO
[10:57:35.796] <TB0> INFO: Found DTB DTB_WRQ4OZ
[10:57:35.807] <TB0> QUIET: Connection to board DTB_WRQ4OZ opened.
[10:57:35.809] <TB0> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 71
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WRQ4OZ
MAC address: 40D855118047
Hostname: pixelDTB071
Comment:
------------------------------------------------------
[10:57:35.811] <TB0> INFO: RPC call hashes of host and DTB match: 486171790
[10:57:37.299] <TB0> INFO: DUT info:
[10:57:37.299] <TB0> INFO: The DUT currently contains the following objects:
[10:57:37.299] <TB0> INFO: 4 TBM Cores tbm10c (4 ON)
[10:57:37.299] <TB0> INFO: TBM Core alpha (0): 7 registers set
[10:57:37.299] <TB0> INFO: TBM Core beta (1): 7 registers set
[10:57:37.299] <TB0> INFO: TBM Core alpha (2): 7 registers set
[10:57:37.299] <TB0> INFO: TBM Core beta (3): 7 registers set
[10:57:37.299] <TB0> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[10:57:37.299] <TB0> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.299] <TB0> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:57:37.700] <TB0> INFO: enter 'restricted' command line mode
[10:57:37.700] <TB0> INFO: enter test to run
[10:57:37.700] <TB0> INFO: test: pretest no parameter change
[10:57:37.700] <TB0> INFO: running: pretest
[10:57:37.704] <TB0> INFO: ######################################################################
[10:57:37.704] <TB0> INFO: PixTestPretest::doTest()
[10:57:37.704] <TB0> INFO: ######################################################################
[10:57:37.705] <TB0> INFO: ----------------------------------------------------------------------
[10:57:37.705] <TB0> INFO: PixTestPretest::programROC()
[10:57:37.705] <TB0> INFO: ----------------------------------------------------------------------
[10:57:54.307] <TB0> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[10:57:54.307] <TB0> INFO: IA differences per ROC: 20.1 19.3 17.7 20.9 20.1 18.5 17.7 18.5 21.7 19.3 19.3 20.9 19.3 20.9 19.3 20.9
[10:57:54.363] <TB0> INFO: ----------------------------------------------------------------------
[10:57:54.363] <TB0> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[10:57:54.363] <TB0> INFO: ----------------------------------------------------------------------
[10:58:03.657] <TB0> INFO: PixTestPretest::setVana() done, Module Ia 400.3 mA = 25.0188 mA/ROC
[10:58:03.657] <TB0> INFO: i(loss) [mA/ROC]: 20.1 20.1 20.1 20.1 20.1 20.9 20.1 20.1 20.1 19.3 19.3 19.3 20.1 19.3 20.9 19.3
[10:58:03.687] <TB0> INFO: ----------------------------------------------------------------------
[10:58:03.687] <TB0> INFO: PixTestPretest::findTiming()
[10:58:03.687] <TB0> INFO: ----------------------------------------------------------------------
[10:58:03.687] <TB0> INFO: PixTestCmd::init()
[10:58:04.242] <TB0> WARNING: Not unmasking DUT, not setting Calibrate bits!

[10:58:36.362] <TB0> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[10:58:36.362] <TB0> INFO: (success/tries = 100/100), width = 4
[10:58:37.866] <TB0> INFO: ----------------------------------------------------------------------
[10:58:37.866] <TB0> INFO: PixTestPretest::findWorkingPixel()
[10:58:37.866] <TB0> INFO: ----------------------------------------------------------------------
[10:58:37.962] <TB0> INFO: Expecting 231680 events.
[10:58:48.160] <TB0> INFO: 231680 events read in total (9607ms).
[10:58:48.170] <TB0> INFO: Test took 10300ms.
[10:58:48.420] <TB0> INFO: Found working pixel in all ROCs: col/row = 12/22
[10:58:48.458] <TB0> INFO: ----------------------------------------------------------------------
[10:58:48.458] <TB0> INFO: PixTestPretest::setVthrCompCalDel()
[10:58:48.458] <TB0> INFO: ----------------------------------------------------------------------
[10:58:48.554] <TB0> INFO: Expecting 231680 events.
[10:58:58.727] <TB0> INFO: 231680 events read in total (9581ms).
[10:58:58.738] <TB0> INFO: Test took 10274ms.
[10:58:58.006] <TB0> INFO: PixTestPretest::setVthrCompCalDel() done
[10:58:58.006] <TB0> INFO: CalDel: 88 93 86 111 104 93 93 93 116 100 109 107 87 78 72 107
[10:58:58.006] <TB0> INFO: VthrComp: 51 51 51 52 51 51 51 51 51 51 51 51 51 51 52 51
[10:58:59.010] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C0.dat
[10:58:59.010] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C1.dat
[10:58:59.011] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C2.dat
[10:58:59.011] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C3.dat
[10:58:59.011] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C4.dat
[10:58:59.011] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C5.dat
[10:58:59.011] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C6.dat
[10:58:59.011] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C7.dat
[10:58:59.011] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C8.dat
[10:58:59.012] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C9.dat
[10:58:59.012] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C10.dat
[10:58:59.012] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C11.dat
[10:58:59.012] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C12.dat
[10:58:59.012] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C13.dat
[10:58:59.012] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C14.dat
[10:58:59.012] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters_C15.dat
[10:58:59.012] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//tbmParameters_C0a.dat
[10:58:59.012] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//tbmParameters_C0b.dat
[10:58:59.012] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//tbmParameters_C1a.dat
[10:58:59.013] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//tbmParameters_C1b.dat
[10:58:59.013] <TB0> INFO: PixTestPretest::doTest() done, duration: 81 seconds
[10:58:59.066] <TB0> INFO: enter test to run
[10:58:59.066] <TB0> INFO: test: FullTest no parameter change
[10:58:59.066] <TB0> INFO: running: fulltest
[10:58:59.066] <TB0> INFO: ######################################################################
[10:58:59.066] <TB0> INFO: PixTestFullTest::doTest()
[10:58:59.066] <TB0> INFO: ######################################################################
[10:58:59.067] <TB0> INFO: ######################################################################
[10:58:59.067] <TB0> INFO: PixTestAlive::doTest()
[10:58:59.067] <TB0> INFO: ######################################################################
[10:58:59.068] <TB0> INFO: ----------------------------------------------------------------------
[10:58:59.068] <TB0> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:58:59.068] <TB0> INFO: ----------------------------------------------------------------------
[10:58:59.310] <TB0> INFO: Expecting 41600 events.
[10:59:02.850] <TB0> INFO: 41600 events read in total (2948ms).
[10:59:02.851] <TB0> INFO: Test took 3781ms.
[10:59:03.083] <TB0> INFO: PixTestAlive::aliveTest() done
[10:59:03.083] <TB0> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0
[10:59:03.085] <TB0> INFO: ----------------------------------------------------------------------
[10:59:03.085] <TB0> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:59:03.085] <TB0> INFO: ----------------------------------------------------------------------
[10:59:03.330] <TB0> INFO: Expecting 41600 events.
[10:59:06.321] <TB0> INFO: 41600 events read in total (2399ms).
[10:59:06.321] <TB0> INFO: Test took 3233ms.
[10:59:06.321] <TB0> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:59:06.559] <TB0> INFO: PixTestAlive::maskTest() done
[10:59:06.559] <TB0> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:59:06.561] <TB0> INFO: ----------------------------------------------------------------------
[10:59:06.561] <TB0> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:59:06.561] <TB0> INFO: ----------------------------------------------------------------------
[10:59:06.799] <TB0> INFO: Expecting 41600 events.
[10:59:10.341] <TB0> INFO: 41600 events read in total (2950ms).
[10:59:10.342] <TB0> INFO: Test took 3779ms.
[10:59:10.575] <TB0> INFO: PixTestAlive::addressDecodingTest() done
[10:59:10.575] <TB0> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:59:10.576] <TB0> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[10:59:10.576] <TB0> INFO: Decoding statistics:
[10:59:10.576] <TB0> INFO: General information:
[10:59:10.576] <TB0> INFO: 16bit words read: 0
[10:59:10.576] <TB0> INFO: valid events total: 0
[10:59:10.576] <TB0> INFO: empty events: 0
[10:59:10.576] <TB0> INFO: valid events with pixels: 0
[10:59:10.576] <TB0> INFO: valid pixel hits: 0
[10:59:10.576] <TB0> INFO: Event errors: 0
[10:59:10.576] <TB0> INFO: start marker: 0
[10:59:10.576] <TB0> INFO: stop marker: 0
[10:59:10.576] <TB0> INFO: overflow: 0
[10:59:10.576] <TB0> INFO: invalid 5bit words: 0
[10:59:10.576] <TB0> INFO: invalid XOR eye diagram: 0
[10:59:10.576] <TB0> INFO: frame (failed synchr.): 0
[10:59:10.576] <TB0> INFO: idle data (no TBM trl): 0
[10:59:10.576] <TB0> INFO: no data (only TBM hdr): 0
[10:59:10.576] <TB0> INFO: TBM errors: 0
[10:59:10.576] <TB0> INFO: flawed TBM headers: 0
[10:59:10.576] <TB0> INFO: flawed TBM trailers: 0
[10:59:10.576] <TB0> INFO: event ID mismatches: 0
[10:59:10.576] <TB0> INFO: ROC errors: 0
[10:59:10.576] <TB0> INFO: missing ROC header(s): 0
[10:59:10.576] <TB0> INFO: misplaced readback start: 0
[10:59:10.576] <TB0> INFO: Pixel decoding errors: 0
[10:59:10.576] <TB0> INFO: pixel data incomplete: 0
[10:59:10.576] <TB0> INFO: pixel address: 0
[10:59:10.576] <TB0> INFO: pulse height fill bit: 0
[10:59:10.576] <TB0> INFO: buffer corruption: 0
[10:59:10.583] <TB0> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C15.dat
[10:59:10.584] <TB0> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr_C15.dat
[10:59:10.584] <TB0> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[10:59:10.584] <TB0> INFO: ######################################################################
[10:59:10.584] <TB0> INFO: PixTestReadback::doTest()
[10:59:10.584] <TB0> INFO: ######################################################################
[10:59:10.584] <TB0> INFO: ----------------------------------------------------------------------
[10:59:10.584] <TB0> INFO: PixTestReadback::CalibrateVd()
[10:59:10.584] <TB0> INFO: ----------------------------------------------------------------------
[10:59:20.555] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C0.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C1.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C2.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C3.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C4.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C5.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C6.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C7.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C8.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C9.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C10.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C11.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C12.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C13.dat
[10:59:20.556] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C14.dat
[10:59:20.557] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C15.dat
[10:59:20.588] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[10:59:20.588] <TB0> INFO: ----------------------------------------------------------------------
[10:59:20.588] <TB0> INFO: PixTestReadback::CalibrateVa()
[10:59:20.588] <TB0> INFO: ----------------------------------------------------------------------
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C0.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C1.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C2.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C3.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C4.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C5.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C6.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C7.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C8.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C9.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C10.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C11.dat
[10:59:30.503] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C12.dat
[10:59:30.504] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C13.dat
[10:59:30.504] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C14.dat
[10:59:30.504] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C15.dat
[10:59:30.531] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[10:59:30.531] <TB0> INFO: ----------------------------------------------------------------------
[10:59:30.531] <TB0> INFO: PixTestReadback::readbackVbg()
[10:59:30.531] <TB0> INFO: ----------------------------------------------------------------------
[10:59:38.187] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[10:59:38.187] <TB0> INFO: ----------------------------------------------------------------------
[10:59:38.187] <TB0> INFO: PixTestReadback::getCalibratedVbg()
[10:59:38.187] <TB0> INFO: ----------------------------------------------------------------------
[10:59:38.187] <TB0> INFO: Vbg will be calibrated using Vd calibration
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 145.3calibrated Vbg = 1.19199 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 156calibrated Vbg = 1.19148 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 156calibrated Vbg = 1.17954 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 154.7calibrated Vbg = 1.17709 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 154calibrated Vbg = 1.17966 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 153.6calibrated Vbg = 1.18216 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 152.2calibrated Vbg = 1.18497 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 163.6calibrated Vbg = 1.17634 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 152.8calibrated Vbg = 1.18498 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 150.3calibrated Vbg = 1.18609 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 149calibrated Vbg = 1.1752 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 153.4calibrated Vbg = 1.16877 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 145.3calibrated Vbg = 1.17663 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 164.5calibrated Vbg = 1.17977 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 159calibrated Vbg = 1.18333 :::*/*/*/*/
[10:59:38.187] <TB0> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 144.6calibrated Vbg = 1.1766 :::*/*/*/*/
[10:59:38.189] <TB0> INFO: ----------------------------------------------------------------------
[10:59:38.189] <TB0> INFO: PixTestReadback::CalibrateIa()
[10:59:38.189] <TB0> INFO: ----------------------------------------------------------------------
[11:02:19.014] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C0.dat
[11:02:19.014] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C1.dat
[11:02:19.014] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C2.dat
[11:02:19.014] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C3.dat
[11:02:19.014] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C4.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C5.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C6.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C7.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C8.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C9.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C10.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C11.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C12.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C13.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C14.dat
[11:02:19.015] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//readbackCal_C15.dat
[11:02:19.043] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[11:02:19.044] <TB0> INFO: PixTestReadback::doTest() done
[11:02:19.044] <TB0> INFO: Decoding statistics:
[11:02:19.044] <TB0> INFO: General information:
[11:02:19.044] <TB0> INFO: 16bit words read: 1536
[11:02:19.044] <TB0> INFO: valid events total: 256
[11:02:19.044] <TB0> INFO: empty events: 256
[11:02:19.044] <TB0> INFO: valid events with pixels: 0
[11:02:19.044] <TB0> INFO: valid pixel hits: 0
[11:02:19.044] <TB0> INFO: Event errors: 0
[11:02:19.044] <TB0> INFO: start marker: 0
[11:02:19.044] <TB0> INFO: stop marker: 0
[11:02:19.044] <TB0> INFO: overflow: 0
[11:02:19.044] <TB0> INFO: invalid 5bit words: 0
[11:02:19.045] <TB0> INFO: invalid XOR eye diagram: 0
[11:02:19.045] <TB0> INFO: frame (failed synchr.): 0
[11:02:19.045] <TB0> INFO: idle data (no TBM trl): 0
[11:02:19.045] <TB0> INFO: no data (only TBM hdr): 0
[11:02:19.045] <TB0> INFO: TBM errors: 0
[11:02:19.045] <TB0> INFO: flawed TBM headers: 0
[11:02:19.045] <TB0> INFO: flawed TBM trailers: 0
[11:02:19.045] <TB0> INFO: event ID mismatches: 0
[11:02:19.045] <TB0> INFO: ROC errors: 0
[11:02:19.045] <TB0> INFO: missing ROC header(s): 0
[11:02:19.045] <TB0> INFO: misplaced readback start: 0
[11:02:19.045] <TB0> INFO: Pixel decoding errors: 0
[11:02:19.045] <TB0> INFO: pixel data incomplete: 0
[11:02:19.045] <TB0> INFO: pixel address: 0
[11:02:19.045] <TB0> INFO: pulse height fill bit: 0
[11:02:19.045] <TB0> INFO: buffer corruption: 0
[11:02:19.097] <TB0> INFO: ######################################################################
[11:02:19.097] <TB0> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:02:19.097] <TB0> INFO: ######################################################################
[11:02:19.101] <TB0> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[11:02:19.143] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[11:02:19.143] <TB0> INFO: run 1 of 1
[11:02:19.379] <TB0> INFO: Expecting 3120000 events.
[11:02:51.809] <TB0> INFO: 677525 events read in total (31838ms).
[11:03:04.185] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (22) != TBM ID (129)

[11:03:04.327] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 22 22 129 22 22 22 22 22

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

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

[11:03:04.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01a 8000 4301 4301 e022 c000

[11:03:04.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a014 80b1 4300 4300 e022 c000

[11:03:04.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a015 80c0 4300 4300 e022 c000

[11:03:04.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4300 e022 c000

[11:03:04.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a017 8040 4300 4300 e022 c000

[11:03:04.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a018 80b1 4300 4300 e022 c000

[11:03:04.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a019 80c0 4380 4301 e022 c000

[11:03:22.532] <TB0> INFO: 1351010 events read in total (62561ms).
[11:03:34.863] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (227) != TBM ID (129)

[11:03:34.000] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 227 227 129 227 227 227 227 227

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

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

[11:03:34.002] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e7 8040 4300 4300 e022 c000

[11:03:34.002] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e1 80c0 4381 4380 e022 c000

[11:03:34.002] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e2 8000 4300 4301 e022 c000

[11:03:34.002] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4300 e022 c000

[11:03:34.002] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e4 80b1 4300 4300 e022 c000

[11:03:34.002] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e5 80c0 4300 4300 e022 c000

[11:03:34.002] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e6 8000 4300 4300 e022 c000

[11:03:53.045] <TB0> INFO: 2021835 events read in total (93075ms).
[11:04:05.348] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (76) != TBM ID (129)

[11:04:05.487] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 76 76 129 76 76 76 76 76

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

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

[11:04:05.487] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a050 80b1 4300 82c 2fc9 4301 82c 2fef e022 c000

[11:04:05.487] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04a 8000 4301 82c 2fcc 4301 82c 2fef e022 c000

[11:04:05.487] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04b 8040 4301 82c 2fcd 4380 82c 2fef e022 c000

[11:04:05.487] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4300 2fcd 4300 82c 2fef e022 c000

[11:04:05.487] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04d 80c0 4300 82c 2fcc 4301 82c 2fef e022 c000

[11:04:05.487] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04e 8000 4301 82c 2fcc 4302 82c 2fef e022 c000

[11:04:05.487] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04f 8040 4382 82c 2fcd 4300 82c 2fef e022 c000

[11:04:23.730] <TB0> INFO: 2690740 events read in total (123759ms).
[11:04:31.723] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (53) != TBM ID (129)

[11:04:31.857] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 53 53 129 53 53 53 53 53

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

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

[11:04:31.857] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a039 80c0 4301 a90 27ef 4301 a90 27ef e022 c000

[11:04:31.857] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a033 8040 4300 a90 27ef 4300 a90 27ef e022 c000

[11:04:31.857] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a034 80b1 4300 4300 a90 27ef e022 c000

[11:04:31.857] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4300 27ef 4300 a90 27ef e022 c000

[11:04:31.857] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a036 8000 4300 a90 27ef 4300 a90 27ef e022 c000

[11:04:31.857] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a037 8040 4300 a90 27ef 4300 a90 27ef e022 c000

[11:04:31.857] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a038 80b1 4300 a90 27ef 4301 a90 27ef e022 c000

[11:04:43.284] <TB0> INFO: 3120000 events read in total (143313ms).
[11:04:43.362] <TB0> INFO: Test took 144220ms.
[11:05:07.358] <TB0> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 168 seconds
[11:05:07.358] <TB0> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:05:07.358] <TB0> INFO: separation cut (per ROC): 117 106 110 109 117 120 104 116 105 102 103 109 105 109 109 100
[11:05:07.358] <TB0> INFO: Decoding statistics:
[11:05:07.358] <TB0> INFO: General information:
[11:05:07.358] <TB0> INFO: 16bit words read: 0
[11:05:07.358] <TB0> INFO: valid events total: 0
[11:05:07.358] <TB0> INFO: empty events: 0
[11:05:07.358] <TB0> INFO: valid events with pixels: 0
[11:05:07.358] <TB0> INFO: valid pixel hits: 0
[11:05:07.358] <TB0> INFO: Event errors: 0
[11:05:07.358] <TB0> INFO: start marker: 0
[11:05:07.358] <TB0> INFO: stop marker: 0
[11:05:07.358] <TB0> INFO: overflow: 0
[11:05:07.358] <TB0> INFO: invalid 5bit words: 0
[11:05:07.358] <TB0> INFO: invalid XOR eye diagram: 0
[11:05:07.358] <TB0> INFO: frame (failed synchr.): 0
[11:05:07.358] <TB0> INFO: idle data (no TBM trl): 0
[11:05:07.358] <TB0> INFO: no data (only TBM hdr): 0
[11:05:07.358] <TB0> INFO: TBM errors: 0
[11:05:07.358] <TB0> INFO: flawed TBM headers: 0
[11:05:07.358] <TB0> INFO: flawed TBM trailers: 0
[11:05:07.358] <TB0> INFO: event ID mismatches: 0
[11:05:07.358] <TB0> INFO: ROC errors: 0
[11:05:07.358] <TB0> INFO: missing ROC header(s): 0
[11:05:07.358] <TB0> INFO: misplaced readback start: 0
[11:05:07.358] <TB0> INFO: Pixel decoding errors: 0
[11:05:07.358] <TB0> INFO: pixel data incomplete: 0
[11:05:07.358] <TB0> INFO: pixel address: 0
[11:05:07.358] <TB0> INFO: pulse height fill bit: 0
[11:05:07.358] <TB0> INFO: buffer corruption: 0
[11:05:07.399] <TB0> INFO: ######################################################################
[11:05:07.399] <TB0> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:05:07.399] <TB0> INFO: ######################################################################
[11:05:07.399] <TB0> INFO: ----------------------------------------------------------------------
[11:05:07.399] <TB0> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:05:07.399] <TB0> INFO: ----------------------------------------------------------------------
[11:05:07.399] <TB0> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[11:05:07.414] <TB0> INFO: dacScan split into 1 runs with ntrig = 50
[11:05:07.414] <TB0> INFO: run 1 of 1
[11:05:07.659] <TB0> INFO: Expecting 36608000 events.
[11:05:32.197] <TB0> INFO: 684750 events read in total (23947ms).
[11:05:54.801] <TB0> INFO: 1356400 events read in total (46551ms).
[11:06:17.874] <TB0> INFO: 2028700 events read in total (69624ms).
[11:06:40.538] <TB0> INFO: 2698800 events read in total (92288ms).
[11:07:03.138] <TB0> INFO: 3368750 events read in total (114888ms).
[11:07:25.919] <TB0> INFO: 4038600 events read in total (137669ms).
[11:07:48.712] <TB0> INFO: 4707900 events read in total (160462ms).
[11:08:11.450] <TB0> INFO: 5376950 events read in total (183200ms).
[11:08:34.265] <TB0> INFO: 6046500 events read in total (206015ms).
[11:08:57.067] <TB0> INFO: 6716950 events read in total (228817ms).
[11:09:19.791] <TB0> INFO: 7387150 events read in total (251541ms).
[11:09:42.774] <TB0> INFO: 8056250 events read in total (274524ms).
[11:10:05.686] <TB0> INFO: 8725500 events read in total (297436ms).
[11:10:28.363] <TB0> INFO: 9391800 events read in total (320113ms).
[11:10:50.978] <TB0> INFO: 10058200 events read in total (342728ms).
[11:11:13.802] <TB0> INFO: 10726250 events read in total (365552ms).
[11:11:36.578] <TB0> INFO: 11394000 events read in total (388328ms).
[11:11:59.627] <TB0> INFO: 12062850 events read in total (411377ms).
[11:12:22.522] <TB0> INFO: 12732200 events read in total (434272ms).
[11:12:45.364] <TB0> INFO: 13403300 events read in total (457114ms).
[11:13:08.279] <TB0> INFO: 14074450 events read in total (480029ms).
[11:13:30.925] <TB0> INFO: 14744050 events read in total (502675ms).
[11:13:53.534] <TB0> INFO: 15413450 events read in total (525285ms).
[11:14:16.512] <TB0> INFO: 16083150 events read in total (548262ms).
[11:14:39.745] <TB0> INFO: 16753300 events read in total (571495ms).
[11:15:02.763] <TB0> INFO: 17421950 events read in total (594513ms).
[11:15:25.528] <TB0> INFO: 18089650 events read in total (617278ms).
[11:15:48.394] <TB0> INFO: 18757550 events read in total (640144ms).
[11:16:11.179] <TB0> INFO: 19422400 events read in total (662929ms).
[11:16:33.951] <TB0> INFO: 20088150 events read in total (685701ms).
[11:16:56.904] <TB0> INFO: 20755000 events read in total (708654ms).
[11:17:19.867] <TB0> INFO: 21421800 events read in total (731617ms).
[11:17:42.984] <TB0> INFO: 22087300 events read in total (754734ms).
[11:18:05.783] <TB0> INFO: 22753700 events read in total (777533ms).
[11:18:28.645] <TB0> INFO: 23417900 events read in total (800395ms).
[11:18:51.531] <TB0> INFO: 24082950 events read in total (823281ms).
[11:19:14.582] <TB0> INFO: 24747150 events read in total (846332ms).
[11:19:37.345] <TB0> INFO: 25411900 events read in total (869095ms).
[11:20:00.245] <TB0> INFO: 26074250 events read in total (891995ms).
[11:20:23.115] <TB0> INFO: 26736600 events read in total (914865ms).
[11:20:46.231] <TB0> INFO: 27399800 events read in total (937981ms).
[11:21:09.350] <TB0> INFO: 28062500 events read in total (961100ms).
[11:21:32.581] <TB0> INFO: 28727300 events read in total (984331ms).
[11:21:55.690] <TB0> INFO: 29389450 events read in total (1007440ms).
[11:22:18.600] <TB0> INFO: 30048950 events read in total (1030350ms).
[11:22:41.338] <TB0> INFO: 30710400 events read in total (1053088ms).
[11:23:04.483] <TB0> INFO: 31373100 events read in total (1076233ms).
[11:23:27.288] <TB0> INFO: 32036500 events read in total (1099038ms).
[11:23:50.147] <TB0> INFO: 32699200 events read in total (1121897ms).
[11:24:13.128] <TB0> INFO: 33363750 events read in total (1144878ms).
[11:24:36.047] <TB0> INFO: 34028350 events read in total (1167797ms).
[11:24:58.875] <TB0> INFO: 34694450 events read in total (1190625ms).
[11:25:21.429] <TB0> INFO: 35358250 events read in total (1213179ms).
[11:25:44.396] <TB0> INFO: 36026750 events read in total (1236146ms).
[11:26:04.329] <TB0> INFO: 36608000 events read in total (1256079ms).
[11:26:04.423] <TB0> INFO: Test took 1257008ms.
[11:26:04.807] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:06.640] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:08.913] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:10.788] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:12.981] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:15.119] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:17.062] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:18.975] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:20.006] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:22.891] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:24.529] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:26.222] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:27.688] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:29.498] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:31.441] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:33.535] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[11:26:35.763] <TB0> INFO: PixTestScurves::scurves() done
[11:26:35.763] <TB0> INFO: Vcal mean: 126.09 118.59 121.58 125.31 115.86 130.85 114.49 123.40 116.89 110.64 111.82 118.43 113.47 118.78 121.84 110.23
[11:26:35.763] <TB0> INFO: Vcal RMS: 6.22 6.09 5.28 6.18 5.00 6.01 5.13 5.19 5.47 4.57 5.21 5.34 4.80 5.59 5.64 4.67
[11:26:35.763] <TB0> INFO: PixTestScurves::fullTest() done, duration: 1288 seconds
[11:26:35.763] <TB0> INFO: Decoding statistics:
[11:26:35.764] <TB0> INFO: General information:
[11:26:35.764] <TB0> INFO: 16bit words read: 0
[11:26:35.764] <TB0> INFO: valid events total: 0
[11:26:35.764] <TB0> INFO: empty events: 0
[11:26:35.764] <TB0> INFO: valid events with pixels: 0
[11:26:35.764] <TB0> INFO: valid pixel hits: 0
[11:26:35.764] <TB0> INFO: Event errors: 0
[11:26:35.764] <TB0> INFO: start marker: 0
[11:26:35.764] <TB0> INFO: stop marker: 0
[11:26:35.764] <TB0> INFO: overflow: 0
[11:26:35.764] <TB0> INFO: invalid 5bit words: 0
[11:26:35.764] <TB0> INFO: invalid XOR eye diagram: 0
[11:26:35.764] <TB0> INFO: frame (failed synchr.): 0
[11:26:35.764] <TB0> INFO: idle data (no TBM trl): 0
[11:26:35.764] <TB0> INFO: no data (only TBM hdr): 0
[11:26:35.764] <TB0> INFO: TBM errors: 0
[11:26:35.764] <TB0> INFO: flawed TBM headers: 0
[11:26:35.764] <TB0> INFO: flawed TBM trailers: 0
[11:26:35.764] <TB0> INFO: event ID mismatches: 0
[11:26:35.764] <TB0> INFO: ROC errors: 0
[11:26:35.764] <TB0> INFO: missing ROC header(s): 0
[11:26:35.764] <TB0> INFO: misplaced readback start: 0
[11:26:35.764] <TB0> INFO: Pixel decoding errors: 0
[11:26:35.764] <TB0> INFO: pixel data incomplete: 0
[11:26:35.764] <TB0> INFO: pixel address: 0
[11:26:35.764] <TB0> INFO: pulse height fill bit: 0
[11:26:35.764] <TB0> INFO: buffer corruption: 0
[11:26:35.845] <TB0> INFO: ######################################################################
[11:26:35.845] <TB0> INFO: PixTestTrim::doTest()
[11:26:35.845] <TB0> INFO: ######################################################################
[11:26:35.846] <TB0> INFO: ----------------------------------------------------------------------
[11:26:35.846] <TB0> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[11:26:35.846] <TB0> INFO: ----------------------------------------------------------------------
[11:26:35.889] <TB0> INFO: ---> VthrComp thr map (minimal VthrComp)
[11:26:35.889] <TB0> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:26:35.902] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:26:35.902] <TB0> INFO: run 1 of 1
[11:26:36.142] <TB0> INFO: Expecting 5025280 events.
[11:27:06.908] <TB0> INFO: 828856 events read in total (30166ms).
[11:27:36.929] <TB0> INFO: 1654912 events read in total (60187ms).
[11:28:06.892] <TB0> INFO: 2480912 events read in total (90150ms).
[11:28:36.966] <TB0> INFO: 3299832 events read in total (120224ms).
[11:29:06.964] <TB0> INFO: 4115368 events read in total (150223ms).
[11:29:37.161] <TB0> INFO: 4928360 events read in total (180419ms).
[11:29:41.245] <TB0> INFO: 5025280 events read in total (184503ms).
[11:29:41.300] <TB0> INFO: Test took 185398ms.
[11:30:00.741] <TB0> INFO: ROC 0 VthrComp = 132
[11:30:00.741] <TB0> INFO: ROC 1 VthrComp = 122
[11:30:00.741] <TB0> INFO: ROC 2 VthrComp = 130
[11:30:00.742] <TB0> INFO: ROC 3 VthrComp = 131
[11:30:00.742] <TB0> INFO: ROC 4 VthrComp = 127
[11:30:00.742] <TB0> INFO: ROC 5 VthrComp = 134
[11:30:00.742] <TB0> INFO: ROC 6 VthrComp = 118
[11:30:00.742] <TB0> INFO: ROC 7 VthrComp = 126
[11:30:00.742] <TB0> INFO: ROC 8 VthrComp = 123
[11:30:00.742] <TB0> INFO: ROC 9 VthrComp = 112
[11:30:00.742] <TB0> INFO: ROC 10 VthrComp = 112
[11:30:00.742] <TB0> INFO: ROC 11 VthrComp = 127
[11:30:00.743] <TB0> INFO: ROC 12 VthrComp = 125
[11:30:00.743] <TB0> INFO: ROC 13 VthrComp = 128
[11:30:00.743] <TB0> INFO: ROC 14 VthrComp = 134
[11:30:00.743] <TB0> INFO: ROC 15 VthrComp = 112
[11:30:00.983] <TB0> INFO: Expecting 41600 events.
[11:30:04.441] <TB0> INFO: 41600 events read in total (2866ms).
[11:30:04.442] <TB0> INFO: Test took 3697ms.
[11:30:04.455] <TB0> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:30:04.455] <TB0> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:30:04.469] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:30:04.470] <TB0> INFO: run 1 of 1
[11:30:04.795] <TB0> INFO: Expecting 5025280 events.
[11:30:30.706] <TB0> INFO: 589984 events read in total (25320ms).
[11:30:56.842] <TB0> INFO: 1178560 events read in total (51456ms).
[11:31:22.842] <TB0> INFO: 1767536 events read in total (77456ms).
[11:31:48.880] <TB0> INFO: 2355800 events read in total (103494ms).
[11:32:14.644] <TB0> INFO: 2941912 events read in total (129258ms).
[11:32:40.520] <TB0> INFO: 3526272 events read in total (155134ms).
[11:33:06.313] <TB0> INFO: 4109568 events read in total (180927ms).
[11:33:32.286] <TB0> INFO: 4692200 events read in total (206900ms).
[11:33:46.813] <TB0> INFO: 5025280 events read in total (221427ms).
[11:33:46.895] <TB0> INFO: Test took 222425ms.
[11:34:15.170] <TB0> INFO: roc 0 with ID = 0 has maximal Vcal 59.8861 for pixel 14/16 mean/min/max = 46.5131/33.0955/59.9308
[11:34:15.171] <TB0> INFO: roc 1 with ID = 1 has maximal Vcal 60.2608 for pixel 16/74 mean/min/max = 46.3187/32.1828/60.4546
[11:34:15.171] <TB0> INFO: roc 2 with ID = 2 has maximal Vcal 58.1802 for pixel 0/77 mean/min/max = 45.5798/32.7459/58.4136
[11:34:15.172] <TB0> INFO: roc 3 with ID = 3 has maximal Vcal 60.5537 for pixel 19/15 mean/min/max = 47.0098/33.3713/60.6482
[11:34:15.172] <TB0> INFO: roc 4 with ID = 4 has maximal Vcal 57.4326 for pixel 16/9 mean/min/max = 45.193/32.9143/57.4717
[11:34:15.173] <TB0> INFO: roc 5 with ID = 5 has maximal Vcal 60.3837 for pixel 30/13 mean/min/max = 47.1825/33.9109/60.4541
[11:34:15.173] <TB0> INFO: roc 6 with ID = 6 has maximal Vcal 58.815 for pixel 6/7 mean/min/max = 45.7774/32.6923/58.8625
[11:34:15.173] <TB0> INFO: roc 7 with ID = 7 has maximal Vcal 58.8518 for pixel 14/0 mean/min/max = 45.6943/32.4967/58.8919
[11:34:15.174] <TB0> INFO: roc 8 with ID = 8 has maximal Vcal 59.9743 for pixel 23/2 mean/min/max = 46.182/32.1923/60.1716
[11:34:15.174] <TB0> INFO: roc 9 with ID = 9 has maximal Vcal 60.2412 for pixel 33/73 mean/min/max = 47.1118/33.9037/60.3199
[11:34:15.174] <TB0> INFO: roc 10 with ID = 10 has maximal Vcal 60.4347 for pixel 0/1 mean/min/max = 47.2241/33.5358/60.9124
[11:34:15.175] <TB0> INFO: roc 11 with ID = 11 has maximal Vcal 58.0686 for pixel 31/11 mean/min/max = 45.0404/31.9634/58.1175
[11:34:15.175] <TB0> INFO: roc 12 with ID = 12 has maximal Vcal 57.2333 for pixel 32/6 mean/min/max = 44.5904/31.8602/57.3205
[11:34:15.176] <TB0> INFO: roc 13 with ID = 13 has maximal Vcal 57.5945 for pixel 19/78 mean/min/max = 44.7425/31.7484/57.7365
[11:34:15.176] <TB0> INFO: roc 14 with ID = 14 has maximal Vcal 59.116 for pixel 18/57 mean/min/max = 46.1496/33.1231/59.176
[11:34:15.176] <TB0> INFO: roc 15 with ID = 15 has maximal Vcal 60.1318 for pixel 13/8 mean/min/max = 46.7297/33.1109/60.3484
[11:34:15.177] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:34:15.266] <TB0> INFO: Expecting 411648 events.
[11:34:24.773] <TB0> INFO: 411648 events read in total (8915ms).
[11:34:24.781] <TB0> INFO: Expecting 411648 events.
[11:34:33.927] <TB0> INFO: 411648 events read in total (8743ms).
[11:34:33.940] <TB0> INFO: Expecting 411648 events.
[11:34:42.981] <TB0> INFO: 411648 events read in total (8638ms).
[11:34:42.993] <TB0> INFO: Expecting 411648 events.
[11:34:52.063] <TB0> INFO: 411648 events read in total (8667ms).
[11:34:52.080] <TB0> INFO: Expecting 411648 events.
[11:35:01.419] <TB0> INFO: 411648 events read in total (8936ms).
[11:35:01.438] <TB0> INFO: Expecting 411648 events.
[11:35:10.687] <TB0> INFO: 411648 events read in total (8846ms).
[11:35:10.709] <TB0> INFO: Expecting 411648 events.
[11:35:20.176] <TB0> INFO: 411648 events read in total (9064ms).
[11:35:20.200] <TB0> INFO: Expecting 411648 events.
[11:35:29.533] <TB0> INFO: 411648 events read in total (8930ms).
[11:35:29.569] <TB0> INFO: Expecting 411648 events.
[11:35:38.928] <TB0> INFO: 411648 events read in total (8956ms).
[11:35:38.958] <TB0> INFO: Expecting 411648 events.
[11:35:48.321] <TB0> INFO: 411648 events read in total (8959ms).
[11:35:48.354] <TB0> INFO: Expecting 411648 events.
[11:35:57.612] <TB0> INFO: 411648 events read in total (8855ms).
[11:35:57.647] <TB0> INFO: Expecting 411648 events.
[11:36:06.975] <TB0> INFO: 411648 events read in total (8925ms).
[11:36:07.027] <TB0> INFO: Expecting 411648 events.
[11:36:16.431] <TB0> INFO: 411648 events read in total (9000ms).
[11:36:16.474] <TB0> INFO: Expecting 411648 events.
[11:36:25.820] <TB0> INFO: 411648 events read in total (8942ms).
[11:36:25.866] <TB0> INFO: Expecting 411648 events.
[11:36:35.189] <TB0> INFO: 411648 events read in total (8920ms).
[11:36:35.251] <TB0> INFO: Expecting 411648 events.
[11:36:44.657] <TB0> INFO: 411648 events read in total (9003ms).
[11:36:44.725] <TB0> INFO: Test took 149548ms.
[11:36:45.528] <TB0> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[11:36:45.543] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:36:45.543] <TB0> INFO: run 1 of 1
[11:36:45.792] <TB0> INFO: Expecting 5025280 events.
[11:37:12.056] <TB0> INFO: 586472 events read in total (25672ms).
[11:37:37.784] <TB0> INFO: 1171064 events read in total (51400ms).
[11:38:03.929] <TB0> INFO: 1755112 events read in total (77545ms).
[11:38:29.657] <TB0> INFO: 2339016 events read in total (103273ms).
[11:38:55.419] <TB0> INFO: 2920768 events read in total (129035ms).
[11:39:21.407] <TB0> INFO: 3503128 events read in total (155023ms).
[11:39:47.629] <TB0> INFO: 4086976 events read in total (181245ms).
[11:40:13.641] <TB0> INFO: 4670568 events read in total (207257ms).
[11:40:29.842] <TB0> INFO: 5025280 events read in total (223458ms).
[11:40:29.990] <TB0> INFO: Test took 224448ms.
[11:40:56.413] <TB0> INFO: ---> TrimStepCorr4 extremal thresholds: 7.220450 .. 143.772080
[11:40:56.658] <TB0> INFO: Expecting 208000 events.
[11:41:06.468] <TB0> INFO: 208000 events read in total (9219ms).
[11:41:06.469] <TB0> INFO: Test took 10055ms.
[11:41:06.522] <TB0> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 7 .. 153 (-1/-1) hits flags = 528 (plus default)
[11:41:06.536] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:41:06.536] <TB0> INFO: run 1 of 1
[11:41:06.817] <TB0> INFO: Expecting 4892160 events.
[11:41:32.522] <TB0> INFO: 577240 events read in total (25113ms).
[11:41:57.883] <TB0> INFO: 1154872 events read in total (50474ms).
[11:42:23.184] <TB0> INFO: 1732064 events read in total (75775ms).
[11:42:48.704] <TB0> INFO: 2309304 events read in total (101295ms).
[11:43:14.306] <TB0> INFO: 2886384 events read in total (126898ms).
[11:43:39.591] <TB0> INFO: 3462680 events read in total (152182ms).
[11:44:05.099] <TB0> INFO: 4038168 events read in total (177690ms).
[11:44:30.108] <TB0> INFO: 4613024 events read in total (202699ms).
[11:44:42.547] <TB0> INFO: 4892160 events read in total (215138ms).
[11:44:42.631] <TB0> INFO: Test took 216096ms.
[11:45:08.796] <TB0> INFO: ---> TrimStepCorr2 extremal thresholds: 28.801867 .. 45.943622
[11:45:09.034] <TB0> INFO: Expecting 208000 events.
[11:45:18.855] <TB0> INFO: 208000 events read in total (9229ms).
[11:45:18.856] <TB0> INFO: Test took 10058ms.
[11:45:18.904] <TB0> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 18 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:45:18.917] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:45:18.917] <TB0> INFO: run 1 of 1
[11:45:19.196] <TB0> INFO: Expecting 1264640 events.
[11:45:47.041] <TB0> INFO: 654896 events read in total (27254ms).
[11:46:12.694] <TB0> INFO: 1264640 events read in total (52908ms).
[11:46:12.728] <TB0> INFO: Test took 53811ms.
[11:46:25.472] <TB0> INFO: ---> TrimStepCorr1a extremal thresholds: 26.463214 .. 48.690175
[11:46:25.719] <TB0> INFO: Expecting 208000 events.
[11:46:35.424] <TB0> INFO: 208000 events read in total (9113ms).
[11:46:35.425] <TB0> INFO: Test took 9952ms.
[11:46:35.472] <TB0> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 58 (-1/-1) hits flags = 528 (plus default)
[11:46:35.487] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:46:35.487] <TB0> INFO: run 1 of 1
[11:46:35.767] <TB0> INFO: Expecting 1431040 events.
[11:47:03.828] <TB0> INFO: 652312 events read in total (27469ms).
[11:47:31.221] <TB0> INFO: 1303784 events read in total (54862ms).
[11:47:36.841] <TB0> INFO: 1431040 events read in total (60482ms).
[11:47:36.870] <TB0> INFO: Test took 61384ms.
[11:47:50.164] <TB0> INFO: ---> TrimStepCorr1b extremal thresholds: 25.373832 .. 45.979992
[11:47:50.403] <TB0> INFO: Expecting 208000 events.
[11:48:00.195] <TB0> INFO: 208000 events read in total (9200ms).
[11:48:00.196] <TB0> INFO: Test took 10031ms.
[11:48:00.244] <TB0> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:48:00.257] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:48:00.257] <TB0> INFO: run 1 of 1
[11:48:00.535] <TB0> INFO: Expecting 1364480 events.
[11:48:28.937] <TB0> INFO: 668440 events read in total (27810ms).
[11:48:56.612] <TB0> INFO: 1336544 events read in total (55485ms).
[11:48:58.166] <TB0> INFO: 1364480 events read in total (57039ms).
[11:48:58.194] <TB0> INFO: Test took 57937ms.
[11:49:13.042] <TB0> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[11:49:13.042] <TB0> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:49:13.056] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[11:49:13.056] <TB0> INFO: run 1 of 1
[11:49:13.342] <TB0> INFO: Expecting 1364480 events.
[11:49:41.586] <TB0> INFO: 668384 events read in total (27652ms).
[11:50:09.501] <TB0> INFO: 1335608 events read in total (55567ms).
[11:50:11.196] <TB0> INFO: 1364480 events read in total (57262ms).
[11:50:11.221] <TB0> INFO: Test took 58165ms.
[11:50:25.562] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C0.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C1.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C2.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C3.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C4.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C5.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C6.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C7.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C8.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C9.dat
[11:50:25.563] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C10.dat
[11:50:25.564] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C11.dat
[11:50:25.564] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C12.dat
[11:50:25.564] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C13.dat
[11:50:25.564] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C14.dat
[11:50:25.564] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C15.dat
[11:50:25.564] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C0.dat
[11:50:25.571] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C1.dat
[11:50:25.578] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C2.dat
[11:50:25.586] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C3.dat
[11:50:25.593] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C4.dat
[11:50:25.600] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C5.dat
[11:50:25.607] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C6.dat
[11:50:25.614] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C7.dat
[11:50:25.622] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C8.dat
[11:50:25.629] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C9.dat
[11:50:25.636] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C10.dat
[11:50:25.643] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C11.dat
[11:50:25.650] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C12.dat
[11:50:25.657] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C13.dat
[11:50:25.664] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C14.dat
[11:50:25.672] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//trimParameters35_C15.dat
[11:50:25.679] <TB0> INFO: PixTestTrim::trimTest() done
[11:50:25.679] <TB0> INFO: vtrim: 137 125 104 138 122 132 119 134 132 144 115 132 120 120 151 125
[11:50:25.679] <TB0> INFO: vthrcomp: 132 122 130 131 127 134 118 126 123 112 112 127 125 128 134 112
[11:50:25.679] <TB0> INFO: vcal mean: 35.00 35.12 35.01 35.24 35.02 35.07 34.97 35.05 35.00 35.08 35.07 35.04 34.97 34.98 35.01 35.06
[11:50:25.679] <TB0> INFO: vcal RMS: 0.96 1.08 0.95 1.32 0.93 1.11 0.97 1.00 1.11 1.08 1.01 1.06 0.96 1.04 1.02 1.01
[11:50:25.679] <TB0> INFO: bits mean: 9.16 9.53 8.43 8.97 9.47 8.97 9.34 9.69 9.31 9.34 8.62 9.81 9.31 9.71 9.54 8.86
[11:50:25.679] <TB0> INFO: bits RMS: 2.64 2.68 3.09 2.74 2.62 2.59 2.69 2.61 2.79 2.47 2.78 2.63 2.89 2.72 2.51 2.79
[11:50:25.687] <TB0> INFO: ----------------------------------------------------------------------
[11:50:25.687] <TB0> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[11:50:25.687] <TB0> INFO: ----------------------------------------------------------------------
[11:50:25.690] <TB0> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[11:50:25.706] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[11:50:25.706] <TB0> INFO: run 1 of 1
[11:50:26.029] <TB0> INFO: Expecting 4160000 events.
[11:50:58.919] <TB0> INFO: 756310 events read in total (32299ms).
[11:51:30.036] <TB0> INFO: 1507710 events read in total (63415ms).
[11:52:01.873] <TB0> INFO: 2259420 events read in total (95253ms).
[11:52:33.837] <TB0> INFO: 3005755 events read in total (127216ms).
[11:53:05.693] <TB0> INFO: 3747750 events read in total (159072ms).
[11:53:23.418] <TB0> INFO: 4160000 events read in total (176797ms).
[11:53:23.567] <TB0> INFO: Test took 177860ms.
[11:53:52.454] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 200 (-1/-1) hits flags = 528 (plus default)
[11:53:52.469] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[11:53:52.469] <TB0> INFO: run 1 of 1
[11:53:52.709] <TB0> INFO: Expecting 4180800 events.
[11:54:24.835] <TB0> INFO: 731630 events read in total (31534ms).
[11:54:55.932] <TB0> INFO: 1458510 events read in total (62631ms).
[11:55:27.357] <TB0> INFO: 2186600 events read in total (94056ms).
[11:55:58.257] <TB0> INFO: 2909670 events read in total (124956ms).
[11:56:29.649] <TB0> INFO: 3628785 events read in total (156348ms).
[11:56:53.639] <TB0> INFO: 4180800 events read in total (180338ms).
[11:56:53.771] <TB0> INFO: Test took 181302ms.
[11:57:22.873] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 192 (-1/-1) hits flags = 528 (plus default)
[11:57:22.891] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[11:57:22.891] <TB0> INFO: run 1 of 1
[11:57:23.162] <TB0> INFO: Expecting 4014400 events.
[11:57:55.129] <TB0> INFO: 743025 events read in total (31376ms).
[11:58:26.569] <TB0> INFO: 1482535 events read in total (62816ms).
[11:58:58.417] <TB0> INFO: 2221115 events read in total (94665ms).
[11:59:30.016] <TB0> INFO: 2954815 events read in total (126263ms).
[12:00:01.643] <TB0> INFO: 3685145 events read in total (157890ms).
[12:00:16.012] <TB0> INFO: 4014400 events read in total (172259ms).
[12:00:16.087] <TB0> INFO: Test took 173196ms.
[12:00:39.405] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 192 (-1/-1) hits flags = 528 (plus default)
[12:00:39.418] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[12:00:39.418] <TB0> INFO: run 1 of 1
[12:00:39.657] <TB0> INFO: Expecting 4014400 events.
[12:01:12.939] <TB0> INFO: 743620 events read in total (32691ms).
[12:01:44.771] <TB0> INFO: 1483185 events read in total (64523ms).
[12:02:16.833] <TB0> INFO: 2222340 events read in total (96585ms).
[12:02:48.606] <TB0> INFO: 2956895 events read in total (128358ms).
[12:03:20.278] <TB0> INFO: 3687960 events read in total (160030ms).
[12:03:34.662] <TB0> INFO: 4014400 events read in total (174414ms).
[12:03:34.752] <TB0> INFO: Test took 175334ms.
[12:04:00.330] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 192 (-1/-1) hits flags = 528 (plus default)
[12:04:00.343] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[12:04:00.343] <TB0> INFO: run 1 of 1
[12:04:00.581] <TB0> INFO: Expecting 4014400 events.
[12:04:33.423] <TB0> INFO: 744040 events read in total (32251ms).
[12:05:04.741] <TB0> INFO: 1483995 events read in total (63569ms).
[12:05:36.359] <TB0> INFO: 2222995 events read in total (95187ms).
[12:06:07.924] <TB0> INFO: 2957560 events read in total (126752ms).
[12:06:39.711] <TB0> INFO: 3688355 events read in total (158539ms).
[12:06:54.162] <TB0> INFO: 4014400 events read in total (172990ms).
[12:06:54.233] <TB0> INFO: Test took 173888ms.
[12:07:19.386] <TB0> INFO: PixTestTrim::trimBitTest() done
[12:07:19.387] <TB0> INFO: PixTestTrim::doTest() done, duration: 2443 seconds
[12:07:19.388] <TB0> INFO: Decoding statistics:
[12:07:19.388] <TB0> INFO: General information:
[12:07:19.388] <TB0> INFO: 16bit words read: 0
[12:07:19.388] <TB0> INFO: valid events total: 0
[12:07:19.388] <TB0> INFO: empty events: 0
[12:07:19.388] <TB0> INFO: valid events with pixels: 0
[12:07:19.388] <TB0> INFO: valid pixel hits: 0
[12:07:19.388] <TB0> INFO: Event errors: 0
[12:07:19.388] <TB0> INFO: start marker: 0
[12:07:19.388] <TB0> INFO: stop marker: 0
[12:07:19.388] <TB0> INFO: overflow: 0
[12:07:19.388] <TB0> INFO: invalid 5bit words: 0
[12:07:19.388] <TB0> INFO: invalid XOR eye diagram: 0
[12:07:19.388] <TB0> INFO: frame (failed synchr.): 0
[12:07:19.388] <TB0> INFO: idle data (no TBM trl): 0
[12:07:19.388] <TB0> INFO: no data (only TBM hdr): 0
[12:07:19.388] <TB0> INFO: TBM errors: 0
[12:07:19.388] <TB0> INFO: flawed TBM headers: 0
[12:07:19.388] <TB0> INFO: flawed TBM trailers: 0
[12:07:19.388] <TB0> INFO: event ID mismatches: 0
[12:07:19.388] <TB0> INFO: ROC errors: 0
[12:07:19.388] <TB0> INFO: missing ROC header(s): 0
[12:07:19.388] <TB0> INFO: misplaced readback start: 0
[12:07:19.388] <TB0> INFO: Pixel decoding errors: 0
[12:07:19.388] <TB0> INFO: pixel data incomplete: 0
[12:07:19.388] <TB0> INFO: pixel address: 0
[12:07:19.388] <TB0> INFO: pulse height fill bit: 0
[12:07:19.388] <TB0> INFO: buffer corruption: 0
[12:07:20.112] <TB0> INFO: ######################################################################
[12:07:20.112] <TB0> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:07:20.112] <TB0> INFO: ######################################################################
[12:07:20.366] <TB0> INFO: Expecting 41600 events.
[12:07:23.811] <TB0> INFO: 41600 events read in total (2853ms).
[12:07:23.812] <TB0> INFO: Test took 3699ms.
[12:07:24.250] <TB0> INFO: Expecting 41600 events.
[12:07:27.728] <TB0> INFO: 41600 events read in total (2886ms).
[12:07:27.729] <TB0> INFO: Test took 3715ms.
[12:07:28.020] <TB0> INFO: Expecting 41600 events.
[12:07:31.652] <TB0> INFO: 41600 events read in total (3040ms).
[12:07:31.652] <TB0> INFO: Test took 3897ms.
[12:07:31.941] <TB0> INFO: Expecting 41600 events.
[12:07:35.521] <TB0> INFO: 41600 events read in total (2988ms).
[12:07:35.522] <TB0> INFO: Test took 3846ms.
[12:07:35.814] <TB0> INFO: Expecting 41600 events.
[12:07:39.383] <TB0> INFO: 41600 events read in total (2978ms).
[12:07:39.384] <TB0> INFO: Test took 3836ms.
[12:07:39.673] <TB0> INFO: Expecting 41600 events.
[12:07:43.208] <TB0> INFO: 41600 events read in total (2943ms).
[12:07:43.209] <TB0> INFO: Test took 3801ms.
[12:07:43.498] <TB0> INFO: Expecting 41600 events.
[12:07:47.062] <TB0> INFO: 41600 events read in total (2972ms).
[12:07:47.062] <TB0> INFO: Test took 3829ms.
[12:07:47.351] <TB0> INFO: Expecting 41600 events.
[12:07:50.900] <TB0> INFO: 41600 events read in total (2957ms).
[12:07:50.901] <TB0> INFO: Test took 3814ms.
[12:07:51.189] <TB0> INFO: Expecting 41600 events.
[12:07:54.769] <TB0> INFO: 41600 events read in total (2988ms).
[12:07:54.770] <TB0> INFO: Test took 3845ms.
[12:07:55.060] <TB0> INFO: Expecting 41600 events.
[12:07:58.543] <TB0> INFO: 41600 events read in total (2891ms).
[12:07:58.544] <TB0> INFO: Test took 3749ms.
[12:07:58.834] <TB0> INFO: Expecting 41600 events.
[12:08:02.470] <TB0> INFO: 41600 events read in total (3045ms).
[12:08:02.471] <TB0> INFO: Test took 3903ms.
[12:08:02.761] <TB0> INFO: Expecting 41600 events.
[12:08:06.308] <TB0> INFO: 41600 events read in total (2956ms).
[12:08:06.309] <TB0> INFO: Test took 3813ms.
[12:08:06.599] <TB0> INFO: Expecting 41600 events.
[12:08:10.162] <TB0> INFO: 41600 events read in total (2971ms).
[12:08:10.163] <TB0> INFO: Test took 3829ms.
[12:08:10.452] <TB0> INFO: Expecting 41600 events.
[12:08:13.994] <TB0> INFO: 41600 events read in total (2949ms).
[12:08:13.996] <TB0> INFO: Test took 3809ms.
[12:08:14.350] <TB0> INFO: Expecting 41600 events.
[12:08:18.113] <TB0> INFO: 41600 events read in total (3171ms).
[12:08:18.114] <TB0> INFO: Test took 4088ms.
[12:08:18.469] <TB0> INFO: Expecting 41600 events.
[12:08:21.998] <TB0> INFO: 41600 events read in total (2933ms).
[12:08:21.999] <TB0> INFO: Test took 3857ms.
[12:08:22.290] <TB0> INFO: Expecting 41600 events.
[12:08:25.976] <TB0> INFO: 41600 events read in total (3095ms).
[12:08:25.977] <TB0> INFO: Test took 3952ms.
[12:08:26.336] <TB0> INFO: Expecting 41600 events.
[12:08:29.006] <TB0> INFO: 41600 events read in total (3079ms).
[12:08:29.007] <TB0> INFO: Test took 4004ms.
[12:08:30.306] <TB0> INFO: Expecting 41600 events.
[12:08:33.798] <TB0> INFO: 41600 events read in total (2901ms).
[12:08:33.799] <TB0> INFO: Test took 3765ms.
[12:08:34.091] <TB0> INFO: Expecting 41600 events.
[12:08:37.557] <TB0> INFO: 41600 events read in total (2874ms).
[12:08:37.558] <TB0> INFO: Test took 3731ms.
[12:08:37.846] <TB0> INFO: Expecting 41600 events.
[12:08:41.398] <TB0> INFO: 41600 events read in total (2960ms).
[12:08:41.398] <TB0> INFO: Test took 3817ms.
[12:08:41.687] <TB0> INFO: Expecting 41600 events.
[12:08:45.396] <TB0> INFO: 41600 events read in total (3117ms).
[12:08:45.396] <TB0> INFO: Test took 3973ms.
[12:08:45.686] <TB0> INFO: Expecting 41600 events.
[12:08:49.205] <TB0> INFO: 41600 events read in total (2927ms).
[12:08:49.205] <TB0> INFO: Test took 3784ms.
[12:08:49.499] <TB0> INFO: Expecting 41600 events.
[12:08:53.070] <TB0> INFO: 41600 events read in total (2980ms).
[12:08:53.071] <TB0> INFO: Test took 3841ms.
[12:08:53.396] <TB0> INFO: Expecting 41600 events.
[12:08:57.065] <TB0> INFO: 41600 events read in total (3078ms).
[12:08:57.066] <TB0> INFO: Test took 3966ms.
[12:08:57.357] <TB0> INFO: Expecting 41600 events.
[12:09:00.911] <TB0> INFO: 41600 events read in total (2962ms).
[12:09:00.912] <TB0> INFO: Test took 3820ms.
[12:09:01.201] <TB0> INFO: Expecting 41600 events.
[12:09:04.761] <TB0> INFO: 41600 events read in total (2968ms).
[12:09:04.762] <TB0> INFO: Test took 3826ms.
[12:09:05.054] <TB0> INFO: Expecting 41600 events.
[12:09:08.822] <TB0> INFO: 41600 events read in total (3176ms).
[12:09:08.823] <TB0> INFO: Test took 4034ms.
[12:09:09.116] <TB0> INFO: Expecting 41600 events.
[12:09:12.782] <TB0> INFO: 41600 events read in total (3074ms).
[12:09:12.783] <TB0> INFO: Test took 3932ms.
[12:09:13.073] <TB0> INFO: Expecting 2560 events.
[12:09:13.966] <TB0> INFO: 2560 events read in total (302ms).
[12:09:13.967] <TB0> INFO: Test took 1171ms.
[12:09:14.274] <TB0> INFO: Expecting 2560 events.
[12:09:15.158] <TB0> INFO: 2560 events read in total (292ms).
[12:09:15.159] <TB0> INFO: Test took 1192ms.
[12:09:15.466] <TB0> INFO: Expecting 2560 events.
[12:09:16.355] <TB0> INFO: 2560 events read in total (297ms).
[12:09:16.355] <TB0> INFO: Test took 1196ms.
[12:09:16.663] <TB0> INFO: Expecting 2560 events.
[12:09:17.559] <TB0> INFO: 2560 events read in total (304ms).
[12:09:17.560] <TB0> INFO: Test took 1204ms.
[12:09:17.868] <TB0> INFO: Expecting 2560 events.
[12:09:18.748] <TB0> INFO: 2560 events read in total (288ms).
[12:09:18.749] <TB0> INFO: Test took 1189ms.
[12:09:19.057] <TB0> INFO: Expecting 2560 events.
[12:09:19.935] <TB0> INFO: 2560 events read in total (286ms).
[12:09:19.935] <TB0> INFO: Test took 1185ms.
[12:09:20.243] <TB0> INFO: Expecting 2560 events.
[12:09:21.126] <TB0> INFO: 2560 events read in total (291ms).
[12:09:21.126] <TB0> INFO: Test took 1190ms.
[12:09:21.434] <TB0> INFO: Expecting 2560 events.
[12:09:22.322] <TB0> INFO: 2560 events read in total (296ms).
[12:09:22.322] <TB0> INFO: Test took 1195ms.
[12:09:22.631] <TB0> INFO: Expecting 2560 events.
[12:09:23.513] <TB0> INFO: 2560 events read in total (290ms).
[12:09:23.513] <TB0> INFO: Test took 1190ms.
[12:09:23.820] <TB0> INFO: Expecting 2560 events.
[12:09:24.703] <TB0> INFO: 2560 events read in total (291ms).
[12:09:24.704] <TB0> INFO: Test took 1190ms.
[12:09:25.012] <TB0> INFO: Expecting 2560 events.
[12:09:25.904] <TB0> INFO: 2560 events read in total (300ms).
[12:09:25.904] <TB0> INFO: Test took 1200ms.
[12:09:26.211] <TB0> INFO: Expecting 2560 events.
[12:09:27.096] <TB0> INFO: 2560 events read in total (293ms).
[12:09:27.096] <TB0> INFO: Test took 1191ms.
[12:09:27.404] <TB0> INFO: Expecting 2560 events.
[12:09:28.291] <TB0> INFO: 2560 events read in total (295ms).
[12:09:28.291] <TB0> INFO: Test took 1194ms.
[12:09:28.599] <TB0> INFO: Expecting 2560 events.
[12:09:29.491] <TB0> INFO: 2560 events read in total (300ms).
[12:09:29.491] <TB0> INFO: Test took 1199ms.
[12:09:29.798] <TB0> INFO: Expecting 2560 events.
[12:09:30.689] <TB0> INFO: 2560 events read in total (299ms).
[12:09:30.690] <TB0> INFO: Test took 1199ms.
[12:09:30.997] <TB0> INFO: Expecting 2560 events.
[12:09:31.881] <TB0> INFO: 2560 events read in total (292ms).
[12:09:31.881] <TB0> INFO: Test took 1191ms.
[12:09:31.885] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:09:32.190] <TB0> INFO: Expecting 655360 events.
[12:09:47.103] <TB0> INFO: 655360 events read in total (14322ms).
[12:09:47.116] <TB0> INFO: Expecting 655360 events.
[12:10:01.798] <TB0> INFO: 655360 events read in total (14278ms).
[12:10:01.819] <TB0> INFO: Expecting 655360 events.
[12:10:16.629] <TB0> INFO: 655360 events read in total (14407ms).
[12:10:16.649] <TB0> INFO: Expecting 655360 events.
[12:10:31.485] <TB0> INFO: 655360 events read in total (14433ms).
[12:10:31.510] <TB0> INFO: Expecting 655360 events.
[12:10:46.419] <TB0> INFO: 655360 events read in total (14506ms).
[12:10:46.448] <TB0> INFO: Expecting 655360 events.
[12:11:00.964] <TB0> INFO: 655360 events read in total (14113ms).
[12:11:00.002] <TB0> INFO: Expecting 655360 events.
[12:11:15.658] <TB0> INFO: 655360 events read in total (14253ms).
[12:11:15.701] <TB0> INFO: Expecting 655360 events.
[12:11:30.293] <TB0> INFO: 655360 events read in total (14189ms).
[12:11:30.336] <TB0> INFO: Expecting 655360 events.
[12:11:44.985] <TB0> INFO: 655360 events read in total (14246ms).
[12:11:45.056] <TB0> INFO: Expecting 655360 events.
[12:11:59.477] <TB0> INFO: 655360 events read in total (14018ms).
[12:11:59.531] <TB0> INFO: Expecting 655360 events.
[12:12:14.173] <TB0> INFO: 655360 events read in total (14239ms).
[12:12:14.243] <TB0> INFO: Expecting 655360 events.
[12:12:28.688] <TB0> INFO: 655360 events read in total (14042ms).
[12:12:28.755] <TB0> INFO: Expecting 655360 events.
[12:12:43.377] <TB0> INFO: 655360 events read in total (14219ms).
[12:12:43.467] <TB0> INFO: Expecting 655360 events.
[12:12:57.919] <TB0> INFO: 655360 events read in total (14050ms).
[12:12:57.990] <TB0> INFO: Expecting 655360 events.
[12:13:12.537] <TB0> INFO: 655360 events read in total (14144ms).
[12:13:12.668] <TB0> INFO: Expecting 655360 events.
[12:13:27.290] <TB0> INFO: 655360 events read in total (14219ms).
[12:13:27.398] <TB0> INFO: Test took 235513ms.
[12:13:27.496] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:27.750] <TB0> INFO: Expecting 655360 events.
[12:13:42.340] <TB0> INFO: 655360 events read in total (13998ms).
[12:13:42.353] <TB0> INFO: Expecting 655360 events.
[12:13:56.588] <TB0> INFO: 655360 events read in total (13832ms).
[12:13:56.604] <TB0> INFO: Expecting 655360 events.
[12:14:10.868] <TB0> INFO: 655360 events read in total (13861ms).
[12:14:10.889] <TB0> INFO: Expecting 655360 events.
[12:14:25.294] <TB0> INFO: 655360 events read in total (14002ms).
[12:14:25.319] <TB0> INFO: Expecting 655360 events.
[12:14:39.843] <TB0> INFO: 655360 events read in total (14121ms).
[12:14:39.872] <TB0> INFO: Expecting 655360 events.
[12:14:54.185] <TB0> INFO: 655360 events read in total (13910ms).
[12:14:54.235] <TB0> INFO: Expecting 655360 events.
[12:15:08.654] <TB0> INFO: 655360 events read in total (14015ms).
[12:15:08.693] <TB0> INFO: Expecting 655360 events.
[12:15:23.088] <TB0> INFO: 655360 events read in total (13992ms).
[12:15:23.150] <TB0> INFO: Expecting 655360 events.
[12:15:37.555] <TB0> INFO: 655360 events read in total (14002ms).
[12:15:37.628] <TB0> INFO: Expecting 655360 events.
[12:15:51.992] <TB0> INFO: 655360 events read in total (13961ms).
[12:15:52.051] <TB0> INFO: Expecting 655360 events.
[12:16:06.324] <TB0> INFO: 655360 events read in total (13869ms).
[12:16:06.397] <TB0> INFO: Expecting 655360 events.
[12:16:20.700] <TB0> INFO: 655360 events read in total (13900ms).
[12:16:20.764] <TB0> INFO: Expecting 655360 events.
[12:16:35.203] <TB0> INFO: 655360 events read in total (14036ms).
[12:16:35.285] <TB0> INFO: Expecting 655360 events.
[12:16:49.376] <TB0> INFO: 655360 events read in total (13688ms).
[12:16:49.449] <TB0> INFO: Expecting 655360 events.
[12:17:03.900] <TB0> INFO: 655360 events read in total (14047ms).
[12:17:04.019] <TB0> INFO: Expecting 655360 events.
[12:17:18.546] <TB0> INFO: 655360 events read in total (14124ms).
[12:17:18.643] <TB0> INFO: Test took 231147ms.
[12:17:18.810] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.816] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.822] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[12:17:18.828] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.834] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.840] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.845] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[12:17:18.851] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[12:17:18.857] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[12:17:18.863] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[12:17:18.869] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.874] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[12:17:18.880] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.886] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.892] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.898] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.904] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.909] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.915] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.921] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.927] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[12:17:18.933] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[12:17:18.938] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[12:17:18.944] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[12:17:18.950] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[12:17:18.955] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.961] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[12:17:18.967] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[12:17:18.001] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C0.dat
[12:17:18.001] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C1.dat
[12:17:18.001] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C2.dat
[12:17:18.001] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C3.dat
[12:17:18.001] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C4.dat
[12:17:18.001] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C5.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C6.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C7.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C8.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C9.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C10.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C11.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C12.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C13.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C14.dat
[12:17:18.002] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//dacParameters35_C15.dat
[12:17:19.242] <TB0> INFO: Expecting 41600 events.
[12:17:22.380] <TB0> INFO: 41600 events read in total (2546ms).
[12:17:22.381] <TB0> INFO: Test took 3376ms.
[12:17:22.855] <TB0> INFO: Expecting 41600 events.
[12:17:25.940] <TB0> INFO: 41600 events read in total (2493ms).
[12:17:25.941] <TB0> INFO: Test took 3350ms.
[12:17:26.429] <TB0> INFO: Expecting 41600 events.
[12:17:29.577] <TB0> INFO: 41600 events read in total (2556ms).
[12:17:29.578] <TB0> INFO: Test took 3425ms.
[12:17:29.795] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:29.884] <TB0> INFO: Expecting 2560 events.
[12:17:30.773] <TB0> INFO: 2560 events read in total (297ms).
[12:17:30.774] <TB0> INFO: Test took 979ms.
[12:17:30.777] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:31.081] <TB0> INFO: Expecting 2560 events.
[12:17:31.970] <TB0> INFO: 2560 events read in total (297ms).
[12:17:31.971] <TB0> INFO: Test took 1194ms.
[12:17:31.973] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:32.279] <TB0> INFO: Expecting 2560 events.
[12:17:33.172] <TB0> INFO: 2560 events read in total (301ms).
[12:17:33.172] <TB0> INFO: Test took 1199ms.
[12:17:33.175] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:33.479] <TB0> INFO: Expecting 2560 events.
[12:17:34.366] <TB0> INFO: 2560 events read in total (295ms).
[12:17:34.367] <TB0> INFO: Test took 1192ms.
[12:17:34.369] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:34.675] <TB0> INFO: Expecting 2560 events.
[12:17:35.571] <TB0> INFO: 2560 events read in total (304ms).
[12:17:35.571] <TB0> INFO: Test took 1202ms.
[12:17:35.576] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:35.878] <TB0> INFO: Expecting 2560 events.
[12:17:36.764] <TB0> INFO: 2560 events read in total (294ms).
[12:17:36.764] <TB0> INFO: Test took 1188ms.
[12:17:36.766] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:37.073] <TB0> INFO: Expecting 2560 events.
[12:17:37.964] <TB0> INFO: 2560 events read in total (299ms).
[12:17:37.964] <TB0> INFO: Test took 1198ms.
[12:17:37.969] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:38.272] <TB0> INFO: Expecting 2560 events.
[12:17:39.160] <TB0> INFO: 2560 events read in total (296ms).
[12:17:39.160] <TB0> INFO: Test took 1191ms.
[12:17:39.162] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:39.468] <TB0> INFO: Expecting 2560 events.
[12:17:40.350] <TB0> INFO: 2560 events read in total (290ms).
[12:17:40.350] <TB0> INFO: Test took 1188ms.
[12:17:40.353] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:40.658] <TB0> INFO: Expecting 2560 events.
[12:17:41.544] <TB0> INFO: 2560 events read in total (295ms).
[12:17:41.544] <TB0> INFO: Test took 1191ms.
[12:17:41.548] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:41.852] <TB0> INFO: Expecting 2560 events.
[12:17:42.735] <TB0> INFO: 2560 events read in total (291ms).
[12:17:42.736] <TB0> INFO: Test took 1188ms.
[12:17:42.739] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:43.044] <TB0> INFO: Expecting 2560 events.
[12:17:43.928] <TB0> INFO: 2560 events read in total (292ms).
[12:17:43.928] <TB0> INFO: Test took 1189ms.
[12:17:43.931] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:44.236] <TB0> INFO: Expecting 2560 events.
[12:17:45.116] <TB0> INFO: 2560 events read in total (288ms).
[12:17:45.116] <TB0> INFO: Test took 1185ms.
[12:17:45.119] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:45.425] <TB0> INFO: Expecting 2560 events.
[12:17:46.309] <TB0> INFO: 2560 events read in total (292ms).
[12:17:46.309] <TB0> INFO: Test took 1190ms.
[12:17:46.311] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:46.618] <TB0> INFO: Expecting 2560 events.
[12:17:47.498] <TB0> INFO: 2560 events read in total (289ms).
[12:17:47.498] <TB0> INFO: Test took 1187ms.
[12:17:47.501] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:47.806] <TB0> INFO: Expecting 2560 events.
[12:17:48.688] <TB0> INFO: 2560 events read in total (290ms).
[12:17:48.689] <TB0> INFO: Test took 1188ms.
[12:17:48.693] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:48.997] <TB0> INFO: Expecting 2560 events.
[12:17:49.889] <TB0> INFO: 2560 events read in total (300ms).
[12:17:49.890] <TB0> INFO: Test took 1197ms.
[12:17:49.893] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:50.197] <TB0> INFO: Expecting 2560 events.
[12:17:51.086] <TB0> INFO: 2560 events read in total (297ms).
[12:17:51.086] <TB0> INFO: Test took 1194ms.
[12:17:51.089] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:51.395] <TB0> INFO: Expecting 2560 events.
[12:17:52.281] <TB0> INFO: 2560 events read in total (295ms).
[12:17:52.282] <TB0> INFO: Test took 1193ms.
[12:17:52.284] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:52.591] <TB0> INFO: Expecting 2560 events.
[12:17:53.472] <TB0> INFO: 2560 events read in total (289ms).
[12:17:53.472] <TB0> INFO: Test took 1189ms.
[12:17:53.475] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:53.784] <TB0> INFO: Expecting 2560 events.
[12:17:54.672] <TB0> INFO: 2560 events read in total (297ms).
[12:17:54.673] <TB0> INFO: Test took 1198ms.
[12:17:54.675] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:54.981] <TB0> INFO: Expecting 2560 events.
[12:17:55.865] <TB0> INFO: 2560 events read in total (293ms).
[12:17:55.865] <TB0> INFO: Test took 1190ms.
[12:17:55.868] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:56.174] <TB0> INFO: Expecting 2560 events.
[12:17:57.054] <TB0> INFO: 2560 events read in total (288ms).
[12:17:57.054] <TB0> INFO: Test took 1187ms.
[12:17:57.059] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:57.362] <TB0> INFO: Expecting 2560 events.
[12:17:58.244] <TB0> INFO: 2560 events read in total (290ms).
[12:17:58.245] <TB0> INFO: Test took 1186ms.
[12:17:58.247] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:58.552] <TB0> INFO: Expecting 2560 events.
[12:17:59.439] <TB0> INFO: 2560 events read in total (296ms).
[12:17:59.439] <TB0> INFO: Test took 1192ms.
[12:17:59.443] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:17:59.748] <TB0> INFO: Expecting 2560 events.
[12:18:00.639] <TB0> INFO: 2560 events read in total (299ms).
[12:18:00.639] <TB0> INFO: Test took 1196ms.
[12:18:00.642] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:18:00.947] <TB0> INFO: Expecting 2560 events.
[12:18:01.839] <TB0> INFO: 2560 events read in total (301ms).
[12:18:01.839] <TB0> INFO: Test took 1198ms.
[12:18:01.842] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:18:02.148] <TB0> INFO: Expecting 2560 events.
[12:18:03.041] <TB0> INFO: 2560 events read in total (301ms).
[12:18:03.041] <TB0> INFO: Test took 1200ms.
[12:18:03.045] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:18:03.348] <TB0> INFO: Expecting 2560 events.
[12:18:04.235] <TB0> INFO: 2560 events read in total (295ms).
[12:18:04.235] <TB0> INFO: Test took 1190ms.
[12:18:04.239] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:18:04.544] <TB0> INFO: Expecting 2560 events.
[12:18:05.428] <TB0> INFO: 2560 events read in total (292ms).
[12:18:05.428] <TB0> INFO: Test took 1189ms.
[12:18:05.431] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:18:05.737] <TB0> INFO: Expecting 2560 events.
[12:18:06.628] <TB0> INFO: 2560 events read in total (299ms).
[12:18:06.628] <TB0> INFO: Test took 1198ms.
[12:18:06.631] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:18:06.936] <TB0> INFO: Expecting 2560 events.
[12:18:07.826] <TB0> INFO: 2560 events read in total (298ms).
[12:18:07.826] <TB0> INFO: Test took 1195ms.
[12:18:08.306] <TB0> INFO: PixTestPhOptimization::doTest() done, duration: 648 seconds
[12:18:08.306] <TB0> INFO: PH scale (per ROC): 44 49 44 42 53 42 44 47 47 37 49 54 41 46 45 35
[12:18:08.306] <TB0> INFO: PH offset (per ROC): 102 107 99 106 125 95 96 103 101 89 125 117 84 97 97 101
[12:18:08.313] <TB0> INFO: Decoding statistics:
[12:18:08.313] <TB0> INFO: General information:
[12:18:08.313] <TB0> INFO: 16bit words read: 127884
[12:18:08.313] <TB0> INFO: valid events total: 20480
[12:18:08.313] <TB0> INFO: empty events: 17978
[12:18:08.313] <TB0> INFO: valid events with pixels: 2502
[12:18:08.313] <TB0> INFO: valid pixel hits: 2502
[12:18:08.313] <TB0> INFO: Event errors: 0
[12:18:08.313] <TB0> INFO: start marker: 0
[12:18:08.313] <TB0> INFO: stop marker: 0
[12:18:08.313] <TB0> INFO: overflow: 0
[12:18:08.313] <TB0> INFO: invalid 5bit words: 0
[12:18:08.313] <TB0> INFO: invalid XOR eye diagram: 0
[12:18:08.313] <TB0> INFO: frame (failed synchr.): 0
[12:18:08.313] <TB0> INFO: idle data (no TBM trl): 0
[12:18:08.313] <TB0> INFO: no data (only TBM hdr): 0
[12:18:08.313] <TB0> INFO: TBM errors: 0
[12:18:08.313] <TB0> INFO: flawed TBM headers: 0
[12:18:08.313] <TB0> INFO: flawed TBM trailers: 0
[12:18:08.313] <TB0> INFO: event ID mismatches: 0
[12:18:08.313] <TB0> INFO: ROC errors: 0
[12:18:08.313] <TB0> INFO: missing ROC header(s): 0
[12:18:08.313] <TB0> INFO: misplaced readback start: 0
[12:18:08.313] <TB0> INFO: Pixel decoding errors: 0
[12:18:08.313] <TB0> INFO: pixel data incomplete: 0
[12:18:08.314] <TB0> INFO: pixel address: 0
[12:18:08.314] <TB0> INFO: pulse height fill bit: 0
[12:18:08.314] <TB0> INFO: buffer corruption: 0
[12:18:08.473] <TB0> INFO: ######################################################################
[12:18:08.473] <TB0> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:18:08.473] <TB0> INFO: ######################################################################
[12:18:08.489] <TB0> INFO: scanning low vcal = 10
[12:18:08.727] <TB0> INFO: Expecting 41600 events.
[12:18:12.316] <TB0> INFO: 41600 events read in total (2997ms).
[12:18:12.316] <TB0> INFO: Test took 3827ms.
[12:18:12.318] <TB0> INFO: scanning low vcal = 20
[12:18:12.612] <TB0> INFO: Expecting 41600 events.
[12:18:16.219] <TB0> INFO: 41600 events read in total (3016ms).
[12:18:16.220] <TB0> INFO: Test took 3902ms.
[12:18:16.221] <TB0> INFO: scanning low vcal = 30
[12:18:16.516] <TB0> INFO: Expecting 41600 events.
[12:18:20.159] <TB0> INFO: 41600 events read in total (3051ms).
[12:18:20.160] <TB0> INFO: Test took 3938ms.
[12:18:20.162] <TB0> INFO: scanning low vcal = 40
[12:18:20.440] <TB0> INFO: Expecting 41600 events.
[12:18:24.380] <TB0> INFO: 41600 events read in total (3349ms).
[12:18:24.381] <TB0> INFO: Test took 4219ms.
[12:18:24.385] <TB0> INFO: scanning low vcal = 50
[12:18:24.661] <TB0> INFO: Expecting 41600 events.
[12:18:28.644] <TB0> INFO: 41600 events read in total (3391ms).
[12:18:28.645] <TB0> INFO: Test took 4260ms.
[12:18:28.648] <TB0> INFO: scanning low vcal = 60
[12:18:28.925] <TB0> INFO: Expecting 41600 events.
[12:18:32.928] <TB0> INFO: 41600 events read in total (3411ms).
[12:18:32.929] <TB0> INFO: Test took 4281ms.
[12:18:32.931] <TB0> INFO: scanning low vcal = 70
[12:18:33.209] <TB0> INFO: Expecting 41600 events.
[12:18:37.227] <TB0> INFO: 41600 events read in total (3426ms).
[12:18:37.228] <TB0> INFO: Test took 4297ms.
[12:18:37.231] <TB0> INFO: scanning low vcal = 80
[12:18:37.509] <TB0> INFO: Expecting 41600 events.
[12:18:41.523] <TB0> INFO: 41600 events read in total (3423ms).
[12:18:41.524] <TB0> INFO: Test took 4293ms.
[12:18:41.526] <TB0> INFO: scanning low vcal = 90
[12:18:41.804] <TB0> INFO: Expecting 41600 events.
[12:18:45.867] <TB0> INFO: 41600 events read in total (3472ms).
[12:18:45.867] <TB0> INFO: Test took 4340ms.
[12:18:45.871] <TB0> INFO: scanning low vcal = 100
[12:18:46.150] <TB0> INFO: Expecting 41600 events.
[12:18:50.192] <TB0> INFO: 41600 events read in total (3450ms).
[12:18:50.193] <TB0> INFO: Test took 4321ms.
[12:18:50.195] <TB0> INFO: scanning low vcal = 110
[12:18:50.473] <TB0> INFO: Expecting 41600 events.
[12:18:54.517] <TB0> INFO: 41600 events read in total (3452ms).
[12:18:54.517] <TB0> INFO: Test took 4322ms.
[12:18:54.521] <TB0> INFO: scanning low vcal = 120
[12:18:54.798] <TB0> INFO: Expecting 41600 events.
[12:18:58.850] <TB0> INFO: 41600 events read in total (3460ms).
[12:18:58.851] <TB0> INFO: Test took 4330ms.
[12:18:58.854] <TB0> INFO: scanning low vcal = 130
[12:18:59.131] <TB0> INFO: Expecting 41600 events.
[12:19:03.193] <TB0> INFO: 41600 events read in total (3470ms).
[12:19:03.194] <TB0> INFO: Test took 4340ms.
[12:19:03.197] <TB0> INFO: scanning low vcal = 140
[12:19:03.477] <TB0> INFO: Expecting 41600 events.
[12:19:07.546] <TB0> INFO: 41600 events read in total (3477ms).
[12:19:07.547] <TB0> INFO: Test took 4350ms.
[12:19:07.550] <TB0> INFO: scanning low vcal = 150
[12:19:07.827] <TB0> INFO: Expecting 41600 events.
[12:19:11.860] <TB0> INFO: 41600 events read in total (3441ms).
[12:19:11.861] <TB0> INFO: Test took 4311ms.
[12:19:11.864] <TB0> INFO: scanning low vcal = 160
[12:19:12.142] <TB0> INFO: Expecting 41600 events.
[12:19:16.171] <TB0> INFO: 41600 events read in total (3437ms).
[12:19:16.172] <TB0> INFO: Test took 4308ms.
[12:19:16.176] <TB0> INFO: scanning low vcal = 170
[12:19:16.453] <TB0> INFO: Expecting 41600 events.
[12:19:20.492] <TB0> INFO: 41600 events read in total (3448ms).
[12:19:20.493] <TB0> INFO: Test took 4317ms.
[12:19:20.498] <TB0> INFO: scanning low vcal = 180
[12:19:20.773] <TB0> INFO: Expecting 41600 events.
[12:19:24.827] <TB0> INFO: 41600 events read in total (3462ms).
[12:19:24.827] <TB0> INFO: Test took 4329ms.
[12:19:24.830] <TB0> INFO: scanning low vcal = 190
[12:19:25.108] <TB0> INFO: Expecting 41600 events.
[12:19:29.146] <TB0> INFO: 41600 events read in total (3446ms).
[12:19:29.147] <TB0> INFO: Test took 4316ms.
[12:19:29.150] <TB0> INFO: scanning low vcal = 200
[12:19:29.427] <TB0> INFO: Expecting 41600 events.
[12:19:33.444] <TB0> INFO: 41600 events read in total (3426ms).
[12:19:33.445] <TB0> INFO: Test took 4295ms.
[12:19:33.448] <TB0> INFO: scanning low vcal = 210
[12:19:33.725] <TB0> INFO: Expecting 41600 events.
[12:19:37.735] <TB0> INFO: 41600 events read in total (3418ms).
[12:19:37.736] <TB0> INFO: Test took 4288ms.
[12:19:37.740] <TB0> INFO: scanning low vcal = 220
[12:19:38.017] <TB0> INFO: Expecting 41600 events.
[12:19:41.964] <TB0> INFO: 41600 events read in total (3355ms).
[12:19:41.965] <TB0> INFO: Test took 4225ms.
[12:19:41.969] <TB0> INFO: scanning low vcal = 230
[12:19:42.245] <TB0> INFO: Expecting 41600 events.
[12:19:46.211] <TB0> INFO: 41600 events read in total (3374ms).
[12:19:46.212] <TB0> INFO: Test took 4243ms.
[12:19:46.216] <TB0> INFO: scanning low vcal = 240
[12:19:46.492] <TB0> INFO: Expecting 41600 events.
[12:19:50.520] <TB0> INFO: 41600 events read in total (3436ms).
[12:19:50.521] <TB0> INFO: Test took 4305ms.
[12:19:50.524] <TB0> INFO: scanning low vcal = 250
[12:19:50.802] <TB0> INFO: Expecting 41600 events.
[12:19:54.787] <TB0> INFO: 41600 events read in total (3393ms).
[12:19:54.788] <TB0> INFO: Test took 4264ms.
[12:19:54.793] <TB0> INFO: scanning high vcal = 30 (= 210 in low range)
[12:19:55.069] <TB0> INFO: Expecting 41600 events.
[12:19:59.058] <TB0> INFO: 41600 events read in total (3397ms).
[12:19:59.059] <TB0> INFO: Test took 4266ms.
[12:19:59.062] <TB0> INFO: scanning high vcal = 50 (= 350 in low range)
[12:19:59.340] <TB0> INFO: Expecting 41600 events.
[12:20:03.333] <TB0> INFO: 41600 events read in total (3401ms).
[12:20:03.334] <TB0> INFO: Test took 4272ms.
[12:20:03.337] <TB0> INFO: scanning high vcal = 70 (= 490 in low range)
[12:20:03.615] <TB0> INFO: Expecting 41600 events.
[12:20:07.582] <TB0> INFO: 41600 events read in total (3376ms).
[12:20:07.583] <TB0> INFO: Test took 4245ms.
[12:20:07.587] <TB0> INFO: scanning high vcal = 90 (= 630 in low range)
[12:20:07.864] <TB0> INFO: Expecting 41600 events.
[12:20:11.824] <TB0> INFO: 41600 events read in total (3368ms).
[12:20:11.825] <TB0> INFO: Test took 4238ms.
[12:20:11.828] <TB0> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:20:12.105] <TB0> INFO: Expecting 41600 events.
[12:20:16.097] <TB0> INFO: 41600 events read in total (3400ms).
[12:20:16.098] <TB0> INFO: Test took 4270ms.
[12:20:16.542] <TB0> INFO: PixTestGainPedestal::measure() done
[12:20:49.879] <TB0> INFO: PixTestGainPedestal::fit() done
[12:20:49.879] <TB0> INFO: non-linearity mean: 0.923 0.970 0.924 0.949 0.980 0.928 0.913 0.949 0.934 0.927 0.980 0.980 0.953 0.937 0.916 0.923
[12:20:49.879] <TB0> INFO: non-linearity RMS: 0.114 0.025 0.103 0.047 0.004 0.088 0.087 0.052 0.097 0.130 0.004 0.004 0.189 0.080 0.079 0.128
[12:20:49.879] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C0.dat
[12:20:49.898] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C1.dat
[12:20:49.917] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C2.dat
[12:20:49.936] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C3.dat
[12:20:49.956] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C4.dat
[12:20:49.975] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C5.dat
[12:20:49.994] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C6.dat
[12:20:50.014] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C7.dat
[12:20:50.033] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C8.dat
[12:20:50.052] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C9.dat
[12:20:50.072] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C10.dat
[12:20:50.090] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C11.dat
[12:20:50.109] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C12.dat
[12:20:50.128] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C13.dat
[12:20:50.147] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C14.dat
[12:20:50.164] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1064_FullQualification_2016-10-25_10h38m_1477384707//001_Fulltest_p17//phCalibrationFitErr35_C15.dat
[12:20:50.177] <TB0> INFO: PixTestGainPedestal::fullTest() done, duration: 161 seconds
[12:20:50.177] <TB0> INFO: Decoding statistics:
[12:20:50.177] <TB0> INFO: General information:
[12:20:50.177] <TB0> INFO: 16bit words read: 3297430
[12:20:50.177] <TB0> INFO: valid events total: 332800
[12:20:50.177] <TB0> INFO: empty events: 644
[12:20:50.177] <TB0> INFO: valid events with pixels: 332156
[12:20:50.177] <TB0> INFO: valid pixel hits: 650315
[12:20:50.177] <TB0> INFO: Event errors: 0
[12:20:50.177] <TB0> INFO: start marker: 0
[12:20:50.177] <TB0> INFO: stop marker: 0
[12:20:50.177] <TB0> INFO: overflow: 0
[12:20:50.177] <TB0> INFO: invalid 5bit words: 0
[12:20:50.177] <TB0> INFO: invalid XOR eye diagram: 0
[12:20:50.177] <TB0> INFO: frame (failed synchr.): 0
[12:20:50.177] <TB0> INFO: idle data (no TBM trl): 0
[12:20:50.177] <TB0> INFO: no data (only TBM hdr): 0
[12:20:50.177] <TB0> INFO: TBM errors: 0
[12:20:50.177] <TB0> INFO: flawed TBM headers: 0
[12:20:50.177] <TB0> INFO: flawed TBM trailers: 0
[12:20:50.177] <TB0> INFO: event ID mismatches: 0
[12:20:50.177] <TB0> INFO: ROC errors: 0
[12:20:50.177] <TB0> INFO: missing ROC header(s): 0
[12:20:50.177] <TB0> INFO: misplaced readback start: 0
[12:20:50.177] <TB0> INFO: Pixel decoding errors: 0
[12:20:50.177] <TB0> INFO: pixel data incomplete: 0
[12:20:50.177] <TB0> INFO: pixel address: 0
[12:20:50.177] <TB0> INFO: pulse height fill bit: 0
[12:20:50.177] <TB0> INFO: buffer corruption: 0
[12:20:50.192] <TB0> INFO: Decoding statistics:
[12:20:50.192] <TB0> INFO: General information:
[12:20:50.192] <TB0> INFO: 16bit words read: 3426850
[12:20:50.192] <TB0> INFO: valid events total: 353536
[12:20:50.192] <TB0> INFO: empty events: 18878
[12:20:50.192] <TB0> INFO: valid events with pixels: 334658
[12:20:50.192] <TB0> INFO: valid pixel hits: 652817
[12:20:50.192] <TB0> INFO: Event errors: 0
[12:20:50.192] <TB0> INFO: start marker: 0
[12:20:50.192] <TB0> INFO: stop marker: 0
[12:20:50.192] <TB0> INFO: overflow: 0
[12:20:50.192] <TB0> INFO: invalid 5bit words: 0
[12:20:50.192] <TB0> INFO: invalid XOR eye diagram: 0
[12:20:50.192] <TB0> INFO: frame (failed synchr.): 0
[12:20:50.192] <TB0> INFO: idle data (no TBM trl): 0
[12:20:50.192] <TB0> INFO: no data (only TBM hdr): 0
[12:20:50.192] <TB0> INFO: TBM errors: 0
[12:20:50.192] <TB0> INFO: flawed TBM headers: 0
[12:20:50.192] <TB0> INFO: flawed TBM trailers: 0
[12:20:50.192] <TB0> INFO: event ID mismatches: 0
[12:20:50.192] <TB0> INFO: ROC errors: 0
[12:20:50.192] <TB0> INFO: missing ROC header(s): 0
[12:20:50.192] <TB0> INFO: misplaced readback start: 0
[12:20:50.192] <TB0> INFO: Pixel decoding errors: 0
[12:20:50.192] <TB0> INFO: pixel data incomplete: 0
[12:20:50.192] <TB0> INFO: pixel address: 0
[12:20:50.192] <TB0> INFO: pulse height fill bit: 0
[12:20:50.192] <TB0> INFO: buffer corruption: 0
[12:20:50.192] <TB0> INFO: enter test to run
[12:20:50.192] <TB0> INFO: test: exit no parameter change
[12:20:50.317] <TB0> QUIET: Connection to board 71 closed.
[12:20:50.319] <TB0> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud