Test Date: 2016-11-07 11:20
Analysis date: 2016-11-08 10:03
Logfile
LogfileView
[12:15:21.344] <TB0> INFO: *** Welcome to pxar ***
[12:15:21.344] <TB0> INFO: *** Today: 2016/11/07
[12:15:21.350] <TB0> INFO: *** Version: c8ba-dirty
[12:15:21.350] <TB0> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C15.dat
[12:15:21.351] <TB0> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//tbmParameters_C1b.dat
[12:15:21.351] <TB0> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//defaultMaskFile.dat
[12:15:21.351] <TB0> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters_C15.dat
[12:15:21.407] <TB0> INFO: clk: 4
[12:15:21.407] <TB0> INFO: ctr: 4
[12:15:21.407] <TB0> INFO: sda: 19
[12:15:21.407] <TB0> INFO: tin: 9
[12:15:21.407] <TB0> INFO: level: 15
[12:15:21.407] <TB0> INFO: triggerdelay: 0
[12:15:21.407] <TB0> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[12:15:21.407] <TB0> INFO: Log level: INFO
[12:15:21.416] <TB0> INFO: Found DTB DTB_WS6AYH
[12:15:21.423] <TB0> QUIET: Connection to board DTB_WS6AYH opened.
[12:15:21.425] <TB0> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 73
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WS6AYH
MAC address: 40D855118049
Hostname: pixelDTB073
Comment:
------------------------------------------------------
[12:15:21.427] <TB0> INFO: RPC call hashes of host and DTB match: 486171790
[12:15:22.912] <TB0> INFO: DUT info:
[12:15:22.912] <TB0> INFO: The DUT currently contains the following objects:
[12:15:22.912] <TB0> INFO: 4 TBM Cores tbm10c (4 ON)
[12:15:22.912] <TB0> INFO: TBM Core alpha (0): 7 registers set
[12:15:22.912] <TB0> INFO: TBM Core beta (1): 7 registers set
[12:15:22.912] <TB0> INFO: TBM Core alpha (2): 7 registers set
[12:15:22.912] <TB0> INFO: TBM Core beta (3): 7 registers set
[12:15:22.912] <TB0> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[12:15:22.912] <TB0> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.912] <TB0> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.913] <TB0> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.913] <TB0> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.913] <TB0> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.913] <TB0> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:22.913] <TB0> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:15:23.313] <TB0> INFO: enter 'restricted' command line mode
[12:15:23.313] <TB0> INFO: enter test to run
[12:15:23.313] <TB0> INFO: test: pretest no parameter change
[12:15:23.313] <TB0> INFO: running: pretest
[12:15:23.852] <TB0> INFO: ######################################################################
[12:15:23.852] <TB0> INFO: PixTestPretest::doTest()
[12:15:23.852] <TB0> INFO: ######################################################################
[12:15:23.853] <TB0> INFO: ----------------------------------------------------------------------
[12:15:23.853] <TB0> INFO: PixTestPretest::programROC()
[12:15:23.853] <TB0> INFO: ----------------------------------------------------------------------
[12:15:41.867] <TB0> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[12:15:41.867] <TB0> INFO: IA differences per ROC: 18.5 20.1 17.7 17.7 19.3 20.1 18.5 22.5 22.5 21.7 17.7 20.9 19.3 20.1 16.1 22.5
[12:15:41.902] <TB0> INFO: ----------------------------------------------------------------------
[12:15:41.902] <TB0> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[12:15:41.902] <TB0> INFO: ----------------------------------------------------------------------
[12:15:48.979] <TB0> INFO: PixTestPretest::setVana() done, Module Ia 380.2 mA = 23.7625 mA/ROC
[12:15:48.979] <TB0> INFO: i(loss) [mA/ROC]: 19.3 19.3 19.3 19.3 19.3 19.3 19.3 19.3 19.3 19.3 18.4 19.3 19.3 19.3 19.3 19.3
[12:15:49.006] <TB0> INFO: ----------------------------------------------------------------------
[12:15:49.006] <TB0> INFO: PixTestPretest::findTiming()
[12:15:49.006] <TB0> INFO: ----------------------------------------------------------------------
[12:15:49.006] <TB0> INFO: PixTestCmd::init()
[12:15:49.571] <TB0> WARNING: Not unmasking DUT, not setting Calibrate bits!

[12:16:20.264] <TB0> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[12:16:20.264] <TB0> INFO: (success/tries = 100/100), width = 3
[12:16:21.768] <TB0> INFO: ----------------------------------------------------------------------
[12:16:21.768] <TB0> INFO: PixTestPretest::findWorkingPixel()
[12:16:21.768] <TB0> INFO: ----------------------------------------------------------------------
[12:16:21.860] <TB0> INFO: Expecting 231680 events.
[12:16:31.586] <TB0> INFO: 231680 events read in total (9135ms).
[12:16:31.594] <TB0> INFO: Test took 9824ms.
[12:16:31.840] <TB0> INFO: Found working pixel in all ROCs: col/row = 12/22
[12:16:31.869] <TB0> INFO: ----------------------------------------------------------------------
[12:16:31.869] <TB0> INFO: PixTestPretest::setVthrCompCalDel()
[12:16:31.869] <TB0> INFO: ----------------------------------------------------------------------
[12:16:31.961] <TB0> INFO: Expecting 231680 events.
[12:16:41.611] <TB0> INFO: 231680 events read in total (9058ms).
[12:16:41.619] <TB0> INFO: Test took 9746ms.
[12:16:41.879] <TB0> INFO: PixTestPretest::setVthrCompCalDel() done
[12:16:41.879] <TB0> INFO: CalDel: 84 94 105 99 92 111 88 96 98 97 94 112 102 82 91 125
[12:16:41.879] <TB0> INFO: VthrComp: 51 51 51 51 52 51 51 51 51 51 55 51 51 51 53 51
[12:16:41.881] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C0.dat
[12:16:41.881] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C1.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C2.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C3.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C4.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C5.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C6.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C7.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C8.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C9.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C10.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C11.dat
[12:16:41.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C12.dat
[12:16:41.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C13.dat
[12:16:41.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C14.dat
[12:16:41.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters_C15.dat
[12:16:41.883] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//tbmParameters_C0a.dat
[12:16:41.883] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//tbmParameters_C0b.dat
[12:16:41.883] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//tbmParameters_C1a.dat
[12:16:41.883] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//tbmParameters_C1b.dat
[12:16:41.883] <TB0> INFO: PixTestPretest::doTest() done, duration: 78 seconds
[12:16:42.015] <TB0> INFO: enter test to run
[12:16:42.015] <TB0> INFO: test: FullTest no parameter change
[12:16:42.015] <TB0> INFO: running: fulltest
[12:16:42.015] <TB0> INFO: ######################################################################
[12:16:42.015] <TB0> INFO: PixTestFullTest::doTest()
[12:16:42.015] <TB0> INFO: ######################################################################
[12:16:42.016] <TB0> INFO: ######################################################################
[12:16:42.016] <TB0> INFO: PixTestAlive::doTest()
[12:16:42.016] <TB0> INFO: ######################################################################
[12:16:42.018] <TB0> INFO: ----------------------------------------------------------------------
[12:16:42.018] <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)
[12:16:42.018] <TB0> INFO: ----------------------------------------------------------------------
[12:16:42.250] <TB0> INFO: Expecting 41600 events.
[12:16:45.815] <TB0> INFO: 41600 events read in total (2973ms).
[12:16:45.816] <TB0> INFO: Test took 3797ms.
[12:16:46.044] <TB0> INFO: PixTestAlive::aliveTest() done
[12:16:46.044] <TB0> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 16 0 0 0 0 0 0
[12:16:46.046] <TB0> INFO: ----------------------------------------------------------------------
[12:16:46.046] <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)
[12:16:46.046] <TB0> INFO: ----------------------------------------------------------------------
[12:16:46.278] <TB0> INFO: Expecting 41600 events.
[12:16:49.202] <TB0> INFO: 41600 events read in total (2332ms).
[12:16:49.203] <TB0> INFO: Test took 3156ms.
[12:16:49.203] <TB0> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[12:16:49.443] <TB0> INFO: PixTestAlive::maskTest() done
[12:16:49.443] <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
[12:16:49.444] <TB0> INFO: ----------------------------------------------------------------------
[12:16:49.444] <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)
[12:16:49.444] <TB0> INFO: ----------------------------------------------------------------------
[12:16:49.677] <TB0> INFO: Expecting 41600 events.
[12:16:53.173] <TB0> INFO: 41600 events read in total (2904ms).
[12:16:53.174] <TB0> INFO: Test took 3728ms.
[12:16:53.401] <TB0> INFO: PixTestAlive::addressDecodingTest() done
[12:16:53.401] <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
[12:16:53.401] <TB0> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[12:16:53.401] <TB0> INFO: Decoding statistics:
[12:16:53.401] <TB0> INFO: General information:
[12:16:53.401] <TB0> INFO: 16bit words read: 0
[12:16:53.401] <TB0> INFO: valid events total: 0
[12:16:53.401] <TB0> INFO: empty events: 0
[12:16:53.401] <TB0> INFO: valid events with pixels: 0
[12:16:53.401] <TB0> INFO: valid pixel hits: 0
[12:16:53.401] <TB0> INFO: Event errors: 0
[12:16:53.401] <TB0> INFO: start marker: 0
[12:16:53.401] <TB0> INFO: stop marker: 0
[12:16:53.401] <TB0> INFO: overflow: 0
[12:16:53.401] <TB0> INFO: invalid 5bit words: 0
[12:16:53.401] <TB0> INFO: invalid XOR eye diagram: 0
[12:16:53.401] <TB0> INFO: frame (failed synchr.): 0
[12:16:53.401] <TB0> INFO: idle data (no TBM trl): 0
[12:16:53.401] <TB0> INFO: no data (only TBM hdr): 0
[12:16:53.401] <TB0> INFO: TBM errors: 0
[12:16:53.401] <TB0> INFO: flawed TBM headers: 0
[12:16:53.401] <TB0> INFO: flawed TBM trailers: 0
[12:16:53.401] <TB0> INFO: event ID mismatches: 0
[12:16:53.401] <TB0> INFO: ROC errors: 0
[12:16:53.401] <TB0> INFO: missing ROC header(s): 0
[12:16:53.401] <TB0> INFO: misplaced readback start: 0
[12:16:53.401] <TB0> INFO: Pixel decoding errors: 0
[12:16:53.401] <TB0> INFO: pixel data incomplete: 0
[12:16:53.401] <TB0> INFO: pixel address: 0
[12:16:53.401] <TB0> INFO: pulse height fill bit: 0
[12:16:53.401] <TB0> INFO: buffer corruption: 0
[12:16:53.410] <TB0> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C15.dat
[12:16:53.411] <TB0> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[12:16:53.411] <TB0> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[12:16:53.411] <TB0> INFO: ######################################################################
[12:16:53.411] <TB0> INFO: PixTestReadback::doTest()
[12:16:53.411] <TB0> INFO: ######################################################################
[12:16:53.411] <TB0> INFO: ----------------------------------------------------------------------
[12:16:53.411] <TB0> INFO: PixTestReadback::CalibrateVd()
[12:16:53.411] <TB0> INFO: ----------------------------------------------------------------------
[12:17:03.379] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C0.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C1.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C2.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C3.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C4.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C5.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C6.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C7.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C8.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C9.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C10.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C11.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C12.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C13.dat
[12:17:03.380] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C14.dat
[12:17:03.381] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C15.dat
[12:17:03.409] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[12:17:03.409] <TB0> INFO: ----------------------------------------------------------------------
[12:17:03.409] <TB0> INFO: PixTestReadback::CalibrateVa()
[12:17:03.409] <TB0> INFO: ----------------------------------------------------------------------
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C0.dat
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C1.dat
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C2.dat
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C3.dat
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C4.dat
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C5.dat
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C6.dat
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C7.dat
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C8.dat
[12:17:13.303] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C9.dat
[12:17:13.304] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C10.dat
[12:17:13.304] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C11.dat
[12:17:13.304] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C12.dat
[12:17:13.304] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C13.dat
[12:17:13.304] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C14.dat
[12:17:13.304] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C15.dat
[12:17:13.332] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[12:17:13.332] <TB0> INFO: ----------------------------------------------------------------------
[12:17:13.332] <TB0> INFO: PixTestReadback::readbackVbg()
[12:17:13.332] <TB0> INFO: ----------------------------------------------------------------------
[12:17:20.969] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[12:17:20.969] <TB0> INFO: ----------------------------------------------------------------------
[12:17:20.969] <TB0> INFO: PixTestReadback::getCalibratedVbg()
[12:17:20.969] <TB0> INFO: ----------------------------------------------------------------------
[12:17:20.969] <TB0> INFO: Vbg will be calibrated using Vd calibration
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 164.9calibrated Vbg = 1.18309 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 156.7calibrated Vbg = 1.18251 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 154.2calibrated Vbg = 1.16927 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 155.2calibrated Vbg = 1.17499 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 148.1calibrated Vbg = 1.17795 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 145.9calibrated Vbg = 1.18209 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 159.4calibrated Vbg = 1.17863 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 162.9calibrated Vbg = 1.17723 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 150.8calibrated Vbg = 1.17329 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 154.9calibrated Vbg = 1.17916 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 159.3calibrated Vbg = 1.16436 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 157.1calibrated Vbg = 1.16822 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 155.8calibrated Vbg = 1.17289 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 162.9calibrated Vbg = 1.17287 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 158.8calibrated Vbg = 1.17822 :::*/*/*/*/
[12:17:20.969] <TB0> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 157.6calibrated Vbg = 1.18397 :::*/*/*/*/
[12:17:20.971] <TB0> INFO: ----------------------------------------------------------------------
[12:17:20.971] <TB0> INFO: PixTestReadback::CalibrateIa()
[12:17:20.971] <TB0> INFO: ----------------------------------------------------------------------
[12:20:01.243] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C0.dat
[12:20:01.243] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C1.dat
[12:20:01.243] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C2.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C3.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C4.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C5.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C6.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C7.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C8.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C9.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C10.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C11.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C12.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C13.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C14.dat
[12:20:01.244] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//readbackCal_C15.dat
[12:20:01.274] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[12:20:01.275] <TB0> INFO: PixTestReadback::doTest() done
[12:20:01.275] <TB0> INFO: Decoding statistics:
[12:20:01.275] <TB0> INFO: General information:
[12:20:01.275] <TB0> INFO: 16bit words read: 1536
[12:20:01.275] <TB0> INFO: valid events total: 256
[12:20:01.275] <TB0> INFO: empty events: 256
[12:20:01.275] <TB0> INFO: valid events with pixels: 0
[12:20:01.275] <TB0> INFO: valid pixel hits: 0
[12:20:01.275] <TB0> INFO: Event errors: 0
[12:20:01.275] <TB0> INFO: start marker: 0
[12:20:01.275] <TB0> INFO: stop marker: 0
[12:20:01.275] <TB0> INFO: overflow: 0
[12:20:01.275] <TB0> INFO: invalid 5bit words: 0
[12:20:01.275] <TB0> INFO: invalid XOR eye diagram: 0
[12:20:01.275] <TB0> INFO: frame (failed synchr.): 0
[12:20:01.275] <TB0> INFO: idle data (no TBM trl): 0
[12:20:01.275] <TB0> INFO: no data (only TBM hdr): 0
[12:20:01.275] <TB0> INFO: TBM errors: 0
[12:20:01.275] <TB0> INFO: flawed TBM headers: 0
[12:20:01.275] <TB0> INFO: flawed TBM trailers: 0
[12:20:01.275] <TB0> INFO: event ID mismatches: 0
[12:20:01.275] <TB0> INFO: ROC errors: 0
[12:20:01.275] <TB0> INFO: missing ROC header(s): 0
[12:20:01.275] <TB0> INFO: misplaced readback start: 0
[12:20:01.275] <TB0> INFO: Pixel decoding errors: 0
[12:20:01.275] <TB0> INFO: pixel data incomplete: 0
[12:20:01.275] <TB0> INFO: pixel address: 0
[12:20:01.275] <TB0> INFO: pulse height fill bit: 0
[12:20:01.275] <TB0> INFO: buffer corruption: 0
[12:20:01.309] <TB0> INFO: ######################################################################
[12:20:01.309] <TB0> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[12:20:01.309] <TB0> INFO: ######################################################################
[12:20:01.311] <TB0> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[12:20:01.323] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[12:20:01.323] <TB0> INFO: run 1 of 1
[12:20:01.554] <TB0> INFO: Expecting 3120000 events.
[12:20:31.492] <TB0> INFO: 659235 events read in total (29346ms).
[12:20:43.517] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (164) != TBM ID (129)

[12:20:43.650] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 164 164 129 164 164 164 164 164

[12:20:43.650] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (165)

[12:20:43.650] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[12:20:43.650] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a8 80b1 4071 252 2def 4031 252 2def e022 c000

[12:20:43.650] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a2 8000 4030 252 2def 4030 252 2def e022 c000

[12:20:43.650] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a3 8040 4030 252 2def 4031 252 2def e022 c000

[12:20:43.650] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4031 4031 2def 4030 252 2ded e022 c000

[12:20:43.650] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a5 80c0 4060 252 2def 4060 252 2def e022 c000

[12:20:43.650] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a6 8000 4070 252 2def 4060 252 2def e022 c000

[12:20:43.650] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a7 8040 4070 252 2def 4070 252 2ded e022 c000

[12:21:01.045] <TB0> INFO: 1313895 events read in total (58899ms).
[12:21:13.036] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (232) != TBM ID (129)

[12:21:13.173] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 232 232 129 232 232 232 232 232

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

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

[12:21:13.173] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ec 80b1 4031 4b0 2fef 4071 4b0 2fef e022 c000

[12:21:13.173] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e6 8000 4030 4b0 2fef 4070 4b0 2fef e022 c000

[12:21:13.173] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e7 8040 4070 4b0 2fef 4070 4b0 2fef e022 c000

[12:21:13.173] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4031 4031 2fef 4030 4b0 2fef e022 c000

[12:21:13.174] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e9 80c0 4031 4b0 2fef 4071 4b0 2fef e022 c000

[12:21:13.174] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ea 8000 4071 4b0 2fef 4031 4b0 2fef e022 c000

[12:21:13.174] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0eb 8040 4031 4b0 2fef 4031 4b0 2fef e022 c000

[12:21:30.204] <TB0> INFO: 1965935 events read in total (88058ms).
[12:21:42.160] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (240) != TBM ID (129)

[12:21:42.295] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 240 240 129 240 240 240 240 240

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

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

[12:21:42.296] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f4 80b1 4030 4030 e022 c000

[12:21:42.296] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ee 8000 4060 4060 e022 c000

[12:21:42.296] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ef 8040 4073 4063 e022 c000

[12:21:42.296] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4031 4031 e022 c000

[12:21:42.296] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f1 80c0 4061 4061 e022 c000

[12:21:42.296] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f2 8000 4060 4070 e022 c000

[12:21:42.296] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f3 8040 4070 4071 e022 c000

[12:21:59.984] <TB0> INFO: 2616015 events read in total (117838ms).
[12:22:09.316] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (80) != TBM ID (129)

[12:22:09.451] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 80 80 129 80 80 80 80 80

[12:22:09.451] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (81)

[12:22:09.451] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[12:22:09.451] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a054 80b1 4030 4030 e022 c000

[12:22:09.451] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04e 8000 4070 4070 e022 c000

[12:22:09.451] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04f 8040 4033 4033 e022 c000

[12:22:09.451] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4031 4031 e022 c000

[12:22:09.451] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a051 80c0 4031 4071 e022 c000

[12:22:09.451] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a052 8000 4030 4030 e022 c000

[12:22:09.451] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a053 8040 4070 4031 e022 c000

[12:22:22.478] <TB0> INFO: 3120000 events read in total (140332ms).
[12:22:22.540] <TB0> INFO: Test took 141218ms.
[12:22:45.792] <TB0> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 164 seconds
[12:22:45.792] <TB0> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 15 0 0 1 0 0 0
[12:22:45.792] <TB0> INFO: separation cut (per ROC): 106 103 99 93 114 105 105 118 105 100 102 103 106 107 104 98
[12:22:45.792] <TB0> INFO: Decoding statistics:
[12:22:45.792] <TB0> INFO: General information:
[12:22:45.792] <TB0> INFO: 16bit words read: 0
[12:22:45.792] <TB0> INFO: valid events total: 0
[12:22:45.792] <TB0> INFO: empty events: 0
[12:22:45.792] <TB0> INFO: valid events with pixels: 0
[12:22:45.792] <TB0> INFO: valid pixel hits: 0
[12:22:45.792] <TB0> INFO: Event errors: 0
[12:22:45.792] <TB0> INFO: start marker: 0
[12:22:45.792] <TB0> INFO: stop marker: 0
[12:22:45.792] <TB0> INFO: overflow: 0
[12:22:45.792] <TB0> INFO: invalid 5bit words: 0
[12:22:45.792] <TB0> INFO: invalid XOR eye diagram: 0
[12:22:45.792] <TB0> INFO: frame (failed synchr.): 0
[12:22:45.792] <TB0> INFO: idle data (no TBM trl): 0
[12:22:45.792] <TB0> INFO: no data (only TBM hdr): 0
[12:22:45.792] <TB0> INFO: TBM errors: 0
[12:22:45.793] <TB0> INFO: flawed TBM headers: 0
[12:22:45.793] <TB0> INFO: flawed TBM trailers: 0
[12:22:45.793] <TB0> INFO: event ID mismatches: 0
[12:22:45.793] <TB0> INFO: ROC errors: 0
[12:22:45.793] <TB0> INFO: missing ROC header(s): 0
[12:22:45.793] <TB0> INFO: misplaced readback start: 0
[12:22:45.793] <TB0> INFO: Pixel decoding errors: 0
[12:22:45.793] <TB0> INFO: pixel data incomplete: 0
[12:22:45.793] <TB0> INFO: pixel address: 0
[12:22:45.793] <TB0> INFO: pulse height fill bit: 0
[12:22:45.793] <TB0> INFO: buffer corruption: 0
[12:22:45.841] <TB0> INFO: ######################################################################
[12:22:45.841] <TB0> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[12:22:45.841] <TB0> INFO: ######################################################################
[12:22:45.841] <TB0> INFO: ----------------------------------------------------------------------
[12:22:45.841] <TB0> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[12:22:45.841] <TB0> INFO: ----------------------------------------------------------------------
[12:22:45.841] <TB0> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[12:22:45.854] <TB0> INFO: dacScan split into 1 runs with ntrig = 50
[12:22:45.854] <TB0> INFO: run 1 of 1
[12:22:46.124] <TB0> INFO: Expecting 36608000 events.
[12:23:10.374] <TB0> INFO: 673150 events read in total (23659ms).
[12:23:32.678] <TB0> INFO: 1330650 events read in total (45963ms).
[12:23:54.741] <TB0> INFO: 1992100 events read in total (68026ms).
[12:24:17.061] <TB0> INFO: 2647550 events read in total (90346ms).
[12:24:39.202] <TB0> INFO: 3305500 events read in total (112487ms).
[12:25:01.553] <TB0> INFO: 3962400 events read in total (134838ms).
[12:25:23.636] <TB0> INFO: 4619350 events read in total (156921ms).
[12:25:45.875] <TB0> INFO: 5277700 events read in total (179160ms).
[12:26:08.264] <TB0> INFO: 5937050 events read in total (201549ms).
[12:26:30.859] <TB0> INFO: 6594650 events read in total (224144ms).
[12:26:53.230] <TB0> INFO: 7250800 events read in total (246515ms).
[12:27:15.650] <TB0> INFO: 7908000 events read in total (268935ms).
[12:27:37.899] <TB0> INFO: 8563850 events read in total (291184ms).
[12:28:00.287] <TB0> INFO: 9220600 events read in total (313572ms).
[12:28:22.350] <TB0> INFO: 9872500 events read in total (335635ms).
[12:28:44.442] <TB0> INFO: 10530000 events read in total (357727ms).
[12:29:06.324] <TB0> INFO: 11182400 events read in total (379609ms).
[12:29:28.642] <TB0> INFO: 11840450 events read in total (401927ms).
[12:29:50.753] <TB0> INFO: 12495300 events read in total (424038ms).
[12:30:13.066] <TB0> INFO: 13152750 events read in total (446351ms).
[12:30:35.424] <TB0> INFO: 13806800 events read in total (468709ms).
[12:30:57.685] <TB0> INFO: 14462500 events read in total (490970ms).
[12:31:20.105] <TB0> INFO: 15116700 events read in total (513390ms).
[12:31:42.382] <TB0> INFO: 15770700 events read in total (535667ms).
[12:32:04.636] <TB0> INFO: 16425650 events read in total (557921ms).
[12:32:26.822] <TB0> INFO: 17078300 events read in total (580107ms).
[12:32:49.353] <TB0> INFO: 17731150 events read in total (602638ms).
[12:33:11.500] <TB0> INFO: 18382650 events read in total (624785ms).
[12:33:33.733] <TB0> INFO: 19036600 events read in total (647018ms).
[12:33:55.816] <TB0> INFO: 19686900 events read in total (669101ms).
[12:34:17.943] <TB0> INFO: 20338700 events read in total (691228ms).
[12:34:40.014] <TB0> INFO: 20986800 events read in total (713299ms).
[12:35:02.292] <TB0> INFO: 21638400 events read in total (735577ms).
[12:35:24.277] <TB0> INFO: 22288900 events read in total (757562ms).
[12:35:46.525] <TB0> INFO: 22939250 events read in total (779810ms).
[12:36:08.694] <TB0> INFO: 23588600 events read in total (801979ms).
[12:36:30.813] <TB0> INFO: 24236350 events read in total (824098ms).
[12:36:52.711] <TB0> INFO: 24886000 events read in total (845996ms).
[12:37:15.048] <TB0> INFO: 25535350 events read in total (868333ms).
[12:37:36.912] <TB0> INFO: 26186650 events read in total (890197ms).
[12:37:59.133] <TB0> INFO: 26835100 events read in total (912418ms).
[12:38:21.243] <TB0> INFO: 27483800 events read in total (934528ms).
[12:38:43.215] <TB0> INFO: 28130850 events read in total (956500ms).
[12:39:05.108] <TB0> INFO: 28780250 events read in total (978393ms).
[12:39:27.012] <TB0> INFO: 29427400 events read in total (1000297ms).
[12:39:49.179] <TB0> INFO: 30077350 events read in total (1022464ms).
[12:40:11.182] <TB0> INFO: 30725800 events read in total (1044467ms).
[12:40:33.298] <TB0> INFO: 31372950 events read in total (1066583ms).
[12:40:55.165] <TB0> INFO: 32021800 events read in total (1088450ms).
[12:41:17.373] <TB0> INFO: 32672000 events read in total (1110658ms).
[12:41:39.348] <TB0> INFO: 33320250 events read in total (1132633ms).
[12:42:01.438] <TB0> INFO: 33967850 events read in total (1154723ms).
[12:42:23.645] <TB0> INFO: 34619050 events read in total (1176930ms).
[12:42:45.728] <TB0> INFO: 35268100 events read in total (1199013ms).
[12:43:07.617] <TB0> INFO: 35917550 events read in total (1220902ms).
[12:43:29.912] <TB0> INFO: 36577100 events read in total (1243197ms).
[12:43:31.320] <TB0> INFO: 36608000 events read in total (1244605ms).
[12:43:31.382] <TB0> INFO: Test took 1245528ms.
[12:43:31.845] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:33.569] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:35.487] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:37.045] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:38.483] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:39.959] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:41.754] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:43.504] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:45.303] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:47.228] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:49.127] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:51.235] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:53.175] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:55.101] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:57.289] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:43:59.498] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[12:44:01.942] <TB0> INFO: PixTestScurves::scurves() done
[12:44:01.942] <TB0> INFO: Vcal mean: 117.06 109.69 108.19 104.09 124.37 111.88 115.98 129.40 117.10 112.06 112.37 110.24 117.93 112.56 115.05 107.05
[12:44:01.942] <TB0> INFO: Vcal RMS: 5.65 5.37 5.32 5.29 7.22 4.58 5.36 5.89 5.82 8.74 5.99 6.41 5.87 4.87 5.67 4.98
[12:44:01.942] <TB0> INFO: PixTestScurves::fullTest() done, duration: 1276 seconds
[12:44:01.942] <TB0> INFO: Decoding statistics:
[12:44:01.942] <TB0> INFO: General information:
[12:44:01.942] <TB0> INFO: 16bit words read: 0
[12:44:01.942] <TB0> INFO: valid events total: 0
[12:44:01.942] <TB0> INFO: empty events: 0
[12:44:01.942] <TB0> INFO: valid events with pixels: 0
[12:44:01.942] <TB0> INFO: valid pixel hits: 0
[12:44:01.942] <TB0> INFO: Event errors: 0
[12:44:01.942] <TB0> INFO: start marker: 0
[12:44:01.942] <TB0> INFO: stop marker: 0
[12:44:01.942] <TB0> INFO: overflow: 0
[12:44:01.942] <TB0> INFO: invalid 5bit words: 0
[12:44:01.942] <TB0> INFO: invalid XOR eye diagram: 0
[12:44:01.942] <TB0> INFO: frame (failed synchr.): 0
[12:44:01.942] <TB0> INFO: idle data (no TBM trl): 0
[12:44:01.942] <TB0> INFO: no data (only TBM hdr): 0
[12:44:01.942] <TB0> INFO: TBM errors: 0
[12:44:01.942] <TB0> INFO: flawed TBM headers: 0
[12:44:01.942] <TB0> INFO: flawed TBM trailers: 0
[12:44:01.942] <TB0> INFO: event ID mismatches: 0
[12:44:01.942] <TB0> INFO: ROC errors: 0
[12:44:01.942] <TB0> INFO: missing ROC header(s): 0
[12:44:01.942] <TB0> INFO: misplaced readback start: 0
[12:44:01.942] <TB0> INFO: Pixel decoding errors: 0
[12:44:01.942] <TB0> INFO: pixel data incomplete: 0
[12:44:01.942] <TB0> INFO: pixel address: 0
[12:44:01.942] <TB0> INFO: pulse height fill bit: 0
[12:44:01.942] <TB0> INFO: buffer corruption: 0
[12:44:02.013] <TB0> INFO: ######################################################################
[12:44:02.013] <TB0> INFO: PixTestTrim::doTest()
[12:44:02.013] <TB0> INFO: ######################################################################
[12:44:02.014] <TB0> INFO: ----------------------------------------------------------------------
[12:44:02.015] <TB0> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[12:44:02.015] <TB0> INFO: ----------------------------------------------------------------------
[12:44:02.070] <TB0> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:44:02.070] <TB0> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:44:02.079] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[12:44:02.080] <TB0> INFO: run 1 of 1
[12:44:02.356] <TB0> INFO: Expecting 5025280 events.
[12:44:32.431] <TB0> INFO: 824552 events read in total (29480ms).
[12:45:02.174] <TB0> INFO: 1645768 events read in total (59223ms).
[12:45:31.796] <TB0> INFO: 2464192 events read in total (88845ms).
[12:46:01.483] <TB0> INFO: 3279472 events read in total (118532ms).
[12:46:30.627] <TB0> INFO: 4090544 events read in total (147677ms).
[12:47:00.091] <TB0> INFO: 4898968 events read in total (177140ms).
[12:47:05.134] <TB0> INFO: 5025280 events read in total (182183ms).
[12:47:05.177] <TB0> INFO: Test took 183097ms.
[12:47:23.315] <TB0> INFO: ROC 0 VthrComp = 118
[12:47:23.315] <TB0> INFO: ROC 1 VthrComp = 114
[12:47:23.315] <TB0> INFO: ROC 2 VthrComp = 113
[12:47:23.316] <TB0> INFO: ROC 3 VthrComp = 105
[12:47:23.316] <TB0> INFO: ROC 4 VthrComp = 130
[12:47:23.316] <TB0> INFO: ROC 5 VthrComp = 120
[12:47:23.316] <TB0> INFO: ROC 6 VthrComp = 119
[12:47:23.316] <TB0> INFO: ROC 7 VthrComp = 134
[12:47:23.317] <TB0> INFO: ROC 8 VthrComp = 127
[12:47:23.318] <TB0> INFO: ROC 9 VthrComp = 120
[12:47:23.318] <TB0> INFO: ROC 10 VthrComp = 112
[12:47:23.318] <TB0> INFO: ROC 11 VthrComp = 109
[12:47:23.318] <TB0> INFO: ROC 12 VthrComp = 121
[12:47:23.318] <TB0> INFO: ROC 13 VthrComp = 119
[12:47:23.318] <TB0> INFO: ROC 14 VthrComp = 113
[12:47:23.318] <TB0> INFO: ROC 15 VthrComp = 110
[12:47:23.554] <TB0> INFO: Expecting 41600 events.
[12:47:27.197] <TB0> INFO: 41600 events read in total (3051ms).
[12:47:27.198] <TB0> INFO: Test took 3878ms.
[12:47:27.208] <TB0> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:47:27.208] <TB0> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:47:27.218] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[12:47:27.218] <TB0> INFO: run 1 of 1
[12:47:27.496] <TB0> INFO: Expecting 5025280 events.
[12:47:53.669] <TB0> INFO: 590544 events read in total (25581ms).
[12:48:18.425] <TB0> INFO: 1179712 events read in total (50337ms).
[12:48:43.528] <TB0> INFO: 1769256 events read in total (75440ms).
[12:49:08.604] <TB0> INFO: 2358312 events read in total (100516ms).
[12:49:33.684] <TB0> INFO: 2945712 events read in total (125596ms).
[12:49:58.719] <TB0> INFO: 3532264 events read in total (150631ms).
[12:50:23.779] <TB0> INFO: 4117816 events read in total (175691ms).
[12:50:48.914] <TB0> INFO: 4703768 events read in total (200826ms).
[12:51:03.310] <TB0> INFO: 5025280 events read in total (215222ms).
[12:51:03.381] <TB0> INFO: Test took 216162ms.
[12:51:31.480] <TB0> INFO: roc 0 with ID = 0 has maximal Vcal 63.1751 for pixel 20/7 mean/min/max = 47.2043/31.186/63.2226
[12:51:31.480] <TB0> INFO: roc 1 with ID = 1 has maximal Vcal 60.3187 for pixel 11/2 mean/min/max = 46.0269/31.616/60.4379
[12:51:31.481] <TB0> INFO: roc 2 with ID = 2 has maximal Vcal 60.393 for pixel 18/1 mean/min/max = 46.2502/32.0493/60.4511
[12:51:31.481] <TB0> INFO: roc 3 with ID = 3 has maximal Vcal 61.4339 for pixel 9/8 mean/min/max = 47.9233/34.3669/61.4798
[12:51:31.481] <TB0> INFO: roc 4 with ID = 4 has maximal Vcal 60.6243 for pixel 47/77 mean/min/max = 46.1791/31.7132/60.6449
[12:51:31.482] <TB0> INFO: roc 5 with ID = 5 has maximal Vcal 58.6047 for pixel 33/7 mean/min/max = 45.3286/31.9804/58.6768
[12:51:31.482] <TB0> INFO: roc 6 with ID = 6 has maximal Vcal 60.7021 for pixel 20/9 mean/min/max = 45.7261/30.5637/60.8885
[12:51:31.482] <TB0> INFO: roc 7 with ID = 7 has maximal Vcal 63.5607 for pixel 9/20 mean/min/max = 48.6526/33.3588/63.9464
[12:51:31.483] <TB0> INFO: roc 8 with ID = 8 has maximal Vcal 60.9665 for pixel 17/0 mean/min/max = 45.6945/30.3903/60.9986
[12:51:31.483] <TB0> INFO: roc 9 with ID = 9 has maximal Vcal 60.6463 for pixel 51/6 mean/min/max = 46.0871/31.449/60.7253
[12:51:31.484] <TB0> INFO: roc 10 with ID = 10 has maximal Vcal 65.4717 for pixel 24/63 mean/min/max = 48.4127/31.1845/65.641
[12:51:31.484] <TB0> INFO: roc 11 with ID = 11 has maximal Vcal 64.8127 for pixel 10/16 mean/min/max = 48.913/32.8665/64.9596
[12:51:31.484] <TB0> INFO: roc 12 with ID = 12 has maximal Vcal 62.6253 for pixel 17/3 mean/min/max = 46.9488/31.2651/62.6325
[12:51:31.485] <TB0> INFO: roc 13 with ID = 13 has maximal Vcal 59.3125 for pixel 51/73 mean/min/max = 45.6/31.6099/59.59
[12:51:31.485] <TB0> INFO: roc 14 with ID = 14 has maximal Vcal 63.5061 for pixel 9/10 mean/min/max = 47.8831/32.1291/63.6372
[12:51:31.485] <TB0> INFO: roc 15 with ID = 15 has maximal Vcal 62.723 for pixel 43/0 mean/min/max = 48.1862/33.4765/62.8958
[12:51:31.486] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:51:31.574] <TB0> INFO: Expecting 411648 events.
[12:51:41.246] <TB0> INFO: 411648 events read in total (9080ms).
[12:51:41.255] <TB0> INFO: Expecting 411648 events.
[12:51:50.594] <TB0> INFO: 411648 events read in total (8936ms).
[12:51:50.603] <TB0> INFO: Expecting 411648 events.
[12:51:59.978] <TB0> INFO: 411648 events read in total (8964ms).
[12:51:59.991] <TB0> INFO: Expecting 411648 events.
[12:52:09.028] <TB0> INFO: 411648 events read in total (8634ms).
[12:52:09.043] <TB0> INFO: Expecting 411648 events.
[12:52:18.082] <TB0> INFO: 411648 events read in total (8636ms).
[12:52:18.099] <TB0> INFO: Expecting 411648 events.
[12:52:27.160] <TB0> INFO: 411648 events read in total (8658ms).
[12:52:27.179] <TB0> INFO: Expecting 411648 events.
[12:52:36.171] <TB0> INFO: 411648 events read in total (8589ms).
[12:52:36.193] <TB0> INFO: Expecting 411648 events.
[12:52:45.196] <TB0> INFO: 411648 events read in total (8600ms).
[12:52:45.230] <TB0> INFO: Expecting 411648 events.
[12:52:54.244] <TB0> INFO: 411648 events read in total (8611ms).
[12:52:54.280] <TB0> INFO: Expecting 411648 events.
[12:53:03.256] <TB0> INFO: 411648 events read in total (8574ms).
[12:53:03.286] <TB0> INFO: Expecting 411648 events.
[12:53:12.340] <TB0> INFO: 411648 events read in total (8651ms).
[12:53:12.370] <TB0> INFO: Expecting 411648 events.
[12:53:21.364] <TB0> INFO: 411648 events read in total (8591ms).
[12:53:21.402] <TB0> INFO: Expecting 411648 events.
[12:53:30.482] <TB0> INFO: 411648 events read in total (8677ms).
[12:53:30.520] <TB0> INFO: Expecting 411648 events.
[12:53:39.554] <TB0> INFO: 411648 events read in total (8631ms).
[12:53:39.593] <TB0> INFO: Expecting 411648 events.
[12:53:48.623] <TB0> INFO: 411648 events read in total (8627ms).
[12:53:48.667] <TB0> INFO: Expecting 411648 events.
[12:53:57.752] <TB0> INFO: 411648 events read in total (8682ms).
[12:53:57.799] <TB0> INFO: Test took 146313ms.
[12:53:58.641] <TB0> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[12:53:58.651] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[12:53:58.651] <TB0> INFO: run 1 of 1
[12:53:58.923] <TB0> INFO: Expecting 5025280 events.
[12:54:24.841] <TB0> INFO: 593464 events read in total (25327ms).
[12:54:50.294] <TB0> INFO: 1185560 events read in total (50780ms).
[12:55:15.747] <TB0> INFO: 1775688 events read in total (76233ms).
[12:55:41.346] <TB0> INFO: 2365480 events read in total (101832ms).
[12:56:06.795] <TB0> INFO: 2955568 events read in total (127281ms).
[12:56:32.496] <TB0> INFO: 3548416 events read in total (152982ms).
[12:56:57.705] <TB0> INFO: 4135280 events read in total (178191ms).
[12:57:22.987] <TB0> INFO: 4722440 events read in total (203473ms).
[12:57:36.238] <TB0> INFO: 5025280 events read in total (216724ms).
[12:57:36.350] <TB0> INFO: Test took 217699ms.
[12:58:00.298] <TB0> INFO: ---> TrimStepCorr4 extremal thresholds: 1.334473 .. 147.326504
[12:58:00.539] <TB0> INFO: Expecting 208000 events.
[12:58:10.275] <TB0> INFO: 208000 events read in total (9144ms).
[12:58:10.276] <TB0> INFO: Test took 9976ms.
[12:58:10.337] <TB0> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 1 .. 157 (-1/-1) hits flags = 528 (plus default)
[12:58:10.348] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[12:58:10.348] <TB0> INFO: run 1 of 1
[12:58:10.626] <TB0> INFO: Expecting 5224960 events.
[12:58:36.736] <TB0> INFO: 583840 events read in total (25518ms).
[12:59:02.168] <TB0> INFO: 1167896 events read in total (50950ms).
[12:59:27.458] <TB0> INFO: 1751696 events read in total (76240ms).
[12:59:52.864] <TB0> INFO: 2335896 events read in total (101646ms).
[13:00:18.141] <TB0> INFO: 2919712 events read in total (126923ms).
[13:00:43.684] <TB0> INFO: 3502800 events read in total (152466ms).
[13:01:09.118] <TB0> INFO: 4085344 events read in total (177900ms).
[13:01:34.396] <TB0> INFO: 4667616 events read in total (203178ms).
[13:01:58.620] <TB0> INFO: 5224960 events read in total (227402ms).
[13:01:58.737] <TB0> INFO: Test took 228389ms.
[13:02:24.302] <TB0> INFO: ---> TrimStepCorr2 extremal thresholds: 28.076300 .. 45.220970
[13:02:24.629] <TB0> INFO: Expecting 208000 events.
[13:02:34.559] <TB0> INFO: 208000 events read in total (9338ms).
[13:02:34.560] <TB0> INFO: Test took 10256ms.
[13:02:34.612] <TB0> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 18 .. 55 (-1/-1) hits flags = 528 (plus default)
[13:02:34.622] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:02:34.622] <TB0> INFO: run 1 of 1
[13:02:34.900] <TB0> INFO: Expecting 1264640 events.
[13:03:02.927] <TB0> INFO: 654824 events read in total (27436ms).
[13:03:28.858] <TB0> INFO: 1264640 events read in total (53368ms).
[13:03:28.885] <TB0> INFO: Test took 54264ms.
[13:03:41.864] <TB0> INFO: ---> TrimStepCorr1a extremal thresholds: 26.952820 .. 47.213023
[13:03:42.100] <TB0> INFO: Expecting 208000 events.
[13:03:51.761] <TB0> INFO: 208000 events read in total (9069ms).
[13:03:51.762] <TB0> INFO: Test took 9897ms.
[13:03:51.819] <TB0> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 57 (-1/-1) hits flags = 528 (plus default)
[13:03:51.829] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:03:51.829] <TB0> INFO: run 1 of 1
[13:03:52.109] <TB0> INFO: Expecting 1397760 events.
[13:04:20.162] <TB0> INFO: 655816 events read in total (27462ms).
[13:04:47.150] <TB0> INFO: 1310312 events read in total (54450ms).
[13:04:51.098] <TB0> INFO: 1397760 events read in total (58398ms).
[13:04:51.121] <TB0> INFO: Test took 59293ms.
[13:05:04.006] <TB0> INFO: ---> TrimStepCorr1b extremal thresholds: 25.076410 .. 47.694708
[13:05:04.251] <TB0> INFO: Expecting 208000 events.
[13:05:14.356] <TB0> INFO: 208000 events read in total (9514ms).
[13:05:14.357] <TB0> INFO: Test took 10350ms.
[13:05:14.405] <TB0> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 15 .. 57 (-1/-1) hits flags = 528 (plus default)
[13:05:14.415] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:05:14.415] <TB0> INFO: run 1 of 1
[13:05:14.693] <TB0> INFO: Expecting 1431040 events.
[13:05:42.875] <TB0> INFO: 658976 events read in total (27591ms).
[13:06:09.954] <TB0> INFO: 1318184 events read in total (54670ms).
[13:06:14.002] <TB0> INFO: 1431040 events read in total (59718ms).
[13:06:15.026] <TB0> INFO: Test took 60612ms.
[13:06:27.347] <TB0> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[13:06:27.347] <TB0> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[13:06:27.357] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:06:27.357] <TB0> INFO: run 1 of 1
[13:06:27.591] <TB0> INFO: Expecting 1364480 events.
[13:06:56.022] <TB0> INFO: 667808 events read in total (27839ms).
[13:07:23.491] <TB0> INFO: 1334896 events read in total (55308ms).
[13:07:25.137] <TB0> INFO: 1364480 events read in total (56954ms).
[13:07:25.172] <TB0> INFO: Test took 57815ms.
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C0.dat
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C1.dat
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C2.dat
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C3.dat
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C4.dat
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C5.dat
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C6.dat
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C7.dat
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C8.dat
[13:07:38.870] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C9.dat
[13:07:38.871] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C10.dat
[13:07:38.871] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C11.dat
[13:07:38.871] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C12.dat
[13:07:38.871] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C13.dat
[13:07:38.871] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C14.dat
[13:07:38.871] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C15.dat
[13:07:38.871] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C0.dat
[13:07:38.879] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C1.dat
[13:07:38.884] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C2.dat
[13:07:38.890] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C3.dat
[13:07:38.895] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C4.dat
[13:07:38.900] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C5.dat
[13:07:38.906] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C6.dat
[13:07:38.911] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C7.dat
[13:07:38.917] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C8.dat
[13:07:38.922] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C9.dat
[13:07:38.928] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C10.dat
[13:07:38.933] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C11.dat
[13:07:38.938] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C12.dat
[13:07:38.944] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C13.dat
[13:07:38.949] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C14.dat
[13:07:38.955] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//trimParameters35_C15.dat
[13:07:38.960] <TB0> INFO: PixTestTrim::trimTest() done
[13:07:38.960] <TB0> INFO: vtrim: 158 137 143 140 139 133 145 174 154 125 119 119 152 126 148 145
[13:07:38.960] <TB0> INFO: vthrcomp: 118 114 113 105 130 120 119 134 127 120 112 109 121 119 113 110
[13:07:38.960] <TB0> INFO: vcal mean: 34.91 34.94 34.97 34.98 34.95 35.10 35.00 34.97 34.90 34.92 35.17 35.03 35.00 34.95 35.09 34.99
[13:07:38.960] <TB0> INFO: vcal RMS: 1.19 1.08 1.04 1.03 1.11 1.02 1.27 1.16 1.14 2.48 1.37 1.13 1.21 1.03 1.26 1.06
[13:07:38.960] <TB0> INFO: bits mean: 10.15 9.63 9.92 9.02 9.61 10.22 10.63 9.59 10.40 9.65 9.81 9.00 10.24 9.84 9.99 9.20
[13:07:38.960] <TB0> INFO: bits RMS: 2.44 2.64 2.45 2.49 2.62 2.43 2.36 2.28 2.45 2.61 2.52 2.55 2.38 2.62 2.39 2.49
[13:07:38.967] <TB0> INFO: ----------------------------------------------------------------------
[13:07:38.967] <TB0> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[13:07:38.967] <TB0> INFO: ----------------------------------------------------------------------
[13:07:38.969] <TB0> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[13:07:38.980] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[13:07:38.980] <TB0> INFO: run 1 of 1
[13:07:39.217] <TB0> INFO: Expecting 4160000 events.
[13:08:11.198] <TB0> INFO: 740935 events read in total (31390ms).
[13:08:42.014] <TB0> INFO: 1476060 events read in total (62206ms).
[13:09:13.083] <TB0> INFO: 2208090 events read in total (93275ms).
[13:09:44.140] <TB0> INFO: 2934525 events read in total (124332ms).
[13:10:14.882] <TB0> INFO: 3658960 events read in total (155074ms).
[13:10:36.056] <TB0> INFO: 4160000 events read in total (176248ms).
[13:10:36.105] <TB0> INFO: Test took 177125ms.
[13:11:03.633] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 202 (-1/-1) hits flags = 528 (plus default)
[13:11:03.648] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[13:11:03.648] <TB0> INFO: run 1 of 1
[13:11:03.919] <TB0> INFO: Expecting 4222400 events.
[13:11:35.832] <TB0> INFO: 713205 events read in total (31322ms).
[13:12:05.840] <TB0> INFO: 1420955 events read in total (61330ms).
[13:12:35.935] <TB0> INFO: 2126270 events read in total (91426ms).
[13:13:05.747] <TB0> INFO: 2827000 events read in total (121237ms).
[13:13:35.867] <TB0> INFO: 3526155 events read in total (151357ms).
[13:14:05.803] <TB0> INFO: 4222400 events read in total (181293ms).
[13:14:05.860] <TB0> INFO: Test took 182211ms.
[13:14:35.037] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 200 (-1/-1) hits flags = 528 (plus default)
[13:14:35.047] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[13:14:35.047] <TB0> INFO: run 1 of 1
[13:14:35.320] <TB0> INFO: Expecting 4180800 events.
[13:15:07.294] <TB0> INFO: 716005 events read in total (31383ms).
[13:15:37.447] <TB0> INFO: 1426585 events read in total (61536ms).
[13:16:07.889] <TB0> INFO: 2134600 events read in total (91978ms).
[13:16:38.004] <TB0> INFO: 2837885 events read in total (122093ms).
[13:17:08.374] <TB0> INFO: 3539235 events read in total (152463ms).
[13:17:35.854] <TB0> INFO: 4180800 events read in total (179943ms).
[13:17:35.909] <TB0> INFO: Test took 180862ms.
[13:18:05.360] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[13:18:05.372] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[13:18:05.372] <TB0> INFO: run 1 of 1
[13:18:05.650] <TB0> INFO: Expecting 4160000 events.
[13:18:37.175] <TB0> INFO: 717490 events read in total (30933ms).
[13:19:07.373] <TB0> INFO: 1429475 events read in total (61131ms).
[13:19:37.643] <TB0> INFO: 2138875 events read in total (91401ms).
[13:20:08.004] <TB0> INFO: 2843280 events read in total (121762ms).
[13:20:38.435] <TB0> INFO: 3546200 events read in total (152193ms).
[13:21:04.760] <TB0> INFO: 4160000 events read in total (178518ms).
[13:21:04.814] <TB0> INFO: Test took 179442ms.
[13:21:33.644] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[13:21:33.654] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[13:21:33.654] <TB0> INFO: run 1 of 1
[13:21:33.896] <TB0> INFO: Expecting 4139200 events.
[13:22:05.422] <TB0> INFO: 719070 events read in total (30934ms).
[13:22:35.936] <TB0> INFO: 1432685 events read in total (61448ms).
[13:23:06.476] <TB0> INFO: 2143590 events read in total (91988ms).
[13:23:36.712] <TB0> INFO: 2849065 events read in total (122224ms).
[13:24:06.912] <TB0> INFO: 3553395 events read in total (152424ms).
[13:24:32.177] <TB0> INFO: 4139200 events read in total (177689ms).
[13:24:32.231] <TB0> INFO: Test took 178576ms.
[13:25:01.835] <TB0> INFO: PixTestTrim::trimBitTest() done
[13:25:01.837] <TB0> INFO: PixTestTrim::doTest() done, duration: 2459 seconds
[13:25:01.837] <TB0> INFO: Decoding statistics:
[13:25:01.837] <TB0> INFO: General information:
[13:25:01.837] <TB0> INFO: 16bit words read: 0
[13:25:01.837] <TB0> INFO: valid events total: 0
[13:25:01.837] <TB0> INFO: empty events: 0
[13:25:01.837] <TB0> INFO: valid events with pixels: 0
[13:25:01.837] <TB0> INFO: valid pixel hits: 0
[13:25:01.837] <TB0> INFO: Event errors: 0
[13:25:01.837] <TB0> INFO: start marker: 0
[13:25:01.837] <TB0> INFO: stop marker: 0
[13:25:01.837] <TB0> INFO: overflow: 0
[13:25:01.837] <TB0> INFO: invalid 5bit words: 0
[13:25:01.837] <TB0> INFO: invalid XOR eye diagram: 0
[13:25:01.837] <TB0> INFO: frame (failed synchr.): 0
[13:25:01.837] <TB0> INFO: idle data (no TBM trl): 0
[13:25:01.837] <TB0> INFO: no data (only TBM hdr): 0
[13:25:01.837] <TB0> INFO: TBM errors: 0
[13:25:01.837] <TB0> INFO: flawed TBM headers: 0
[13:25:01.837] <TB0> INFO: flawed TBM trailers: 0
[13:25:01.837] <TB0> INFO: event ID mismatches: 0
[13:25:01.837] <TB0> INFO: ROC errors: 0
[13:25:01.837] <TB0> INFO: missing ROC header(s): 0
[13:25:01.837] <TB0> INFO: misplaced readback start: 0
[13:25:01.837] <TB0> INFO: Pixel decoding errors: 0
[13:25:01.837] <TB0> INFO: pixel data incomplete: 0
[13:25:01.837] <TB0> INFO: pixel address: 0
[13:25:01.837] <TB0> INFO: pulse height fill bit: 0
[13:25:01.837] <TB0> INFO: buffer corruption: 0
[13:25:02.474] <TB0> INFO: ######################################################################
[13:25:02.474] <TB0> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[13:25:02.474] <TB0> INFO: ######################################################################
[13:25:02.706] <TB0> INFO: Expecting 41600 events.
[13:25:06.198] <TB0> INFO: 41600 events read in total (2900ms).
[13:25:06.199] <TB0> INFO: Test took 3724ms.
[13:25:06.635] <TB0> INFO: Expecting 41600 events.
[13:25:10.194] <TB0> INFO: 41600 events read in total (2967ms).
[13:25:10.195] <TB0> INFO: Test took 3791ms.
[13:25:10.485] <TB0> INFO: Expecting 41600 events.
[13:25:14.091] <TB0> INFO: 41600 events read in total (3014ms).
[13:25:14.091] <TB0> INFO: Test took 3871ms.
[13:25:14.379] <TB0> INFO: Expecting 41600 events.
[13:25:17.833] <TB0> INFO: 41600 events read in total (2862ms).
[13:25:17.834] <TB0> INFO: Test took 3719ms.
[13:25:18.122] <TB0> INFO: Expecting 41600 events.
[13:25:21.618] <TB0> INFO: 41600 events read in total (2904ms).
[13:25:21.619] <TB0> INFO: Test took 3761ms.
[13:25:21.908] <TB0> INFO: Expecting 41600 events.
[13:25:25.497] <TB0> INFO: 41600 events read in total (2997ms).
[13:25:25.497] <TB0> INFO: Test took 3854ms.
[13:25:25.797] <TB0> INFO: Expecting 41600 events.
[13:25:29.422] <TB0> INFO: 41600 events read in total (3033ms).
[13:25:29.423] <TB0> INFO: Test took 3902ms.
[13:25:29.714] <TB0> INFO: Expecting 41600 events.
[13:25:33.270] <TB0> INFO: 41600 events read in total (2965ms).
[13:25:33.271] <TB0> INFO: Test took 3822ms.
[13:25:33.561] <TB0> INFO: Expecting 41600 events.
[13:25:37.160] <TB0> INFO: 41600 events read in total (3008ms).
[13:25:37.161] <TB0> INFO: Test took 3865ms.
[13:25:37.452] <TB0> INFO: Expecting 41600 events.
[13:25:41.095] <TB0> INFO: 41600 events read in total (3052ms).
[13:25:41.096] <TB0> INFO: Test took 3909ms.
[13:25:41.388] <TB0> INFO: Expecting 41600 events.
[13:25:44.930] <TB0> INFO: 41600 events read in total (2950ms).
[13:25:44.931] <TB0> INFO: Test took 3808ms.
[13:25:45.219] <TB0> INFO: Expecting 41600 events.
[13:25:48.694] <TB0> INFO: 41600 events read in total (2883ms).
[13:25:48.695] <TB0> INFO: Test took 3741ms.
[13:25:48.983] <TB0> INFO: Expecting 41600 events.
[13:25:52.442] <TB0> INFO: 41600 events read in total (2868ms).
[13:25:52.443] <TB0> INFO: Test took 3725ms.
[13:25:52.731] <TB0> INFO: Expecting 41600 events.
[13:25:56.262] <TB0> INFO: 41600 events read in total (2940ms).
[13:25:56.263] <TB0> INFO: Test took 3797ms.
[13:25:56.561] <TB0> INFO: Expecting 41600 events.
[13:26:00.149] <TB0> INFO: 41600 events read in total (2997ms).
[13:26:00.150] <TB0> INFO: Test took 3863ms.
[13:26:00.440] <TB0> INFO: Expecting 41600 events.
[13:26:03.999] <TB0> INFO: 41600 events read in total (2968ms).
[13:26:03.000] <TB0> INFO: Test took 3825ms.
[13:26:04.294] <TB0> INFO: Expecting 41600 events.
[13:26:07.788] <TB0> INFO: 41600 events read in total (2903ms).
[13:26:07.789] <TB0> INFO: Test took 3764ms.
[13:26:08.089] <TB0> INFO: Expecting 41600 events.
[13:26:11.559] <TB0> INFO: 41600 events read in total (2878ms).
[13:26:11.559] <TB0> INFO: Test took 3746ms.
[13:26:11.847] <TB0> INFO: Expecting 41600 events.
[13:26:15.338] <TB0> INFO: 41600 events read in total (2899ms).
[13:26:15.338] <TB0> INFO: Test took 3756ms.
[13:26:15.629] <TB0> INFO: Expecting 41600 events.
[13:26:19.168] <TB0> INFO: 41600 events read in total (2948ms).
[13:26:19.169] <TB0> INFO: Test took 3805ms.
[13:26:19.457] <TB0> INFO: Expecting 41600 events.
[13:26:22.931] <TB0> INFO: 41600 events read in total (2882ms).
[13:26:22.931] <TB0> INFO: Test took 3739ms.
[13:26:23.222] <TB0> INFO: Expecting 41600 events.
[13:26:26.690] <TB0> INFO: 41600 events read in total (2877ms).
[13:26:26.690] <TB0> INFO: Test took 3733ms.
[13:26:26.978] <TB0> INFO: Expecting 41600 events.
[13:26:30.474] <TB0> INFO: 41600 events read in total (2904ms).
[13:26:30.474] <TB0> INFO: Test took 3761ms.
[13:26:30.765] <TB0> INFO: Expecting 41600 events.
[13:26:34.263] <TB0> INFO: 41600 events read in total (2906ms).
[13:26:34.263] <TB0> INFO: Test took 3765ms.
[13:26:34.554] <TB0> INFO: Expecting 41600 events.
[13:26:38.058] <TB0> INFO: 41600 events read in total (2912ms).
[13:26:38.059] <TB0> INFO: Test took 3770ms.
[13:26:38.358] <TB0> INFO: Expecting 41600 events.
[13:26:41.908] <TB0> INFO: 41600 events read in total (2958ms).
[13:26:41.909] <TB0> INFO: Test took 3827ms.
[13:26:42.197] <TB0> INFO: Expecting 41600 events.
[13:26:45.817] <TB0> INFO: 41600 events read in total (3028ms).
[13:26:45.817] <TB0> INFO: Test took 3884ms.
[13:26:46.112] <TB0> INFO: Expecting 41600 events.
[13:26:49.632] <TB0> INFO: 41600 events read in total (2929ms).
[13:26:49.633] <TB0> INFO: Test took 3792ms.
[13:26:49.922] <TB0> INFO: Expecting 41600 events.
[13:26:53.401] <TB0> INFO: 41600 events read in total (2887ms).
[13:26:53.401] <TB0> INFO: Test took 3743ms.
[13:26:53.693] <TB0> INFO: Expecting 2560 events.
[13:26:54.576] <TB0> INFO: 2560 events read in total (291ms).
[13:26:54.577] <TB0> INFO: Test took 1161ms.
[13:26:54.885] <TB0> INFO: Expecting 2560 events.
[13:26:55.767] <TB0> INFO: 2560 events read in total (291ms).
[13:26:55.767] <TB0> INFO: Test took 1190ms.
[13:26:56.075] <TB0> INFO: Expecting 2560 events.
[13:26:56.958] <TB0> INFO: 2560 events read in total (291ms).
[13:26:56.958] <TB0> INFO: Test took 1190ms.
[13:26:57.266] <TB0> INFO: Expecting 2560 events.
[13:26:58.148] <TB0> INFO: 2560 events read in total (291ms).
[13:26:58.148] <TB0> INFO: Test took 1190ms.
[13:26:58.456] <TB0> INFO: Expecting 2560 events.
[13:26:59.338] <TB0> INFO: 2560 events read in total (290ms).
[13:26:59.339] <TB0> INFO: Test took 1190ms.
[13:26:59.646] <TB0> INFO: Expecting 2560 events.
[13:27:00.528] <TB0> INFO: 2560 events read in total (290ms).
[13:27:00.529] <TB0> INFO: Test took 1190ms.
[13:27:00.837] <TB0> INFO: Expecting 2560 events.
[13:27:01.716] <TB0> INFO: 2560 events read in total (288ms).
[13:27:01.716] <TB0> INFO: Test took 1187ms.
[13:27:02.024] <TB0> INFO: Expecting 2560 events.
[13:27:02.903] <TB0> INFO: 2560 events read in total (287ms).
[13:27:02.903] <TB0> INFO: Test took 1186ms.
[13:27:03.210] <TB0> INFO: Expecting 2560 events.
[13:27:04.089] <TB0> INFO: 2560 events read in total (287ms).
[13:27:04.089] <TB0> INFO: Test took 1185ms.
[13:27:04.397] <TB0> INFO: Expecting 2560 events.
[13:27:05.279] <TB0> INFO: 2560 events read in total (291ms).
[13:27:05.279] <TB0> INFO: Test took 1189ms.
[13:27:05.586] <TB0> INFO: Expecting 2560 events.
[13:27:06.465] <TB0> INFO: 2560 events read in total (287ms).
[13:27:06.465] <TB0> INFO: Test took 1186ms.
[13:27:06.773] <TB0> INFO: Expecting 2560 events.
[13:27:07.653] <TB0> INFO: 2560 events read in total (288ms).
[13:27:07.653] <TB0> INFO: Test took 1187ms.
[13:27:07.961] <TB0> INFO: Expecting 2560 events.
[13:27:08.843] <TB0> INFO: 2560 events read in total (290ms).
[13:27:08.843] <TB0> INFO: Test took 1189ms.
[13:27:09.151] <TB0> INFO: Expecting 2560 events.
[13:27:10.033] <TB0> INFO: 2560 events read in total (290ms).
[13:27:10.034] <TB0> INFO: Test took 1190ms.
[13:27:10.341] <TB0> INFO: Expecting 2560 events.
[13:27:11.224] <TB0> INFO: 2560 events read in total (291ms).
[13:27:11.224] <TB0> INFO: Test took 1190ms.
[13:27:11.532] <TB0> INFO: Expecting 2560 events.
[13:27:12.417] <TB0> INFO: 2560 events read in total (294ms).
[13:27:12.417] <TB0> INFO: Test took 1193ms.
[13:27:12.420] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:27:12.726] <TB0> INFO: Expecting 655360 events.
[13:27:27.080] <TB0> INFO: 655360 events read in total (13762ms).
[13:27:27.091] <TB0> INFO: Expecting 655360 events.
[13:27:41.333] <TB0> INFO: 655360 events read in total (13839ms).
[13:27:41.348] <TB0> INFO: Expecting 655360 events.
[13:27:55.503] <TB0> INFO: 655360 events read in total (13752ms).
[13:27:55.522] <TB0> INFO: Expecting 655360 events.
[13:28:09.750] <TB0> INFO: 655360 events read in total (13825ms).
[13:28:09.773] <TB0> INFO: Expecting 655360 events.
[13:28:23.999] <TB0> INFO: 655360 events read in total (13823ms).
[13:28:24.025] <TB0> INFO: Expecting 655360 events.
[13:28:38.151] <TB0> INFO: 655360 events read in total (13723ms).
[13:28:38.183] <TB0> INFO: Expecting 655360 events.
[13:28:52.423] <TB0> INFO: 655360 events read in total (13837ms).
[13:28:52.458] <TB0> INFO: Expecting 655360 events.
[13:29:06.511] <TB0> INFO: 655360 events read in total (13650ms).
[13:29:06.551] <TB0> INFO: Expecting 655360 events.
[13:29:20.660] <TB0> INFO: 655360 events read in total (13706ms).
[13:29:20.718] <TB0> INFO: Expecting 655360 events.
[13:29:34.831] <TB0> INFO: 655360 events read in total (13710ms).
[13:29:34.880] <TB0> INFO: Expecting 655360 events.
[13:29:48.964] <TB0> INFO: 655360 events read in total (13681ms).
[13:29:49.018] <TB0> INFO: Expecting 655360 events.
[13:30:03.145] <TB0> INFO: 655360 events read in total (13724ms).
[13:30:03.202] <TB0> INFO: Expecting 655360 events.
[13:30:17.328] <TB0> INFO: 655360 events read in total (13723ms).
[13:30:17.409] <TB0> INFO: Expecting 655360 events.
[13:30:31.578] <TB0> INFO: 655360 events read in total (13766ms).
[13:30:31.645] <TB0> INFO: Expecting 655360 events.
[13:30:45.699] <TB0> INFO: 655360 events read in total (13651ms).
[13:30:45.792] <TB0> INFO: Expecting 655360 events.
[13:30:59.841] <TB0> INFO: 655360 events read in total (13646ms).
[13:30:59.915] <TB0> INFO: Test took 227495ms.
[13:30:59.993] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:31:00.258] <TB0> INFO: Expecting 655360 events.
[13:31:14.407] <TB0> INFO: 655360 events read in total (13553ms).
[13:31:14.419] <TB0> INFO: Expecting 655360 events.
[13:31:28.231] <TB0> INFO: 655360 events read in total (13409ms).
[13:31:28.245] <TB0> INFO: Expecting 655360 events.
[13:31:42.299] <TB0> INFO: 655360 events read in total (13651ms).
[13:31:42.317] <TB0> INFO: Expecting 655360 events.
[13:31:56.273] <TB0> INFO: 655360 events read in total (13553ms).
[13:31:56.296] <TB0> INFO: Expecting 655360 events.
[13:32:10.226] <TB0> INFO: 655360 events read in total (13527ms).
[13:32:10.261] <TB0> INFO: Expecting 655360 events.
[13:32:24.345] <TB0> INFO: 655360 events read in total (13681ms).
[13:32:24.386] <TB0> INFO: Expecting 655360 events.
[13:32:38.473] <TB0> INFO: 655360 events read in total (13684ms).
[13:32:38.508] <TB0> INFO: Expecting 655360 events.
[13:32:52.491] <TB0> INFO: 655360 events read in total (13580ms).
[13:32:52.532] <TB0> INFO: Expecting 655360 events.
[13:33:06.497] <TB0> INFO: 655360 events read in total (13562ms).
[13:33:06.542] <TB0> INFO: Expecting 655360 events.
[13:33:20.587] <TB0> INFO: 655360 events read in total (13642ms).
[13:33:20.637] <TB0> INFO: Expecting 655360 events.
[13:33:34.484] <TB0> INFO: 655360 events read in total (13444ms).
[13:33:34.556] <TB0> INFO: Expecting 655360 events.
[13:33:48.458] <TB0> INFO: 655360 events read in total (13499ms).
[13:33:48.516] <TB0> INFO: Expecting 655360 events.
[13:34:02.407] <TB0> INFO: 655360 events read in total (13488ms).
[13:34:02.470] <TB0> INFO: Expecting 655360 events.
[13:34:16.348] <TB0> INFO: 655360 events read in total (13475ms).
[13:34:16.415] <TB0> INFO: Expecting 655360 events.
[13:34:30.361] <TB0> INFO: 655360 events read in total (13543ms).
[13:34:30.431] <TB0> INFO: Expecting 655360 events.
[13:34:44.406] <TB0> INFO: 655360 events read in total (13572ms).
[13:34:44.480] <TB0> INFO: Test took 224487ms.
[13:34:44.699] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.704] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[13:34:44.708] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.713] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.718] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.722] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.727] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.731] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.736] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.740] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.745] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[13:34:44.749] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[13:34:44.754] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[13:34:44.759] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[13:34:44.763] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[13:34:44.768] <TB0> INFO: safety margin for low PH: adding 6, margin is now 26
[13:34:44.773] <TB0> INFO: safety margin for low PH: adding 7, margin is now 27
[13:34:44.778] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.782] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.787] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.792] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.797] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[13:34:44.802] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[13:34:44.806] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.811] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[13:34:44.816] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.822] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[13:34:44.827] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[13:34:44.832] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[13:34:44.836] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[13:34:44.841] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[13:34:44.848] <TB0> INFO: safety margin for low PH: adding 6, margin is now 26
[13:34:44.854] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[13:34:44.860] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[13:34:44.866] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[13:34:44.873] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[13:34:44.879] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[13:34:44.913] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C0.dat
[13:34:44.914] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C1.dat
[13:34:44.914] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C2.dat
[13:34:44.914] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C3.dat
[13:34:44.914] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C4.dat
[13:34:44.914] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C5.dat
[13:34:44.914] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C6.dat
[13:34:44.914] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C7.dat
[13:34:44.914] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C8.dat
[13:34:44.915] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C9.dat
[13:34:44.915] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C10.dat
[13:34:44.915] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C11.dat
[13:34:44.915] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C12.dat
[13:34:44.915] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C13.dat
[13:34:44.915] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C14.dat
[13:34:44.915] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//dacParameters35_C15.dat
[13:34:45.152] <TB0> INFO: Expecting 41600 events.
[13:34:48.246] <TB0> INFO: 41600 events read in total (2502ms).
[13:34:48.246] <TB0> INFO: Test took 3328ms.
[13:34:48.696] <TB0> INFO: Expecting 41600 events.
[13:34:51.743] <TB0> INFO: 41600 events read in total (2455ms).
[13:34:51.743] <TB0> INFO: Test took 3285ms.
[13:34:52.186] <TB0> INFO: Expecting 41600 events.
[13:34:55.275] <TB0> INFO: 41600 events read in total (2498ms).
[13:34:55.275] <TB0> INFO: Test took 3321ms.
[13:34:55.489] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:34:55.578] <TB0> INFO: Expecting 2560 events.
[13:34:56.459] <TB0> INFO: 2560 events read in total (290ms).
[13:34:56.460] <TB0> INFO: Test took 971ms.
[13:34:56.461] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:34:56.768] <TB0> INFO: Expecting 2560 events.
[13:34:57.652] <TB0> INFO: 2560 events read in total (292ms).
[13:34:57.652] <TB0> INFO: Test took 1191ms.
[13:34:57.654] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:34:57.960] <TB0> INFO: Expecting 2560 events.
[13:34:58.848] <TB0> INFO: 2560 events read in total (297ms).
[13:34:58.848] <TB0> INFO: Test took 1194ms.
[13:34:58.850] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:34:59.156] <TB0> INFO: Expecting 2560 events.
[13:35:00.039] <TB0> INFO: 2560 events read in total (291ms).
[13:35:00.039] <TB0> INFO: Test took 1189ms.
[13:35:00.041] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:00.348] <TB0> INFO: Expecting 2560 events.
[13:35:01.233] <TB0> INFO: 2560 events read in total (294ms).
[13:35:01.233] <TB0> INFO: Test took 1192ms.
[13:35:01.235] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:01.545] <TB0> INFO: Expecting 2560 events.
[13:35:02.428] <TB0> INFO: 2560 events read in total (291ms).
[13:35:02.428] <TB0> INFO: Test took 1193ms.
[13:35:02.430] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:02.736] <TB0> INFO: Expecting 2560 events.
[13:35:03.619] <TB0> INFO: 2560 events read in total (291ms).
[13:35:03.619] <TB0> INFO: Test took 1189ms.
[13:35:03.621] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:03.927] <TB0> INFO: Expecting 2560 events.
[13:35:04.810] <TB0> INFO: 2560 events read in total (291ms).
[13:35:04.811] <TB0> INFO: Test took 1190ms.
[13:35:04.813] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:05.119] <TB0> INFO: Expecting 2560 events.
[13:35:05.997] <TB0> INFO: 2560 events read in total (287ms).
[13:35:05.997] <TB0> INFO: Test took 1184ms.
[13:35:05.999] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:06.306] <TB0> INFO: Expecting 2560 events.
[13:35:07.188] <TB0> INFO: 2560 events read in total (291ms).
[13:35:07.189] <TB0> INFO: Test took 1190ms.
[13:35:07.191] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:07.497] <TB0> INFO: Expecting 2560 events.
[13:35:08.375] <TB0> INFO: 2560 events read in total (286ms).
[13:35:08.375] <TB0> INFO: Test took 1184ms.
[13:35:08.377] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:08.684] <TB0> INFO: Expecting 2560 events.
[13:35:09.561] <TB0> INFO: 2560 events read in total (286ms).
[13:35:09.562] <TB0> INFO: Test took 1185ms.
[13:35:09.563] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:09.870] <TB0> INFO: Expecting 2560 events.
[13:35:10.748] <TB0> INFO: 2560 events read in total (287ms).
[13:35:10.748] <TB0> INFO: Test took 1185ms.
[13:35:10.750] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:11.056] <TB0> INFO: Expecting 2560 events.
[13:35:11.934] <TB0> INFO: 2560 events read in total (286ms).
[13:35:11.934] <TB0> INFO: Test took 1184ms.
[13:35:11.936] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:12.243] <TB0> INFO: Expecting 2560 events.
[13:35:13.120] <TB0> INFO: 2560 events read in total (286ms).
[13:35:13.120] <TB0> INFO: Test took 1184ms.
[13:35:13.123] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:13.429] <TB0> INFO: Expecting 2560 events.
[13:35:14.306] <TB0> INFO: 2560 events read in total (286ms).
[13:35:14.307] <TB0> INFO: Test took 1184ms.
[13:35:14.308] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:14.614] <TB0> INFO: Expecting 2560 events.
[13:35:15.492] <TB0> INFO: 2560 events read in total (286ms).
[13:35:15.492] <TB0> INFO: Test took 1184ms.
[13:35:15.495] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:15.801] <TB0> INFO: Expecting 2560 events.
[13:35:16.678] <TB0> INFO: 2560 events read in total (286ms).
[13:35:16.678] <TB0> INFO: Test took 1183ms.
[13:35:16.680] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:16.987] <TB0> INFO: Expecting 2560 events.
[13:35:17.868] <TB0> INFO: 2560 events read in total (290ms).
[13:35:17.868] <TB0> INFO: Test took 1188ms.
[13:35:17.870] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:18.177] <TB0> INFO: Expecting 2560 events.
[13:35:19.059] <TB0> INFO: 2560 events read in total (291ms).
[13:35:19.059] <TB0> INFO: Test took 1189ms.
[13:35:19.061] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:19.368] <TB0> INFO: Expecting 2560 events.
[13:35:20.249] <TB0> INFO: 2560 events read in total (290ms).
[13:35:20.249] <TB0> INFO: Test took 1188ms.
[13:35:20.251] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:20.558] <TB0> INFO: Expecting 2560 events.
[13:35:21.437] <TB0> INFO: 2560 events read in total (288ms).
[13:35:21.437] <TB0> INFO: Test took 1186ms.
[13:35:21.439] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:21.746] <TB0> INFO: Expecting 2560 events.
[13:35:22.623] <TB0> INFO: 2560 events read in total (286ms).
[13:35:22.624] <TB0> INFO: Test took 1185ms.
[13:35:22.626] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:22.932] <TB0> INFO: Expecting 2560 events.
[13:35:23.813] <TB0> INFO: 2560 events read in total (290ms).
[13:35:23.813] <TB0> INFO: Test took 1187ms.
[13:35:23.815] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:24.121] <TB0> INFO: Expecting 2560 events.
[13:35:25.003] <TB0> INFO: 2560 events read in total (290ms).
[13:35:25.003] <TB0> INFO: Test took 1188ms.
[13:35:25.005] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:25.312] <TB0> INFO: Expecting 2560 events.
[13:35:26.195] <TB0> INFO: 2560 events read in total (292ms).
[13:35:26.195] <TB0> INFO: Test took 1190ms.
[13:35:26.197] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:26.503] <TB0> INFO: Expecting 2560 events.
[13:35:27.386] <TB0> INFO: 2560 events read in total (291ms).
[13:35:27.386] <TB0> INFO: Test took 1189ms.
[13:35:27.388] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:27.695] <TB0> INFO: Expecting 2560 events.
[13:35:28.577] <TB0> INFO: 2560 events read in total (291ms).
[13:35:28.577] <TB0> INFO: Test took 1189ms.
[13:35:28.579] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:28.886] <TB0> INFO: Expecting 2560 events.
[13:35:29.767] <TB0> INFO: 2560 events read in total (290ms).
[13:35:29.767] <TB0> INFO: Test took 1188ms.
[13:35:29.769] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:30.076] <TB0> INFO: Expecting 2560 events.
[13:35:30.958] <TB0> INFO: 2560 events read in total (291ms).
[13:35:30.959] <TB0> INFO: Test took 1190ms.
[13:35:30.961] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:31.267] <TB0> INFO: Expecting 2560 events.
[13:35:32.149] <TB0> INFO: 2560 events read in total (290ms).
[13:35:32.149] <TB0> INFO: Test took 1188ms.
[13:35:32.151] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:35:32.458] <TB0> INFO: Expecting 2560 events.
[13:35:33.344] <TB0> INFO: 2560 events read in total (295ms).
[13:35:33.345] <TB0> INFO: Test took 1194ms.
[13:35:33.807] <TB0> INFO: PixTestPhOptimization::doTest() done, duration: 631 seconds
[13:35:33.807] <TB0> INFO: PH scale (per ROC): 55 55 67 68 43 39 54 55 49 55 36 48 48 55 52 37
[13:35:33.807] <TB0> INFO: PH offset (per ROC): 125 114 126 134 94 101 124 123 113 110 101 110 111 107 112 101
[13:35:33.812] <TB0> INFO: Decoding statistics:
[13:35:33.812] <TB0> INFO: General information:
[13:35:33.812] <TB0> INFO: 16bit words read: 127880
[13:35:33.812] <TB0> INFO: valid events total: 20480
[13:35:33.812] <TB0> INFO: empty events: 17980
[13:35:33.812] <TB0> INFO: valid events with pixels: 2500
[13:35:33.812] <TB0> INFO: valid pixel hits: 2500
[13:35:33.812] <TB0> INFO: Event errors: 0
[13:35:33.812] <TB0> INFO: start marker: 0
[13:35:33.812] <TB0> INFO: stop marker: 0
[13:35:33.812] <TB0> INFO: overflow: 0
[13:35:33.812] <TB0> INFO: invalid 5bit words: 0
[13:35:33.812] <TB0> INFO: invalid XOR eye diagram: 0
[13:35:33.812] <TB0> INFO: frame (failed synchr.): 0
[13:35:33.812] <TB0> INFO: idle data (no TBM trl): 0
[13:35:33.812] <TB0> INFO: no data (only TBM hdr): 0
[13:35:33.812] <TB0> INFO: TBM errors: 0
[13:35:33.812] <TB0> INFO: flawed TBM headers: 0
[13:35:33.812] <TB0> INFO: flawed TBM trailers: 0
[13:35:33.812] <TB0> INFO: event ID mismatches: 0
[13:35:33.812] <TB0> INFO: ROC errors: 0
[13:35:33.812] <TB0> INFO: missing ROC header(s): 0
[13:35:33.813] <TB0> INFO: misplaced readback start: 0
[13:35:33.813] <TB0> INFO: Pixel decoding errors: 0
[13:35:33.813] <TB0> INFO: pixel data incomplete: 0
[13:35:33.813] <TB0> INFO: pixel address: 0
[13:35:33.813] <TB0> INFO: pulse height fill bit: 0
[13:35:33.813] <TB0> INFO: buffer corruption: 0
[13:35:34.074] <TB0> INFO: ######################################################################
[13:35:34.074] <TB0> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[13:35:34.074] <TB0> INFO: ######################################################################
[13:35:34.085] <TB0> INFO: scanning low vcal = 10
[13:35:34.362] <TB0> INFO: Expecting 41600 events.
[13:35:37.900] <TB0> INFO: 41600 events read in total (2947ms).
[13:35:37.900] <TB0> INFO: Test took 3814ms.
[13:35:37.902] <TB0> INFO: scanning low vcal = 20
[13:35:38.202] <TB0> INFO: Expecting 41600 events.
[13:35:41.764] <TB0> INFO: 41600 events read in total (2971ms).
[13:35:41.764] <TB0> INFO: Test took 3862ms.
[13:35:41.766] <TB0> INFO: scanning low vcal = 30
[13:35:42.063] <TB0> INFO: Expecting 41600 events.
[13:35:45.681] <TB0> INFO: 41600 events read in total (3026ms).
[13:35:45.683] <TB0> INFO: Test took 3917ms.
[13:35:45.685] <TB0> INFO: scanning low vcal = 40
[13:35:45.978] <TB0> INFO: Expecting 41600 events.
[13:35:49.911] <TB0> INFO: 41600 events read in total (3341ms).
[13:35:49.912] <TB0> INFO: Test took 4227ms.
[13:35:49.915] <TB0> INFO: scanning low vcal = 50
[13:35:50.192] <TB0> INFO: Expecting 41600 events.
[13:35:54.128] <TB0> INFO: 41600 events read in total (3345ms).
[13:35:54.129] <TB0> INFO: Test took 4214ms.
[13:35:54.132] <TB0> INFO: scanning low vcal = 60
[13:35:54.408] <TB0> INFO: Expecting 41600 events.
[13:35:58.327] <TB0> INFO: 41600 events read in total (3327ms).
[13:35:58.328] <TB0> INFO: Test took 4196ms.
[13:35:58.331] <TB0> INFO: scanning low vcal = 70
[13:35:58.607] <TB0> INFO: Expecting 41600 events.
[13:36:02.573] <TB0> INFO: 41600 events read in total (3374ms).
[13:36:02.573] <TB0> INFO: Test took 4242ms.
[13:36:02.576] <TB0> INFO: scanning low vcal = 80
[13:36:02.853] <TB0> INFO: Expecting 41600 events.
[13:36:06.786] <TB0> INFO: 41600 events read in total (3342ms).
[13:36:06.787] <TB0> INFO: Test took 4211ms.
[13:36:06.789] <TB0> INFO: scanning low vcal = 90
[13:36:07.066] <TB0> INFO: Expecting 41600 events.
[13:36:11.017] <TB0> INFO: 41600 events read in total (3360ms).
[13:36:11.018] <TB0> INFO: Test took 4228ms.
[13:36:11.021] <TB0> INFO: scanning low vcal = 100
[13:36:11.298] <TB0> INFO: Expecting 41600 events.
[13:36:15.247] <TB0> INFO: 41600 events read in total (3358ms).
[13:36:15.248] <TB0> INFO: Test took 4227ms.
[13:36:15.251] <TB0> INFO: scanning low vcal = 110
[13:36:15.527] <TB0> INFO: Expecting 41600 events.
[13:36:19.485] <TB0> INFO: 41600 events read in total (3366ms).
[13:36:19.485] <TB0> INFO: Test took 4234ms.
[13:36:19.488] <TB0> INFO: scanning low vcal = 120
[13:36:19.765] <TB0> INFO: Expecting 41600 events.
[13:36:23.696] <TB0> INFO: 41600 events read in total (3340ms).
[13:36:23.697] <TB0> INFO: Test took 4209ms.
[13:36:23.699] <TB0> INFO: scanning low vcal = 130
[13:36:23.976] <TB0> INFO: Expecting 41600 events.
[13:36:27.896] <TB0> INFO: 41600 events read in total (3328ms).
[13:36:27.897] <TB0> INFO: Test took 4197ms.
[13:36:27.899] <TB0> INFO: scanning low vcal = 140
[13:36:28.176] <TB0> INFO: Expecting 41600 events.
[13:36:32.130] <TB0> INFO: 41600 events read in total (3362ms).
[13:36:32.130] <TB0> INFO: Test took 4231ms.
[13:36:32.133] <TB0> INFO: scanning low vcal = 150
[13:36:32.409] <TB0> INFO: Expecting 41600 events.
[13:36:36.314] <TB0> INFO: 41600 events read in total (3313ms).
[13:36:36.315] <TB0> INFO: Test took 4182ms.
[13:36:36.318] <TB0> INFO: scanning low vcal = 160
[13:36:36.594] <TB0> INFO: Expecting 41600 events.
[13:36:40.531] <TB0> INFO: 41600 events read in total (3345ms).
[13:36:40.532] <TB0> INFO: Test took 4214ms.
[13:36:40.534] <TB0> INFO: scanning low vcal = 170
[13:36:40.811] <TB0> INFO: Expecting 41600 events.
[13:36:44.790] <TB0> INFO: 41600 events read in total (3387ms).
[13:36:44.791] <TB0> INFO: Test took 4256ms.
[13:36:44.794] <TB0> INFO: scanning low vcal = 180
[13:36:45.071] <TB0> INFO: Expecting 41600 events.
[13:36:48.000] <TB0> INFO: 41600 events read in total (3338ms).
[13:36:48.001] <TB0> INFO: Test took 4207ms.
[13:36:49.004] <TB0> INFO: scanning low vcal = 190
[13:36:49.280] <TB0> INFO: Expecting 41600 events.
[13:36:53.188] <TB0> INFO: 41600 events read in total (3316ms).
[13:36:53.188] <TB0> INFO: Test took 4184ms.
[13:36:53.191] <TB0> INFO: scanning low vcal = 200
[13:36:53.468] <TB0> INFO: Expecting 41600 events.
[13:36:57.437] <TB0> INFO: 41600 events read in total (3378ms).
[13:36:57.437] <TB0> INFO: Test took 4246ms.
[13:36:57.441] <TB0> INFO: scanning low vcal = 210
[13:36:57.718] <TB0> INFO: Expecting 41600 events.
[13:37:01.757] <TB0> INFO: 41600 events read in total (3447ms).
[13:37:01.758] <TB0> INFO: Test took 4317ms.
[13:37:01.761] <TB0> INFO: scanning low vcal = 220
[13:37:02.038] <TB0> INFO: Expecting 41600 events.
[13:37:05.977] <TB0> INFO: 41600 events read in total (3346ms).
[13:37:05.978] <TB0> INFO: Test took 4217ms.
[13:37:05.980] <TB0> INFO: scanning low vcal = 230
[13:37:06.258] <TB0> INFO: Expecting 41600 events.
[13:37:10.232] <TB0> INFO: 41600 events read in total (3383ms).
[13:37:10.232] <TB0> INFO: Test took 4251ms.
[13:37:10.235] <TB0> INFO: scanning low vcal = 240
[13:37:10.512] <TB0> INFO: Expecting 41600 events.
[13:37:14.474] <TB0> INFO: 41600 events read in total (3371ms).
[13:37:14.474] <TB0> INFO: Test took 4239ms.
[13:37:14.477] <TB0> INFO: scanning low vcal = 250
[13:37:14.754] <TB0> INFO: Expecting 41600 events.
[13:37:18.687] <TB0> INFO: 41600 events read in total (3342ms).
[13:37:18.688] <TB0> INFO: Test took 4211ms.
[13:37:18.691] <TB0> INFO: scanning high vcal = 30 (= 210 in low range)
[13:37:18.967] <TB0> INFO: Expecting 41600 events.
[13:37:22.899] <TB0> INFO: 41600 events read in total (3340ms).
[13:37:22.900] <TB0> INFO: Test took 4209ms.
[13:37:22.902] <TB0> INFO: scanning high vcal = 50 (= 350 in low range)
[13:37:23.179] <TB0> INFO: Expecting 41600 events.
[13:37:27.125] <TB0> INFO: 41600 events read in total (3355ms).
[13:37:27.126] <TB0> INFO: Test took 4223ms.
[13:37:27.129] <TB0> INFO: scanning high vcal = 70 (= 490 in low range)
[13:37:27.405] <TB0> INFO: Expecting 41600 events.
[13:37:31.347] <TB0> INFO: 41600 events read in total (3350ms).
[13:37:31.348] <TB0> INFO: Test took 4218ms.
[13:37:31.350] <TB0> INFO: scanning high vcal = 90 (= 630 in low range)
[13:37:31.627] <TB0> INFO: Expecting 41600 events.
[13:37:35.591] <TB0> INFO: 41600 events read in total (3373ms).
[13:37:35.591] <TB0> INFO: Test took 4241ms.
[13:37:35.594] <TB0> INFO: scanning high vcal = 200 (= 1400 in low range)
[13:37:35.871] <TB0> INFO: Expecting 41600 events.
[13:37:39.814] <TB0> INFO: 41600 events read in total (3352ms).
[13:37:39.814] <TB0> INFO: Test took 4220ms.
[13:37:40.335] <TB0> INFO: PixTestGainPedestal::measure() done
[13:38:14.926] <TB0> INFO: PixTestGainPedestal::fit() done
[13:38:14.926] <TB0> INFO: non-linearity mean: 0.977 0.977 0.985 0.984 0.919 1.004 0.985 0.976 0.944 0.939 0.921 0.952 0.947 0.965 0.968 1.036
[13:38:14.926] <TB0> INFO: non-linearity RMS: 0.004 0.006 0.003 0.003 0.112 0.162 0.004 0.004 0.041 0.054 0.142 0.059 0.099 0.018 0.028 0.150
[13:38:14.926] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[13:38:14.941] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[13:38:14.954] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[13:38:14.968] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[13:38:14.982] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[13:38:14.996] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[13:38:15.014] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[13:38:15.027] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[13:38:15.042] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[13:38:15.056] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[13:38:15.070] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[13:38:15.084] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[13:38:15.098] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[13:38:15.113] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[13:38:15.127] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[13:38:15.141] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1131_FullQualification_2016-11-07_11h20m_1478514052//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[13:38:15.155] <TB0> INFO: PixTestGainPedestal::fullTest() done, duration: 161 seconds
[13:38:15.155] <TB0> INFO: Decoding statistics:
[13:38:15.155] <TB0> INFO: General information:
[13:38:15.155] <TB0> INFO: 16bit words read: 3327498
[13:38:15.155] <TB0> INFO: valid events total: 332800
[13:38:15.155] <TB0> INFO: empty events: 0
[13:38:15.155] <TB0> INFO: valid events with pixels: 332800
[13:38:15.156] <TB0> INFO: valid pixel hits: 665349
[13:38:15.156] <TB0> INFO: Event errors: 0
[13:38:15.156] <TB0> INFO: start marker: 0
[13:38:15.156] <TB0> INFO: stop marker: 0
[13:38:15.156] <TB0> INFO: overflow: 0
[13:38:15.156] <TB0> INFO: invalid 5bit words: 0
[13:38:15.156] <TB0> INFO: invalid XOR eye diagram: 0
[13:38:15.156] <TB0> INFO: frame (failed synchr.): 0
[13:38:15.156] <TB0> INFO: idle data (no TBM trl): 0
[13:38:15.156] <TB0> INFO: no data (only TBM hdr): 0
[13:38:15.156] <TB0> INFO: TBM errors: 0
[13:38:15.156] <TB0> INFO: flawed TBM headers: 0
[13:38:15.156] <TB0> INFO: flawed TBM trailers: 0
[13:38:15.156] <TB0> INFO: event ID mismatches: 0
[13:38:15.156] <TB0> INFO: ROC errors: 0
[13:38:15.156] <TB0> INFO: missing ROC header(s): 0
[13:38:15.156] <TB0> INFO: misplaced readback start: 0
[13:38:15.156] <TB0> INFO: Pixel decoding errors: 0
[13:38:15.156] <TB0> INFO: pixel data incomplete: 0
[13:38:15.156] <TB0> INFO: pixel address: 0
[13:38:15.156] <TB0> INFO: pulse height fill bit: 0
[13:38:15.156] <TB0> INFO: buffer corruption: 0
[13:38:15.170] <TB0> INFO: Decoding statistics:
[13:38:15.170] <TB0> INFO: General information:
[13:38:15.170] <TB0> INFO: 16bit words read: 3456914
[13:38:15.170] <TB0> INFO: valid events total: 353536
[13:38:15.170] <TB0> INFO: empty events: 18236
[13:38:15.170] <TB0> INFO: valid events with pixels: 335300
[13:38:15.170] <TB0> INFO: valid pixel hits: 667849
[13:38:15.170] <TB0> INFO: Event errors: 0
[13:38:15.170] <TB0> INFO: start marker: 0
[13:38:15.170] <TB0> INFO: stop marker: 0
[13:38:15.170] <TB0> INFO: overflow: 0
[13:38:15.170] <TB0> INFO: invalid 5bit words: 0
[13:38:15.170] <TB0> INFO: invalid XOR eye diagram: 0
[13:38:15.170] <TB0> INFO: frame (failed synchr.): 0
[13:38:15.170] <TB0> INFO: idle data (no TBM trl): 0
[13:38:15.170] <TB0> INFO: no data (only TBM hdr): 0
[13:38:15.170] <TB0> INFO: TBM errors: 0
[13:38:15.170] <TB0> INFO: flawed TBM headers: 0
[13:38:15.170] <TB0> INFO: flawed TBM trailers: 0
[13:38:15.170] <TB0> INFO: event ID mismatches: 0
[13:38:15.170] <TB0> INFO: ROC errors: 0
[13:38:15.170] <TB0> INFO: missing ROC header(s): 0
[13:38:15.170] <TB0> INFO: misplaced readback start: 0
[13:38:15.170] <TB0> INFO: Pixel decoding errors: 0
[13:38:15.170] <TB0> INFO: pixel data incomplete: 0
[13:38:15.170] <TB0> INFO: pixel address: 0
[13:38:15.171] <TB0> INFO: pulse height fill bit: 0
[13:38:15.171] <TB0> INFO: buffer corruption: 0
[13:38:15.171] <TB0> INFO: enter test to run
[13:38:15.171] <TB0> INFO: test: exit no parameter change
[13:38:15.210] <TB0> QUIET: Connection to board 73 closed.
[13:38:15.210] <TB0> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud