Test Date: 2016-10-31 10:37
Analysis date: 2016-10-31 15:42
Logfile
LogfileView
[11:34:44.507] <TB3> INFO: *** Welcome to pxar ***
[11:34:44.507] <TB3> INFO: *** Today: 2016/10/31
[11:34:44.512] <TB3> INFO: *** Version: c8ba-dirty
[11:34:44.513] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C15.dat
[11:34:44.513] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C1b.dat
[11:34:44.513] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//defaultMaskFile.dat
[11:34:44.513] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters_C15.dat
[11:34:44.568] <TB3> INFO: clk: 4
[11:34:44.568] <TB3> INFO: ctr: 4
[11:34:44.568] <TB3> INFO: sda: 19
[11:34:44.568] <TB3> INFO: tin: 9
[11:34:44.568] <TB3> INFO: level: 15
[11:34:44.568] <TB3> INFO: triggerdelay: 0
[11:34:44.568] <TB3> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[11:34:44.568] <TB3> INFO: Log level: INFO
[11:34:44.577] <TB3> INFO: Found DTB DTB_WZ4I6J
[11:34:44.585] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[11:34:44.587] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 170
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WZ4I6J
MAC address: 40D8551180AA
Hostname: pixelDTB170
Comment:
------------------------------------------------------
[11:34:44.589] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[11:34:46.072] <TB3> INFO: DUT info:
[11:34:46.072] <TB3> INFO: The DUT currently contains the following objects:
[11:34:46.072] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[11:34:46.072] <TB3> INFO: TBM Core alpha (0): 7 registers set
[11:34:46.072] <TB3> INFO: TBM Core beta (1): 7 registers set
[11:34:46.072] <TB3> INFO: TBM Core alpha (2): 7 registers set
[11:34:46.072] <TB3> INFO: TBM Core beta (3): 7 registers set
[11:34:46.072] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[11:34:46.072] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.072] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.073] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:46.473] <TB3> INFO: enter 'restricted' command line mode
[11:34:46.473] <TB3> INFO: enter test to run
[11:34:46.473] <TB3> INFO: test: pretest no parameter change
[11:34:46.473] <TB3> INFO: running: pretest
[11:34:47.120] <TB3> INFO: ######################################################################
[11:34:47.120] <TB3> INFO: PixTestPretest::doTest()
[11:34:47.120] <TB3> INFO: ######################################################################
[11:34:47.121] <TB3> INFO: ----------------------------------------------------------------------
[11:34:47.121] <TB3> INFO: PixTestPretest::programROC()
[11:34:47.121] <TB3> INFO: ----------------------------------------------------------------------
[11:35:05.134] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:35:05.134] <TB3> INFO: IA differences per ROC: 19.3 16.9 20.1 19.3 20.1 19.3 19.3 20.1 19.3 19.3 19.3 20.1 20.1 19.3 20.9 19.3
[11:35:05.169] <TB3> INFO: ----------------------------------------------------------------------
[11:35:05.169] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:35:05.169] <TB3> INFO: ----------------------------------------------------------------------
[11:35:26.412] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 381.9 mA = 23.8688 mA/ROC
[11:35:26.412] <TB3> INFO: i(loss) [mA/ROC]: 19.2 18.4 19.2 18.4 17.6 18.4 19.2 17.6 17.6 17.6 18.4 18.4 18.4 19.2 19.2 18.4
[11:35:26.439] <TB3> INFO: ----------------------------------------------------------------------
[11:35:26.439] <TB3> INFO: PixTestPretest::findTiming()
[11:35:26.439] <TB3> INFO: ----------------------------------------------------------------------
[11:35:26.439] <TB3> INFO: PixTestCmd::init()
[11:35:27.006] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!

[11:35:57.658] <TB3> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[11:35:57.658] <TB3> INFO: (success/tries = 100/100), width = 3
[11:35:59.168] <TB3> INFO: ----------------------------------------------------------------------
[11:35:59.168] <TB3> INFO: PixTestPretest::findWorkingPixel()
[11:35:59.168] <TB3> INFO: ----------------------------------------------------------------------
[11:35:59.259] <TB3> INFO: Expecting 231680 events.
[11:36:08.911] <TB3> INFO: 231680 events read in total (9060ms).
[11:36:08.918] <TB3> INFO: Test took 9748ms.
[11:36:09.164] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:36:09.193] <TB3> INFO: ----------------------------------------------------------------------
[11:36:09.193] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[11:36:09.193] <TB3> INFO: ----------------------------------------------------------------------
[11:36:09.284] <TB3> INFO: Expecting 231680 events.
[11:36:18.925] <TB3> INFO: 231680 events read in total (9049ms).
[11:36:18.933] <TB3> INFO: Test took 9737ms.
[11:36:19.194] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[11:36:19.195] <TB3> INFO: CalDel: 90 97 103 84 104 95 106 100 96 104 100 101 109 95 97 89
[11:36:19.195] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[11:36:19.197] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C0.dat
[11:36:19.197] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C1.dat
[11:36:19.197] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C2.dat
[11:36:19.197] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C3.dat
[11:36:19.197] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C4.dat
[11:36:19.197] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C5.dat
[11:36:19.197] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C6.dat
[11:36:19.197] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C7.dat
[11:36:19.197] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C8.dat
[11:36:19.198] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C9.dat
[11:36:19.198] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C10.dat
[11:36:19.198] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C11.dat
[11:36:19.198] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C12.dat
[11:36:19.198] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C13.dat
[11:36:19.198] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C14.dat
[11:36:19.198] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C15.dat
[11:36:19.198] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C0a.dat
[11:36:19.198] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C0b.dat
[11:36:19.198] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C1a.dat
[11:36:19.198] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C1b.dat
[11:36:19.198] <TB3> INFO: PixTestPretest::doTest() done, duration: 92 seconds
[11:36:19.295] <TB3> INFO: enter test to run
[11:36:19.295] <TB3> INFO: test: FullTest no parameter change
[11:36:19.295] <TB3> INFO: running: fulltest
[11:36:19.295] <TB3> INFO: ######################################################################
[11:36:19.295] <TB3> INFO: PixTestFullTest::doTest()
[11:36:19.295] <TB3> INFO: ######################################################################
[11:36:19.296] <TB3> INFO: ######################################################################
[11:36:19.296] <TB3> INFO: PixTestAlive::doTest()
[11:36:19.296] <TB3> INFO: ######################################################################
[11:36:19.297] <TB3> INFO: ----------------------------------------------------------------------
[11:36:19.297] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:36:19.297] <TB3> INFO: ----------------------------------------------------------------------
[11:36:19.574] <TB3> INFO: Expecting 41600 events.
[11:36:22.001] <TB3> INFO: 41600 events read in total (2835ms).
[11:36:22.002] <TB3> INFO: Test took 3704ms.
[11:36:23.230] <TB3> INFO: PixTestAlive::aliveTest() done
[11:36:23.230] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0
[11:36:23.231] <TB3> INFO: ----------------------------------------------------------------------
[11:36:23.231] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:36:23.231] <TB3> INFO: ----------------------------------------------------------------------
[11:36:23.464] <TB3> INFO: Expecting 41600 events.
[11:36:26.394] <TB3> INFO: 41600 events read in total (2338ms).
[11:36:26.394] <TB3> INFO: Test took 3161ms.
[11:36:26.394] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:36:26.633] <TB3> INFO: PixTestAlive::maskTest() done
[11:36:26.633] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:36:26.635] <TB3> INFO: ----------------------------------------------------------------------
[11:36:26.635] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:36:26.635] <TB3> INFO: ----------------------------------------------------------------------
[11:36:26.868] <TB3> INFO: Expecting 41600 events.
[11:36:30.301] <TB3> INFO: 41600 events read in total (2841ms).
[11:36:30.301] <TB3> INFO: Test took 3665ms.
[11:36:30.528] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[11:36:30.528] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:36:30.528] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[11:36:30.528] <TB3> INFO: Decoding statistics:
[11:36:30.528] <TB3> INFO: General information:
[11:36:30.528] <TB3> INFO: 16bit words read: 0
[11:36:30.528] <TB3> INFO: valid events total: 0
[11:36:30.528] <TB3> INFO: empty events: 0
[11:36:30.528] <TB3> INFO: valid events with pixels: 0
[11:36:30.528] <TB3> INFO: valid pixel hits: 0
[11:36:30.528] <TB3> INFO: Event errors: 0
[11:36:30.528] <TB3> INFO: start marker: 0
[11:36:30.528] <TB3> INFO: stop marker: 0
[11:36:30.528] <TB3> INFO: overflow: 0
[11:36:30.528] <TB3> INFO: invalid 5bit words: 0
[11:36:30.528] <TB3> INFO: invalid XOR eye diagram: 0
[11:36:30.528] <TB3> INFO: frame (failed synchr.): 0
[11:36:30.528] <TB3> INFO: idle data (no TBM trl): 0
[11:36:30.528] <TB3> INFO: no data (only TBM hdr): 0
[11:36:30.528] <TB3> INFO: TBM errors: 0
[11:36:30.528] <TB3> INFO: flawed TBM headers: 0
[11:36:30.528] <TB3> INFO: flawed TBM trailers: 0
[11:36:30.528] <TB3> INFO: event ID mismatches: 0
[11:36:30.528] <TB3> INFO: ROC errors: 0
[11:36:30.528] <TB3> INFO: missing ROC header(s): 0
[11:36:30.528] <TB3> INFO: misplaced readback start: 0
[11:36:30.528] <TB3> INFO: Pixel decoding errors: 0
[11:36:30.528] <TB3> INFO: pixel data incomplete: 0
[11:36:30.528] <TB3> INFO: pixel address: 0
[11:36:30.528] <TB3> INFO: pulse height fill bit: 0
[11:36:30.528] <TB3> INFO: buffer corruption: 0
[11:36:30.536] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C15.dat
[11:36:30.536] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[11:36:30.536] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[11:36:30.536] <TB3> INFO: ######################################################################
[11:36:30.536] <TB3> INFO: PixTestReadback::doTest()
[11:36:30.536] <TB3> INFO: ######################################################################
[11:36:30.536] <TB3> INFO: ----------------------------------------------------------------------
[11:36:30.536] <TB3> INFO: PixTestReadback::CalibrateVd()
[11:36:30.536] <TB3> INFO: ----------------------------------------------------------------------
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C0.dat
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C1.dat
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C2.dat
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C3.dat
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C4.dat
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C5.dat
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C6.dat
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C7.dat
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C8.dat
[11:36:40.503] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C9.dat
[11:36:40.504] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C10.dat
[11:36:40.504] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C11.dat
[11:36:40.504] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C12.dat
[11:36:40.504] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C13.dat
[11:36:40.504] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C14.dat
[11:36:40.504] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C15.dat
[11:36:40.531] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:36:40.531] <TB3> INFO: ----------------------------------------------------------------------
[11:36:40.531] <TB3> INFO: PixTestReadback::CalibrateVa()
[11:36:40.531] <TB3> INFO: ----------------------------------------------------------------------
[11:36:50.424] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C0.dat
[11:36:50.424] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C1.dat
[11:36:50.424] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C2.dat
[11:36:50.424] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C3.dat
[11:36:50.424] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C4.dat
[11:36:50.424] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C5.dat
[11:36:50.424] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C6.dat
[11:36:50.424] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C7.dat
[11:36:50.425] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C8.dat
[11:36:50.425] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C9.dat
[11:36:50.425] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C10.dat
[11:36:50.425] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C11.dat
[11:36:50.425] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C12.dat
[11:36:50.425] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C13.dat
[11:36:50.425] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C14.dat
[11:36:50.425] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C15.dat
[11:36:50.453] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:36:50.453] <TB3> INFO: ----------------------------------------------------------------------
[11:36:50.453] <TB3> INFO: PixTestReadback::readbackVbg()
[11:36:50.453] <TB3> INFO: ----------------------------------------------------------------------
[11:36:58.093] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:36:58.093] <TB3> INFO: ----------------------------------------------------------------------
[11:36:58.093] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[11:36:58.093] <TB3> INFO: ----------------------------------------------------------------------
[11:36:58.093] <TB3> INFO: Vbg will be calibrated using Vd calibration
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 167.5calibrated Vbg = 1.16033 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 155.9calibrated Vbg = 1.15711 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 148.1calibrated Vbg = 1.15563 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 158.4calibrated Vbg = 1.15328 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 147.4calibrated Vbg = 1.15222 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 151calibrated Vbg = 1.15897 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 156.3calibrated Vbg = 1.16801 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 157.1calibrated Vbg = 1.15748 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 152.9calibrated Vbg = 1.15699 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 147.8calibrated Vbg = 1.15624 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 148.9calibrated Vbg = 1.15186 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 151.9calibrated Vbg = 1.14826 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 157.1calibrated Vbg = 1.15303 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 144.1calibrated Vbg = 1.15848 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 154.8calibrated Vbg = 1.15438 :::*/*/*/*/
[11:36:58.093] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 147.3calibrated Vbg = 1.15458 :::*/*/*/*/
[11:36:58.095] <TB3> INFO: ----------------------------------------------------------------------
[11:36:58.095] <TB3> INFO: PixTestReadback::CalibrateIa()
[11:36:58.095] <TB3> INFO: ----------------------------------------------------------------------
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C0.dat
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C1.dat
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C2.dat
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C3.dat
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C4.dat
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C5.dat
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C6.dat
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C7.dat
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C8.dat
[11:39:38.370] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C9.dat
[11:39:38.371] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C10.dat
[11:39:38.371] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C11.dat
[11:39:38.371] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C12.dat
[11:39:38.371] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C13.dat
[11:39:38.371] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C14.dat
[11:39:38.371] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C15.dat
[11:39:38.397] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:39:38.398] <TB3> INFO: PixTestReadback::doTest() done
[11:39:38.398] <TB3> INFO: Decoding statistics:
[11:39:38.398] <TB3> INFO: General information:
[11:39:38.398] <TB3> INFO: 16bit words read: 1536
[11:39:38.398] <TB3> INFO: valid events total: 256
[11:39:38.398] <TB3> INFO: empty events: 256
[11:39:38.398] <TB3> INFO: valid events with pixels: 0
[11:39:38.398] <TB3> INFO: valid pixel hits: 0
[11:39:38.398] <TB3> INFO: Event errors: 0
[11:39:38.398] <TB3> INFO: start marker: 0
[11:39:38.398] <TB3> INFO: stop marker: 0
[11:39:38.398] <TB3> INFO: overflow: 0
[11:39:38.398] <TB3> INFO: invalid 5bit words: 0
[11:39:38.398] <TB3> INFO: invalid XOR eye diagram: 0
[11:39:38.398] <TB3> INFO: frame (failed synchr.): 0
[11:39:38.398] <TB3> INFO: idle data (no TBM trl): 0
[11:39:38.398] <TB3> INFO: no data (only TBM hdr): 0
[11:39:38.398] <TB3> INFO: TBM errors: 0
[11:39:38.398] <TB3> INFO: flawed TBM headers: 0
[11:39:38.398] <TB3> INFO: flawed TBM trailers: 0
[11:39:38.398] <TB3> INFO: event ID mismatches: 0
[11:39:38.398] <TB3> INFO: ROC errors: 0
[11:39:38.398] <TB3> INFO: missing ROC header(s): 0
[11:39:38.398] <TB3> INFO: misplaced readback start: 0
[11:39:38.398] <TB3> INFO: Pixel decoding errors: 0
[11:39:38.398] <TB3> INFO: pixel data incomplete: 0
[11:39:38.398] <TB3> INFO: pixel address: 0
[11:39:38.398] <TB3> INFO: pulse height fill bit: 0
[11:39:38.398] <TB3> INFO: buffer corruption: 0
[11:39:38.432] <TB3> INFO: ######################################################################
[11:39:38.432] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:39:38.432] <TB3> INFO: ######################################################################
[11:39:38.434] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[11:39:38.449] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:39:38.449] <TB3> INFO: run 1 of 1
[11:39:38.741] <TB3> INFO: Expecting 3120000 events.
[11:40:09.611] <TB3> INFO: 647275 events read in total (30278ms).
[11:40:21.480] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (236) != TBM ID (129)

[11:40:21.623] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 236 236 129 236 236 236 236 236

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

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

[11:40:21.623] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f0 80b1 4c00 4c00 e022 c000

[11:40:21.623] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ea 8000 4c00 4c00 e022 c000

[11:40:21.623] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0eb 8040 4c00 4c00 e022 c000

[11:40:21.623] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c01 e022 c000

[11:40:21.623] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ed 80c0 4c00 4c00 e022 c000

[11:40:21.623] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ee 8000 4c01 4c01 e022 c000

[11:40:21.623] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ef 8040 4c02 4c02 e022 c000

[11:40:39.257] <TB3> INFO: 1291770 events read in total (59924ms).
[11:40:51.118] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (123) != TBM ID (129)

[11:40:51.261] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 123 123 129 123 123 123 123 123

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

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

[11:40:51.261] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07f 8040 4c03 4c03 e022 c000

[11:40:51.262] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a079 80c0 4c00 4c00 e022 c000

[11:40:51.262] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07a 8000 4c01 4c01 e022 c000

[11:40:51.262] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c01 e022 c000

[11:40:51.262] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07c 80b1 4c00 4c00 e022 c000

[11:40:51.262] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07d 80c0 4c00 4c00 e022 c000

[11:40:51.262] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07e 8000 4c01 4c01 e022 c000

[11:41:09.701] <TB3> INFO: 1935755 events read in total (90368ms).
[11:41:21.548] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (12) != TBM ID (129)

[11:41:21.692] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 12 12 129 12 12 12 12 12

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

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

[11:41:21.693] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a010 80b1 4c00 4c00 e022 c000

[11:41:21.693] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00a 8000 4c00 4c00 e022 c000

[11:41:21.693] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00b 8040 4c01 4c01 e022 c000

[11:41:21.693] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c01 e022 c000

[11:41:21.693] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00d 80c0 4c01 4c01 e022 c000

[11:41:21.693] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00e 8000 4c00 4c00 e022 c000

[11:41:21.693] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00f 8040 4c02 4c02 e022 c000

[11:41:40.353] <TB3> INFO: 2579185 events read in total (121020ms).
[11:41:50.340] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (114) != TBM ID (129)

[11:41:50.483] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 114 114 129 114 114 114 114 114

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

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

[11:41:50.483] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a076 8000 4c00 a52 2dcc 4c00 a52 2daa e022 c000

[11:41:50.483] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a070 80b1 4c00 a52 2dcd 4c00 a52 2dae e022 c000

[11:41:50.483] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a071 80c0 4c01 a52 2de0 4c01 a52 2dac e022 c000

[11:41:50.483] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c01 2dcd 4c00 a52 2dad e022 c000

[11:41:50.483] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a073 8040 4c00 a52 2dcf 4c01 a52 2dac e022 c000

[11:41:50.483] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a074 80b1 4c00 a52 2de0 4c00 a52 2daa e022 c000

[11:41:50.483] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a075 80c0 4c00 a52 2de0 4c00 a52 2dae e022 c000

[11:42:05.712] <TB3> INFO: 3120000 events read in total (146379ms).
[11:42:05.797] <TB3> INFO: Test took 147348ms.
[11:42:27.656] <TB3> INFO: PixTestBBMap::doTest() done with 1 decoding errors: , duration: 169 seconds
[11:42:27.656] <TB3> INFO: number of dead bumps (per ROC): 1 0 0 0 1 0 0 1 0 0 0 0 0 0 1 0
[11:42:27.656] <TB3> INFO: separation cut (per ROC): 101 99 95 102 88 103 89 96 91 101 100 99 89 93 108 104
[11:42:27.656] <TB3> INFO: Decoding statistics:
[11:42:27.656] <TB3> INFO: General information:
[11:42:27.656] <TB3> INFO: 16bit words read: 0
[11:42:27.656] <TB3> INFO: valid events total: 0
[11:42:27.656] <TB3> INFO: empty events: 0
[11:42:27.656] <TB3> INFO: valid events with pixels: 0
[11:42:27.656] <TB3> INFO: valid pixel hits: 0
[11:42:27.656] <TB3> INFO: Event errors: 0
[11:42:27.656] <TB3> INFO: start marker: 0
[11:42:27.656] <TB3> INFO: stop marker: 0
[11:42:27.656] <TB3> INFO: overflow: 0
[11:42:27.656] <TB3> INFO: invalid 5bit words: 0
[11:42:27.656] <TB3> INFO: invalid XOR eye diagram: 0
[11:42:27.656] <TB3> INFO: frame (failed synchr.): 0
[11:42:27.656] <TB3> INFO: idle data (no TBM trl): 0
[11:42:27.656] <TB3> INFO: no data (only TBM hdr): 0
[11:42:27.656] <TB3> INFO: TBM errors: 0
[11:42:27.656] <TB3> INFO: flawed TBM headers: 0
[11:42:27.656] <TB3> INFO: flawed TBM trailers: 0
[11:42:27.656] <TB3> INFO: event ID mismatches: 0
[11:42:27.656] <TB3> INFO: ROC errors: 0
[11:42:27.657] <TB3> INFO: missing ROC header(s): 0
[11:42:27.657] <TB3> INFO: misplaced readback start: 0
[11:42:27.657] <TB3> INFO: Pixel decoding errors: 0
[11:42:27.657] <TB3> INFO: pixel data incomplete: 0
[11:42:27.657] <TB3> INFO: pixel address: 0
[11:42:27.657] <TB3> INFO: pulse height fill bit: 0
[11:42:27.657] <TB3> INFO: buffer corruption: 0
[11:42:27.704] <TB3> INFO: ######################################################################
[11:42:27.704] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:42:27.704] <TB3> INFO: ######################################################################
[11:42:27.704] <TB3> INFO: ----------------------------------------------------------------------
[11:42:27.704] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:42:27.704] <TB3> INFO: ----------------------------------------------------------------------
[11:42:27.705] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[11:42:27.716] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:42:27.716] <TB3> INFO: run 1 of 1
[11:42:27.975] <TB3> INFO: Expecting 36608000 events.
[11:42:51.731] <TB3> INFO: 657400 events read in total (23164ms).
[11:43:14.512] <TB3> INFO: 1304850 events read in total (45945ms).
[11:43:37.674] <TB3> INFO: 1950550 events read in total (69107ms).
[11:44:00.563] <TB3> INFO: 2596900 events read in total (91996ms).
[11:44:23.756] <TB3> INFO: 3242100 events read in total (115189ms).
[11:44:46.375] <TB3> INFO: 3885100 events read in total (137808ms).
[11:45:09.045] <TB3> INFO: 4529050 events read in total (160478ms).
[11:45:31.957] <TB3> INFO: 5171750 events read in total (183390ms).
[11:45:54.625] <TB3> INFO: 5816000 events read in total (206058ms).
[11:46:17.576] <TB3> INFO: 6458200 events read in total (229009ms).
[11:46:40.444] <TB3> INFO: 7101100 events read in total (251877ms).
[11:47:03.093] <TB3> INFO: 7742200 events read in total (274526ms).
[11:47:25.758] <TB3> INFO: 8384500 events read in total (297191ms).
[11:47:48.636] <TB3> INFO: 9027450 events read in total (320069ms).
[11:48:11.616] <TB3> INFO: 9669850 events read in total (343049ms).
[11:48:34.548] <TB3> INFO: 10312500 events read in total (365981ms).
[11:48:57.263] <TB3> INFO: 10954150 events read in total (388696ms).
[11:49:20.276] <TB3> INFO: 11596900 events read in total (411709ms).
[11:49:43.231] <TB3> INFO: 12239300 events read in total (434664ms).
[11:50:05.002] <TB3> INFO: 12881900 events read in total (457435ms).
[11:50:28.811] <TB3> INFO: 13523750 events read in total (480244ms).
[11:50:51.768] <TB3> INFO: 14165250 events read in total (503201ms).
[11:51:14.696] <TB3> INFO: 14805100 events read in total (526129ms).
[11:51:37.735] <TB3> INFO: 15444100 events read in total (549168ms).
[11:52:00.827] <TB3> INFO: 16083350 events read in total (572260ms).
[11:52:23.813] <TB3> INFO: 16723950 events read in total (595246ms).
[11:52:46.845] <TB3> INFO: 17365050 events read in total (618278ms).
[11:53:09.442] <TB3> INFO: 18004650 events read in total (640875ms).
[11:53:32.420] <TB3> INFO: 18644500 events read in total (663853ms).
[11:53:55.241] <TB3> INFO: 19283750 events read in total (686674ms).
[11:54:18.006] <TB3> INFO: 19921450 events read in total (709439ms).
[11:54:40.569] <TB3> INFO: 20559450 events read in total (732002ms).
[11:55:03.125] <TB3> INFO: 21197050 events read in total (754558ms).
[11:55:25.753] <TB3> INFO: 21836100 events read in total (777186ms).
[11:55:48.549] <TB3> INFO: 22473850 events read in total (799982ms).
[11:56:10.926] <TB3> INFO: 23109200 events read in total (822359ms).
[11:56:34.079] <TB3> INFO: 23747050 events read in total (845512ms).
[11:56:56.309] <TB3> INFO: 24382750 events read in total (867742ms).
[11:57:19.253] <TB3> INFO: 25019750 events read in total (890686ms).
[11:57:41.909] <TB3> INFO: 25656600 events read in total (913342ms).
[11:58:04.858] <TB3> INFO: 26291800 events read in total (936291ms).
[11:58:27.401] <TB3> INFO: 26926200 events read in total (958834ms).
[11:58:50.279] <TB3> INFO: 27561400 events read in total (981712ms).
[11:59:12.511] <TB3> INFO: 28197750 events read in total (1003944ms).
[11:59:35.339] <TB3> INFO: 28832000 events read in total (1026772ms).
[11:59:58.113] <TB3> INFO: 29466400 events read in total (1049546ms).
[12:00:20.601] <TB3> INFO: 30100450 events read in total (1072034ms).
[12:00:43.253] <TB3> INFO: 30734950 events read in total (1094686ms).
[12:01:06.193] <TB3> INFO: 31369150 events read in total (1117626ms).
[12:01:28.940] <TB3> INFO: 32003700 events read in total (1140373ms).
[12:01:51.628] <TB3> INFO: 32638050 events read in total (1163061ms).
[12:02:14.098] <TB3> INFO: 33271850 events read in total (1185531ms).
[12:02:36.962] <TB3> INFO: 33907800 events read in total (1208395ms).
[12:02:59.786] <TB3> INFO: 34541950 events read in total (1231219ms).
[12:03:22.237] <TB3> INFO: 35174800 events read in total (1253670ms).
[12:03:44.740] <TB3> INFO: 35810200 events read in total (1276173ms).
[12:04:07.536] <TB3> INFO: 36454500 events read in total (1298969ms).
[12:04:13.242] <TB3> INFO: 36608000 events read in total (1304675ms).
[12:04:13.297] <TB3> INFO: Test took 1305580ms.
[12:04:13.708] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:15.580] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:17.050] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:18.887] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:20.466] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:22.258] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:24.069] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:25.749] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:27.397] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:29.523] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:31.335] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:32.822] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:34.285] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:35.821] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:37.415] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:38.988] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:04:40.523] <TB3> INFO: PixTestScurves::scurves() done
[12:04:40.523] <TB3> INFO: Vcal mean: 106.60 102.90 103.49 111.73 94.76 111.47 101.98 108.53 99.53 102.40 105.19 103.08 102.52 94.56 113.39 110.83
[12:04:40.523] <TB3> INFO: Vcal RMS: 5.06 5.43 5.07 5.04 4.89 4.59 5.19 4.49 5.05 4.94 5.14 5.02 5.40 5.41 5.29 4.83
[12:04:40.523] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1332 seconds
[12:04:40.523] <TB3> INFO: Decoding statistics:
[12:04:40.523] <TB3> INFO: General information:
[12:04:40.523] <TB3> INFO: 16bit words read: 0
[12:04:40.523] <TB3> INFO: valid events total: 0
[12:04:40.523] <TB3> INFO: empty events: 0
[12:04:40.523] <TB3> INFO: valid events with pixels: 0
[12:04:40.523] <TB3> INFO: valid pixel hits: 0
[12:04:40.523] <TB3> INFO: Event errors: 0
[12:04:40.523] <TB3> INFO: start marker: 0
[12:04:40.523] <TB3> INFO: stop marker: 0
[12:04:40.523] <TB3> INFO: overflow: 0
[12:04:40.523] <TB3> INFO: invalid 5bit words: 0
[12:04:40.523] <TB3> INFO: invalid XOR eye diagram: 0
[12:04:40.523] <TB3> INFO: frame (failed synchr.): 0
[12:04:40.523] <TB3> INFO: idle data (no TBM trl): 0
[12:04:40.523] <TB3> INFO: no data (only TBM hdr): 0
[12:04:40.523] <TB3> INFO: TBM errors: 0
[12:04:40.523] <TB3> INFO: flawed TBM headers: 0
[12:04:40.523] <TB3> INFO: flawed TBM trailers: 0
[12:04:40.523] <TB3> INFO: event ID mismatches: 0
[12:04:40.523] <TB3> INFO: ROC errors: 0
[12:04:40.523] <TB3> INFO: missing ROC header(s): 0
[12:04:40.523] <TB3> INFO: misplaced readback start: 0
[12:04:40.523] <TB3> INFO: Pixel decoding errors: 0
[12:04:40.523] <TB3> INFO: pixel data incomplete: 0
[12:04:40.523] <TB3> INFO: pixel address: 0
[12:04:40.523] <TB3> INFO: pulse height fill bit: 0
[12:04:40.523] <TB3> INFO: buffer corruption: 0
[12:04:40.612] <TB3> INFO: ######################################################################
[12:04:40.612] <TB3> INFO: PixTestTrim::doTest()
[12:04:40.612] <TB3> INFO: ######################################################################
[12:04:40.613] <TB3> INFO: ----------------------------------------------------------------------
[12:04:40.613] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[12:04:40.613] <TB3> INFO: ----------------------------------------------------------------------
[12:04:40.652] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:04:40.652] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:04:40.662] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:04:40.662] <TB3> INFO: run 1 of 1
[12:04:40.894] <TB3> INFO: Expecting 5025280 events.
[12:05:11.768] <TB3> INFO: 811344 events read in total (30277ms).
[12:05:41.634] <TB3> INFO: 1618640 events read in total (60143ms).
[12:06:12.209] <TB3> INFO: 2424296 events read in total (90718ms).
[12:06:42.448] <TB3> INFO: 3227680 events read in total (120957ms).
[12:07:12.247] <TB3> INFO: 4028728 events read in total (150756ms).
[12:07:42.372] <TB3> INFO: 4827696 events read in total (180881ms).
[12:07:49.732] <TB3> INFO: 5025280 events read in total (188241ms).
[12:07:49.794] <TB3> INFO: Test took 189132ms.
[12:08:09.858] <TB3> INFO: ROC 0 VthrComp = 119
[12:08:09.859] <TB3> INFO: ROC 1 VthrComp = 111
[12:08:09.859] <TB3> INFO: ROC 2 VthrComp = 111
[12:08:09.859] <TB3> INFO: ROC 3 VthrComp = 122
[12:08:09.859] <TB3> INFO: ROC 4 VthrComp = 106
[12:08:09.859] <TB3> INFO: ROC 5 VthrComp = 120
[12:08:09.859] <TB3> INFO: ROC 6 VthrComp = 108
[12:08:09.859] <TB3> INFO: ROC 7 VthrComp = 114
[12:08:09.859] <TB3> INFO: ROC 8 VthrComp = 108
[12:08:09.860] <TB3> INFO: ROC 9 VthrComp = 110
[12:08:09.860] <TB3> INFO: ROC 10 VthrComp = 113
[12:08:09.860] <TB3> INFO: ROC 11 VthrComp = 111
[12:08:09.861] <TB3> INFO: ROC 12 VthrComp = 107
[12:08:09.861] <TB3> INFO: ROC 13 VthrComp = 105
[12:08:09.861] <TB3> INFO: ROC 14 VthrComp = 126
[12:08:09.861] <TB3> INFO: ROC 15 VthrComp = 118
[12:08:10.094] <TB3> INFO: Expecting 41600 events.
[12:08:13.561] <TB3> INFO: 41600 events read in total (2875ms).
[12:08:13.562] <TB3> INFO: Test took 3700ms.
[12:08:13.574] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:08:13.574] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:08:13.585] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:08:13.585] <TB3> INFO: run 1 of 1
[12:08:13.863] <TB3> INFO: Expecting 5025280 events.
[12:08:41.352] <TB3> INFO: 589216 events read in total (26897ms).
[12:09:07.391] <TB3> INFO: 1178136 events read in total (52936ms).
[12:09:33.719] <TB3> INFO: 1766392 events read in total (79264ms).
[12:09:59.651] <TB3> INFO: 2355032 events read in total (105196ms).
[12:10:25.988] <TB3> INFO: 2941736 events read in total (131533ms).
[12:10:52.226] <TB3> INFO: 3526608 events read in total (157771ms).
[12:11:17.897] <TB3> INFO: 4109880 events read in total (183442ms).
[12:11:43.231] <TB3> INFO: 4692856 events read in total (208776ms).
[12:11:58.390] <TB3> INFO: 5025280 events read in total (223935ms).
[12:11:58.449] <TB3> INFO: Test took 224864ms.
[12:12:21.961] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 57.4823 for pixel 1/74 mean/min/max = 44.3219/31.0882/57.5555
[12:12:21.961] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 60.2513 for pixel 1/72 mean/min/max = 47.0001/33.6315/60.3688
[12:12:21.962] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 59.3091 for pixel 0/48 mean/min/max = 46.6001/33.8907/59.3096
[12:12:21.962] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 60.7009 for pixel 0/44 mean/min/max = 46.0223/31.3155/60.7292
[12:12:21.963] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 57.2843 for pixel 15/61 mean/min/max = 45.7503/34.1146/57.3861
[12:12:21.963] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 57.6304 for pixel 20/5 mean/min/max = 45.51/33.3448/57.6752
[12:12:21.964] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 59.2242 for pixel 51/13 mean/min/max = 47.4325/35.6/59.265
[12:12:21.964] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 58.1235 for pixel 0/23 mean/min/max = 45.6244/33.0895/58.1593
[12:12:21.964] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 57.369 for pixel 22/70 mean/min/max = 46.198/34.8806/57.5155
[12:12:21.965] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 57.5641 for pixel 25/74 mean/min/max = 46.1571/34.7248/57.5893
[12:12:21.965] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 57.5642 for pixel 17/75 mean/min/max = 45.0917/32.4903/57.693
[12:12:21.966] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 58.0533 for pixel 0/6 mean/min/max = 46.4599/34.6026/58.3172
[12:12:21.966] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 60.9365 for pixel 40/1 mean/min/max = 47.7128/34.3226/61.1029
[12:12:21.967] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 59.0636 for pixel 21/79 mean/min/max = 46.3102/33.514/59.1064
[12:12:21.967] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 58.392 for pixel 6/2 mean/min/max = 44.5951/30.7505/58.4396
[12:12:21.967] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 58.0619 for pixel 51/0 mean/min/max = 44.8728/31.6637/58.082
[12:12:21.968] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:12:22.056] <TB3> INFO: Expecting 411648 events.
[12:12:31.651] <TB3> INFO: 411648 events read in total (9000ms).
[12:12:31.658] <TB3> INFO: Expecting 411648 events.
[12:12:40.960] <TB3> INFO: 411648 events read in total (8899ms).
[12:12:40.974] <TB3> INFO: Expecting 411648 events.
[12:12:50.197] <TB3> INFO: 411648 events read in total (8821ms).
[12:12:50.208] <TB3> INFO: Expecting 411648 events.
[12:12:59.516] <TB3> INFO: 411648 events read in total (8905ms).
[12:12:59.531] <TB3> INFO: Expecting 411648 events.
[12:13:08.756] <TB3> INFO: 411648 events read in total (8821ms).
[12:13:08.774] <TB3> INFO: Expecting 411648 events.
[12:13:18.067] <TB3> INFO: 411648 events read in total (8890ms).
[12:13:18.086] <TB3> INFO: Expecting 411648 events.
[12:13:27.475] <TB3> INFO: 411648 events read in total (8986ms).
[12:13:27.508] <TB3> INFO: Expecting 411648 events.
[12:13:36.889] <TB3> INFO: 411648 events read in total (8978ms).
[12:13:36.924] <TB3> INFO: Expecting 411648 events.
[12:13:46.266] <TB3> INFO: 411648 events read in total (8940ms).
[12:13:46.292] <TB3> INFO: Expecting 411648 events.
[12:13:55.660] <TB3> INFO: 411648 events read in total (8965ms).
[12:13:55.708] <TB3> INFO: Expecting 411648 events.
[12:14:05.107] <TB3> INFO: 411648 events read in total (8996ms).
[12:14:05.139] <TB3> INFO: Expecting 411648 events.
[12:14:14.535] <TB3> INFO: 411648 events read in total (8993ms).
[12:14:14.570] <TB3> INFO: Expecting 411648 events.
[12:14:23.795] <TB3> INFO: 411648 events read in total (8822ms).
[12:14:23.833] <TB3> INFO: Expecting 411648 events.
[12:14:33.173] <TB3> INFO: 411648 events read in total (8937ms).
[12:14:33.235] <TB3> INFO: Expecting 411648 events.
[12:14:42.716] <TB3> INFO: 411648 events read in total (9078ms).
[12:14:42.777] <TB3> INFO: Expecting 411648 events.
[12:14:52.005] <TB3> INFO: 411648 events read in total (8825ms).
[12:14:52.052] <TB3> INFO: Test took 150084ms.
[12:14:52.962] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[12:14:52.972] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:14:52.972] <TB3> INFO: run 1 of 1
[12:14:53.204] <TB3> INFO: Expecting 5025280 events.
[12:15:20.616] <TB3> INFO: 584528 events read in total (26821ms).
[12:15:46.576] <TB3> INFO: 1168896 events read in total (52781ms).
[12:16:12.758] <TB3> INFO: 1751976 events read in total (78963ms).
[12:16:39.190] <TB3> INFO: 2333824 events read in total (105395ms).
[12:17:05.492] <TB3> INFO: 2916520 events read in total (131697ms).
[12:17:31.800] <TB3> INFO: 3497784 events read in total (158005ms).
[12:17:57.901] <TB3> INFO: 4077936 events read in total (184106ms).
[12:18:24.200] <TB3> INFO: 4659312 events read in total (210405ms).
[12:18:40.714] <TB3> INFO: 5025280 events read in total (226919ms).
[12:18:40.806] <TB3> INFO: Test took 227833ms.
[12:19:02.047] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 2.066356 .. 146.362869
[12:19:02.283] <TB3> INFO: Expecting 208000 events.
[12:19:11.811] <TB3> INFO: 208000 events read in total (8936ms).
[12:19:11.812] <TB3> INFO: Test took 9763ms.
[12:19:11.859] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 2 .. 156 (-1/-1) hits flags = 528 (plus default)
[12:19:11.869] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:19:11.869] <TB3> INFO: run 1 of 1
[12:19:12.159] <TB3> INFO: Expecting 5158400 events.
[12:19:38.594] <TB3> INFO: 582784 events read in total (25843ms).
[12:20:04.216] <TB3> INFO: 1165712 events read in total (51465ms).
[12:20:29.864] <TB3> INFO: 1748344 events read in total (77113ms).
[12:20:55.896] <TB3> INFO: 2331320 events read in total (103145ms).
[12:21:21.587] <TB3> INFO: 2914000 events read in total (128836ms).
[12:21:47.611] <TB3> INFO: 3496104 events read in total (154860ms).
[12:22:13.984] <TB3> INFO: 4076864 events read in total (181233ms).
[12:22:40.271] <TB3> INFO: 4657768 events read in total (207520ms).
[12:23:03.339] <TB3> INFO: 5158400 events read in total (230588ms).
[12:23:03.425] <TB3> INFO: Test took 231557ms.
[12:23:26.918] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 27.465799 .. 52.965668
[12:23:27.209] <TB3> INFO: Expecting 208000 events.
[12:23:37.012] <TB3> INFO: 208000 events read in total (9211ms).
[12:23:37.013] <TB3> INFO: Test took 10093ms.
[12:23:37.060] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 62 (-1/-1) hits flags = 528 (plus default)
[12:23:37.070] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:23:37.070] <TB3> INFO: run 1 of 1
[12:23:37.348] <TB3> INFO: Expecting 1530880 events.
[12:24:05.372] <TB3> INFO: 635752 events read in total (27433ms).
[12:24:32.699] <TB3> INFO: 1270312 events read in total (54760ms).
[12:24:43.895] <TB3> INFO: 1530880 events read in total (65957ms).
[12:24:43.922] <TB3> INFO: Test took 66853ms.
[12:24:55.494] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 25.189637 .. 46.299672
[12:24:55.727] <TB3> INFO: Expecting 208000 events.
[12:25:05.610] <TB3> INFO: 208000 events read in total (9292ms).
[12:25:05.611] <TB3> INFO: Test took 10115ms.
[12:25:05.658] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 15 .. 56 (-1/-1) hits flags = 528 (plus default)
[12:25:05.668] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:25:05.668] <TB3> INFO: run 1 of 1
[12:25:05.946] <TB3> INFO: Expecting 1397760 events.
[12:25:35.028] <TB3> INFO: 663816 events read in total (28490ms).
[12:26:02.756] <TB3> INFO: 1326096 events read in total (56218ms).
[12:26:06.397] <TB3> INFO: 1397760 events read in total (59859ms).
[12:26:06.421] <TB3> INFO: Test took 60754ms.
[12:26:17.568] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 25.276988 .. 44.651368
[12:26:17.847] <TB3> INFO: Expecting 208000 events.
[12:26:27.993] <TB3> INFO: 208000 events read in total (9554ms).
[12:26:27.994] <TB3> INFO: Test took 10425ms.
[12:26:28.042] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 15 .. 54 (-1/-1) hits flags = 528 (plus default)
[12:26:28.050] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:26:28.050] <TB3> INFO: run 1 of 1
[12:26:28.328] <TB3> INFO: Expecting 1331200 events.
[12:26:57.116] <TB3> INFO: 672320 events read in total (28196ms).
[12:27:25.171] <TB3> INFO: 1331200 events read in total (56251ms).
[12:27:25.197] <TB3> INFO: Test took 57146ms.
[12:27:36.951] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:27:36.951] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[12:27:36.961] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:27:36.961] <TB3> INFO: run 1 of 1
[12:27:37.206] <TB3> INFO: Expecting 1364480 events.
[12:28:05.875] <TB3> INFO: 667368 events read in total (28077ms).
[12:28:34.356] <TB3> INFO: 1334048 events read in total (56559ms).
[12:28:36.226] <TB3> INFO: 1364480 events read in total (58428ms).
[12:28:36.257] <TB3> INFO: Test took 59297ms.
[12:28:47.844] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C0.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C1.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C2.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C3.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C4.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C5.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C6.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C7.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C8.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C9.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C10.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C11.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C12.dat
[12:28:47.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C13.dat
[12:28:47.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C14.dat
[12:28:47.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C15.dat
[12:28:47.846] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C0.dat
[12:28:47.852] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C1.dat
[12:28:47.857] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C2.dat
[12:28:47.863] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C3.dat
[12:28:47.868] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C4.dat
[12:28:47.874] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C5.dat
[12:28:47.879] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C6.dat
[12:28:47.885] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C7.dat
[12:28:47.890] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C8.dat
[12:28:47.896] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C9.dat
[12:28:47.901] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C10.dat
[12:28:47.907] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C11.dat
[12:28:47.912] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C12.dat
[12:28:47.918] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C13.dat
[12:28:47.923] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C14.dat
[12:28:47.929] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C15.dat
[12:28:47.934] <TB3> INFO: PixTestTrim::trimTest() done
[12:28:47.934] <TB3> INFO: vtrim: 142 135 127 160 120 129 146 115 141 127 127 110 137 146 137 136
[12:28:47.934] <TB3> INFO: vthrcomp: 119 111 111 122 106 120 108 114 108 110 113 111 107 105 126 118
[12:28:47.934] <TB3> INFO: vcal mean: 34.94 34.95 35.05 34.92 34.99 34.98 34.94 34.96 34.99 34.98 34.90 34.95 34.97 35.03 34.88 34.93
[12:28:47.934] <TB3> INFO: vcal RMS: 1.02 0.98 0.97 1.12 0.95 1.03 0.98 1.03 0.98 0.94 1.04 0.99 1.04 0.96 1.07 1.10
[12:28:47.934] <TB3> INFO: bits mean: 10.18 8.73 9.16 10.37 9.15 9.94 9.02 9.45 9.51 9.39 9.88 8.58 9.27 9.73 10.40 10.11
[12:28:47.934] <TB3> INFO: bits RMS: 2.59 2.74 2.53 2.34 2.50 2.35 2.38 2.63 2.27 2.35 2.51 2.66 2.37 2.38 2.41 2.51
[12:28:47.941] <TB3> INFO: ----------------------------------------------------------------------
[12:28:47.941] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[12:28:47.941] <TB3> INFO: ----------------------------------------------------------------------
[12:28:47.943] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[12:28:47.952] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:28:47.952] <TB3> INFO: run 1 of 1
[12:28:48.185] <TB3> INFO: Expecting 4160000 events.
[12:29:20.614] <TB3> INFO: 723215 events read in total (31838ms).
[12:29:52.197] <TB3> INFO: 1441025 events read in total (63421ms).
[12:30:23.125] <TB3> INFO: 2155815 events read in total (94349ms).
[12:30:54.425] <TB3> INFO: 2867180 events read in total (125649ms).
[12:31:25.730] <TB3> INFO: 3574765 events read in total (156954ms).
[12:31:51.628] <TB3> INFO: 4160000 events read in total (182852ms).
[12:31:51.696] <TB3> INFO: Test took 183744ms.
[12:32:15.783] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 182 (-1/-1) hits flags = 528 (plus default)
[12:32:15.796] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:32:15.796] <TB3> INFO: run 1 of 1
[12:32:16.081] <TB3> INFO: Expecting 3806400 events.
[12:32:48.227] <TB3> INFO: 722065 events read in total (31555ms).
[12:33:19.652] <TB3> INFO: 1438415 events read in total (62980ms).
[12:33:50.906] <TB3> INFO: 2151240 events read in total (94235ms).
[12:34:22.447] <TB3> INFO: 2860175 events read in total (125775ms).
[12:34:53.796] <TB3> INFO: 3566560 events read in total (157124ms).
[12:35:04.797] <TB3> INFO: 3806400 events read in total (168125ms).
[12:35:04.843] <TB3> INFO: Test took 169047ms.
[12:35:28.573] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 168 (-1/-1) hits flags = 528 (plus default)
[12:35:28.583] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:35:28.583] <TB3> INFO: run 1 of 1
[12:35:28.815] <TB3> INFO: Expecting 3515200 events.
[12:36:01.710] <TB3> INFO: 743955 events read in total (32303ms).
[12:36:34.102] <TB3> INFO: 1481395 events read in total (64695ms).
[12:37:05.958] <TB3> INFO: 2214400 events read in total (96552ms).
[12:37:38.011] <TB3> INFO: 2942075 events read in total (128604ms).
[12:38:03.064] <TB3> INFO: 3515200 events read in total (153657ms).
[12:38:03.108] <TB3> INFO: Test took 154525ms.
[12:38:28.565] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 169 (-1/-1) hits flags = 528 (plus default)
[12:38:28.577] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:38:28.577] <TB3> INFO: run 1 of 1
[12:38:28.835] <TB3> INFO: Expecting 3536000 events.
[12:39:01.190] <TB3> INFO: 742760 events read in total (31764ms).
[12:39:33.008] <TB3> INFO: 1478880 events read in total (63582ms).
[12:40:05.017] <TB3> INFO: 2210680 events read in total (95591ms).
[12:40:37.052] <TB3> INFO: 2937400 events read in total (127626ms).
[12:41:03.514] <TB3> INFO: 3536000 events read in total (154088ms).
[12:41:03.575] <TB3> INFO: Test took 154997ms.
[12:41:25.064] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 168 (-1/-1) hits flags = 528 (plus default)
[12:41:25.073] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:41:25.073] <TB3> INFO: run 1 of 1
[12:41:25.304] <TB3> INFO: Expecting 3515200 events.
[12:41:58.599] <TB3> INFO: 744525 events read in total (32703ms).
[12:42:30.282] <TB3> INFO: 1482740 events read in total (64386ms).
[12:43:02.211] <TB3> INFO: 2216160 events read in total (96316ms).
[12:43:34.020] <TB3> INFO: 2944410 events read in total (128124ms).
[12:43:59.169] <TB3> INFO: 3515200 events read in total (153273ms).
[12:43:59.229] <TB3> INFO: Test took 154156ms.
[12:44:19.568] <TB3> INFO: PixTestTrim::trimBitTest() done
[12:44:19.569] <TB3> INFO: PixTestTrim::doTest() done, duration: 2378 seconds
[12:44:19.569] <TB3> INFO: Decoding statistics:
[12:44:19.569] <TB3> INFO: General information:
[12:44:19.569] <TB3> INFO: 16bit words read: 0
[12:44:19.569] <TB3> INFO: valid events total: 0
[12:44:19.569] <TB3> INFO: empty events: 0
[12:44:19.569] <TB3> INFO: valid events with pixels: 0
[12:44:19.569] <TB3> INFO: valid pixel hits: 0
[12:44:19.569] <TB3> INFO: Event errors: 0
[12:44:19.569] <TB3> INFO: start marker: 0
[12:44:19.569] <TB3> INFO: stop marker: 0
[12:44:19.569] <TB3> INFO: overflow: 0
[12:44:19.569] <TB3> INFO: invalid 5bit words: 0
[12:44:19.569] <TB3> INFO: invalid XOR eye diagram: 0
[12:44:19.569] <TB3> INFO: frame (failed synchr.): 0
[12:44:19.569] <TB3> INFO: idle data (no TBM trl): 0
[12:44:19.569] <TB3> INFO: no data (only TBM hdr): 0
[12:44:19.569] <TB3> INFO: TBM errors: 0
[12:44:19.569] <TB3> INFO: flawed TBM headers: 0
[12:44:19.569] <TB3> INFO: flawed TBM trailers: 0
[12:44:19.569] <TB3> INFO: event ID mismatches: 0
[12:44:19.569] <TB3> INFO: ROC errors: 0
[12:44:19.569] <TB3> INFO: missing ROC header(s): 0
[12:44:19.569] <TB3> INFO: misplaced readback start: 0
[12:44:19.569] <TB3> INFO: Pixel decoding errors: 0
[12:44:19.569] <TB3> INFO: pixel data incomplete: 0
[12:44:19.570] <TB3> INFO: pixel address: 0
[12:44:19.570] <TB3> INFO: pulse height fill bit: 0
[12:44:19.570] <TB3> INFO: buffer corruption: 0
[12:44:20.198] <TB3> INFO: ######################################################################
[12:44:20.198] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:44:20.198] <TB3> INFO: ######################################################################
[12:44:20.488] <TB3> INFO: Expecting 41600 events.
[12:44:24.101] <TB3> INFO: 41600 events read in total (3022ms).
[12:44:24.102] <TB3> INFO: Test took 3903ms.
[12:44:24.573] <TB3> INFO: Expecting 41600 events.
[12:44:28.163] <TB3> INFO: 41600 events read in total (2998ms).
[12:44:28.164] <TB3> INFO: Test took 3859ms.
[12:44:28.452] <TB3> INFO: Expecting 41600 events.
[12:44:32.082] <TB3> INFO: 41600 events read in total (3039ms).
[12:44:32.083] <TB3> INFO: Test took 3896ms.
[12:44:32.375] <TB3> INFO: Expecting 41600 events.
[12:44:35.855] <TB3> INFO: 41600 events read in total (2888ms).
[12:44:35.856] <TB3> INFO: Test took 3745ms.
[12:44:36.144] <TB3> INFO: Expecting 41600 events.
[12:44:39.880] <TB3> INFO: 41600 events read in total (3145ms).
[12:44:39.881] <TB3> INFO: Test took 4002ms.
[12:44:40.172] <TB3> INFO: Expecting 41600 events.
[12:44:43.806] <TB3> INFO: 41600 events read in total (3043ms).
[12:44:43.806] <TB3> INFO: Test took 3899ms.
[12:44:44.094] <TB3> INFO: Expecting 41600 events.
[12:44:47.787] <TB3> INFO: 41600 events read in total (3101ms).
[12:44:47.788] <TB3> INFO: Test took 3958ms.
[12:44:48.076] <TB3> INFO: Expecting 41600 events.
[12:44:51.587] <TB3> INFO: 41600 events read in total (2920ms).
[12:44:51.588] <TB3> INFO: Test took 3777ms.
[12:44:51.876] <TB3> INFO: Expecting 41600 events.
[12:44:55.433] <TB3> INFO: 41600 events read in total (2965ms).
[12:44:55.433] <TB3> INFO: Test took 3822ms.
[12:44:55.725] <TB3> INFO: Expecting 41600 events.
[12:44:59.307] <TB3> INFO: 41600 events read in total (2991ms).
[12:44:59.308] <TB3> INFO: Test took 3848ms.
[12:44:59.599] <TB3> INFO: Expecting 41600 events.
[12:45:03.099] <TB3> INFO: 41600 events read in total (2908ms).
[12:45:03.100] <TB3> INFO: Test took 3766ms.
[12:45:03.415] <TB3> INFO: Expecting 41600 events.
[12:45:06.969] <TB3> INFO: 41600 events read in total (2963ms).
[12:45:06.970] <TB3> INFO: Test took 3844ms.
[12:45:07.258] <TB3> INFO: Expecting 41600 events.
[12:45:10.890] <TB3> INFO: 41600 events read in total (3040ms).
[12:45:10.892] <TB3> INFO: Test took 3898ms.
[12:45:11.183] <TB3> INFO: Expecting 41600 events.
[12:45:14.975] <TB3> INFO: 41600 events read in total (3200ms).
[12:45:14.976] <TB3> INFO: Test took 4058ms.
[12:45:15.306] <TB3> INFO: Expecting 41600 events.
[12:45:19.072] <TB3> INFO: 41600 events read in total (3174ms).
[12:45:19.073] <TB3> INFO: Test took 4073ms.
[12:45:19.364] <TB3> INFO: Expecting 41600 events.
[12:45:23.060] <TB3> INFO: 41600 events read in total (3104ms).
[12:45:23.061] <TB3> INFO: Test took 3961ms.
[12:45:23.349] <TB3> INFO: Expecting 41600 events.
[12:45:26.948] <TB3> INFO: 41600 events read in total (3007ms).
[12:45:26.949] <TB3> INFO: Test took 3864ms.
[12:45:27.236] <TB3> INFO: Expecting 41600 events.
[12:45:30.707] <TB3> INFO: 41600 events read in total (2879ms).
[12:45:30.708] <TB3> INFO: Test took 3736ms.
[12:45:30.996] <TB3> INFO: Expecting 41600 events.
[12:45:34.584] <TB3> INFO: 41600 events read in total (2997ms).
[12:45:34.584] <TB3> INFO: Test took 3853ms.
[12:45:34.872] <TB3> INFO: Expecting 41600 events.
[12:45:38.334] <TB3> INFO: 41600 events read in total (2871ms).
[12:45:38.334] <TB3> INFO: Test took 3727ms.
[12:45:38.650] <TB3> INFO: Expecting 41600 events.
[12:45:42.253] <TB3> INFO: 41600 events read in total (3011ms).
[12:45:42.253] <TB3> INFO: Test took 3895ms.
[12:45:42.541] <TB3> INFO: Expecting 41600 events.
[12:45:46.156] <TB3> INFO: 41600 events read in total (3023ms).
[12:45:46.157] <TB3> INFO: Test took 3881ms.
[12:45:46.449] <TB3> INFO: Expecting 41600 events.
[12:45:50.059] <TB3> INFO: 41600 events read in total (3018ms).
[12:45:50.059] <TB3> INFO: Test took 3875ms.
[12:45:50.348] <TB3> INFO: Expecting 41600 events.
[12:45:53.920] <TB3> INFO: 41600 events read in total (2981ms).
[12:45:53.921] <TB3> INFO: Test took 3838ms.
[12:45:54.209] <TB3> INFO: Expecting 41600 events.
[12:45:57.687] <TB3> INFO: 41600 events read in total (2886ms).
[12:45:57.688] <TB3> INFO: Test took 3743ms.
[12:45:57.976] <TB3> INFO: Expecting 41600 events.
[12:46:01.600] <TB3> INFO: 41600 events read in total (3033ms).
[12:46:01.601] <TB3> INFO: Test took 3890ms.
[12:46:01.915] <TB3> INFO: Expecting 41600 events.
[12:46:05.427] <TB3> INFO: 41600 events read in total (2921ms).
[12:46:05.428] <TB3> INFO: Test took 3800ms.
[12:46:05.749] <TB3> INFO: Expecting 41600 events.
[12:46:09.375] <TB3> INFO: 41600 events read in total (3035ms).
[12:46:09.376] <TB3> INFO: Test took 3921ms.
[12:46:09.699] <TB3> INFO: Expecting 41600 events.
[12:46:13.219] <TB3> INFO: 41600 events read in total (2929ms).
[12:46:13.219] <TB3> INFO: Test took 3814ms.
[12:46:13.509] <TB3> INFO: Expecting 2560 events.
[12:46:14.393] <TB3> INFO: 2560 events read in total (293ms).
[12:46:14.394] <TB3> INFO: Test took 1162ms.
[12:46:14.701] <TB3> INFO: Expecting 2560 events.
[12:46:15.590] <TB3> INFO: 2560 events read in total (297ms).
[12:46:15.590] <TB3> INFO: Test took 1196ms.
[12:46:15.897] <TB3> INFO: Expecting 2560 events.
[12:46:16.785] <TB3> INFO: 2560 events read in total (296ms).
[12:46:16.785] <TB3> INFO: Test took 1195ms.
[12:46:17.093] <TB3> INFO: Expecting 2560 events.
[12:46:17.976] <TB3> INFO: 2560 events read in total (292ms).
[12:46:17.977] <TB3> INFO: Test took 1192ms.
[12:46:18.284] <TB3> INFO: Expecting 2560 events.
[12:46:19.163] <TB3> INFO: 2560 events read in total (287ms).
[12:46:19.163] <TB3> INFO: Test took 1186ms.
[12:46:19.472] <TB3> INFO: Expecting 2560 events.
[12:46:20.351] <TB3> INFO: 2560 events read in total (288ms).
[12:46:20.351] <TB3> INFO: Test took 1187ms.
[12:46:20.659] <TB3> INFO: Expecting 2560 events.
[12:46:21.542] <TB3> INFO: 2560 events read in total (292ms).
[12:46:21.542] <TB3> INFO: Test took 1191ms.
[12:46:21.850] <TB3> INFO: Expecting 2560 events.
[12:46:22.733] <TB3> INFO: 2560 events read in total (291ms).
[12:46:22.733] <TB3> INFO: Test took 1191ms.
[12:46:23.041] <TB3> INFO: Expecting 2560 events.
[12:46:23.921] <TB3> INFO: 2560 events read in total (288ms).
[12:46:23.921] <TB3> INFO: Test took 1187ms.
[12:46:24.229] <TB3> INFO: Expecting 2560 events.
[12:46:25.111] <TB3> INFO: 2560 events read in total (291ms).
[12:46:25.111] <TB3> INFO: Test took 1189ms.
[12:46:25.419] <TB3> INFO: Expecting 2560 events.
[12:46:26.299] <TB3> INFO: 2560 events read in total (288ms).
[12:46:26.299] <TB3> INFO: Test took 1187ms.
[12:46:26.607] <TB3> INFO: Expecting 2560 events.
[12:46:27.487] <TB3> INFO: 2560 events read in total (289ms).
[12:46:27.487] <TB3> INFO: Test took 1188ms.
[12:46:27.795] <TB3> INFO: Expecting 2560 events.
[12:46:28.683] <TB3> INFO: 2560 events read in total (297ms).
[12:46:28.683] <TB3> INFO: Test took 1195ms.
[12:46:28.990] <TB3> INFO: Expecting 2560 events.
[12:46:29.874] <TB3> INFO: 2560 events read in total (292ms).
[12:46:29.874] <TB3> INFO: Test took 1191ms.
[12:46:30.181] <TB3> INFO: Expecting 2560 events.
[12:46:31.065] <TB3> INFO: 2560 events read in total (292ms).
[12:46:31.065] <TB3> INFO: Test took 1191ms.
[12:46:31.373] <TB3> INFO: Expecting 2560 events.
[12:46:32.261] <TB3> INFO: 2560 events read in total (296ms).
[12:46:32.261] <TB3> INFO: Test took 1196ms.
[12:46:32.264] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:46:32.570] <TB3> INFO: Expecting 655360 events.
[12:46:47.401] <TB3> INFO: 655360 events read in total (14240ms).
[12:46:47.411] <TB3> INFO: Expecting 655360 events.
[12:47:01.883] <TB3> INFO: 655360 events read in total (14069ms).
[12:47:01.897] <TB3> INFO: Expecting 655360 events.
[12:47:16.578] <TB3> INFO: 655360 events read in total (14278ms).
[12:47:16.596] <TB3> INFO: Expecting 655360 events.
[12:47:31.295] <TB3> INFO: 655360 events read in total (14296ms).
[12:47:31.318] <TB3> INFO: Expecting 655360 events.
[12:47:45.860] <TB3> INFO: 655360 events read in total (14139ms).
[12:47:45.886] <TB3> INFO: Expecting 655360 events.
[12:48:00.323] <TB3> INFO: 655360 events read in total (14033ms).
[12:48:00.353] <TB3> INFO: Expecting 655360 events.
[12:48:15.026] <TB3> INFO: 655360 events read in total (14270ms).
[12:48:15.060] <TB3> INFO: Expecting 655360 events.
[12:48:29.788] <TB3> INFO: 655360 events read in total (14325ms).
[12:48:29.845] <TB3> INFO: Expecting 655360 events.
[12:48:44.533] <TB3> INFO: 655360 events read in total (14285ms).
[12:48:44.604] <TB3> INFO: Expecting 655360 events.
[12:48:59.369] <TB3> INFO: 655360 events read in total (14362ms).
[12:48:59.416] <TB3> INFO: Expecting 655360 events.
[12:49:14.066] <TB3> INFO: 655360 events read in total (14247ms).
[12:49:14.119] <TB3> INFO: Expecting 655360 events.
[12:49:28.885] <TB3> INFO: 655360 events read in total (14363ms).
[12:49:28.942] <TB3> INFO: Expecting 655360 events.
[12:49:43.365] <TB3> INFO: 655360 events read in total (14020ms).
[12:49:43.426] <TB3> INFO: Expecting 655360 events.
[12:49:58.036] <TB3> INFO: 655360 events read in total (14207ms).
[12:49:58.105] <TB3> INFO: Expecting 655360 events.
[12:50:12.762] <TB3> INFO: 655360 events read in total (14254ms).
[12:50:12.864] <TB3> INFO: Expecting 655360 events.
[12:50:27.415] <TB3> INFO: 655360 events read in total (14148ms).
[12:50:27.491] <TB3> INFO: Test took 235227ms.
[12:50:27.574] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:50:27.839] <TB3> INFO: Expecting 655360 events.
[12:50:42.439] <TB3> INFO: 655360 events read in total (14008ms).
[12:50:42.449] <TB3> INFO: Expecting 655360 events.
[12:50:56.824] <TB3> INFO: 655360 events read in total (13972ms).
[12:50:56.839] <TB3> INFO: Expecting 655360 events.
[12:51:11.417] <TB3> INFO: 655360 events read in total (14175ms).
[12:51:11.435] <TB3> INFO: Expecting 655360 events.
[12:51:25.890] <TB3> INFO: 655360 events read in total (14052ms).
[12:51:25.913] <TB3> INFO: Expecting 655360 events.
[12:51:40.368] <TB3> INFO: 655360 events read in total (14052ms).
[12:51:40.395] <TB3> INFO: Expecting 655360 events.
[12:51:54.785] <TB3> INFO: 655360 events read in total (13987ms).
[12:51:54.815] <TB3> INFO: Expecting 655360 events.
[12:52:09.305] <TB3> INFO: 655360 events read in total (14087ms).
[12:52:09.340] <TB3> INFO: Expecting 655360 events.
[12:52:23.474] <TB3> INFO: 655360 events read in total (13731ms).
[12:52:23.512] <TB3> INFO: Expecting 655360 events.
[12:52:37.866] <TB3> INFO: 655360 events read in total (13951ms).
[12:52:37.932] <TB3> INFO: Expecting 655360 events.
[12:52:52.307] <TB3> INFO: 655360 events read in total (13972ms).
[12:52:52.374] <TB3> INFO: Expecting 655360 events.
[12:53:06.782] <TB3> INFO: 655360 events read in total (14005ms).
[12:53:06.835] <TB3> INFO: Expecting 655360 events.
[12:53:21.216] <TB3> INFO: 655360 events read in total (13978ms).
[12:53:21.273] <TB3> INFO: Expecting 655360 events.
[12:53:35.650] <TB3> INFO: 655360 events read in total (13974ms).
[12:53:35.710] <TB3> INFO: Expecting 655360 events.
[12:53:50.348] <TB3> INFO: 655360 events read in total (14235ms).
[12:53:50.412] <TB3> INFO: Expecting 655360 events.
[12:54:05.170] <TB3> INFO: 655360 events read in total (14355ms).
[12:54:05.239] <TB3> INFO: Expecting 655360 events.
[12:54:19.733] <TB3> INFO: 655360 events read in total (14091ms).
[12:54:19.806] <TB3> INFO: Test took 232232ms.
[12:54:19.962] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:19.967] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:19.971] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:19.975] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:19.980] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:19.984] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:19.989] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:19.993] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:19.998] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:54:19.002] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.007] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.012] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.016] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.021] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:20.025] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.030] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.035] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.039] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.044] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.048] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:20.053] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:20.057] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:54:20.062] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[12:54:20.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C0.dat
[12:54:20.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C1.dat
[12:54:20.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C2.dat
[12:54:20.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C3.dat
[12:54:20.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C4.dat
[12:54:20.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C5.dat
[12:54:20.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C6.dat
[12:54:20.095] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C7.dat
[12:54:20.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C8.dat
[12:54:20.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C9.dat
[12:54:20.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C10.dat
[12:54:20.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C11.dat
[12:54:20.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C12.dat
[12:54:20.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C13.dat
[12:54:20.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C14.dat
[12:54:20.096] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C15.dat
[12:54:20.331] <TB3> INFO: Expecting 41600 events.
[12:54:23.448] <TB3> INFO: 41600 events read in total (2525ms).
[12:54:23.448] <TB3> INFO: Test took 3349ms.
[12:54:23.891] <TB3> INFO: Expecting 41600 events.
[12:54:27.011] <TB3> INFO: 41600 events read in total (2528ms).
[12:54:27.012] <TB3> INFO: Test took 3353ms.
[12:54:27.466] <TB3> INFO: Expecting 41600 events.
[12:54:30.615] <TB3> INFO: 41600 events read in total (2558ms).
[12:54:30.616] <TB3> INFO: Test took 3390ms.
[12:54:30.836] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:30.925] <TB3> INFO: Expecting 2560 events.
[12:54:31.813] <TB3> INFO: 2560 events read in total (296ms).
[12:54:31.813] <TB3> INFO: Test took 977ms.
[12:54:31.815] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:32.121] <TB3> INFO: Expecting 2560 events.
[12:54:33.009] <TB3> INFO: 2560 events read in total (296ms).
[12:54:33.009] <TB3> INFO: Test took 1194ms.
[12:54:33.011] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:33.317] <TB3> INFO: Expecting 2560 events.
[12:54:34.205] <TB3> INFO: 2560 events read in total (296ms).
[12:54:34.205] <TB3> INFO: Test took 1194ms.
[12:54:34.207] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:34.513] <TB3> INFO: Expecting 2560 events.
[12:54:35.397] <TB3> INFO: 2560 events read in total (292ms).
[12:54:35.397] <TB3> INFO: Test took 1190ms.
[12:54:35.399] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:35.706] <TB3> INFO: Expecting 2560 events.
[12:54:36.590] <TB3> INFO: 2560 events read in total (292ms).
[12:54:36.590] <TB3> INFO: Test took 1191ms.
[12:54:36.592] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:36.898] <TB3> INFO: Expecting 2560 events.
[12:54:37.782] <TB3> INFO: 2560 events read in total (292ms).
[12:54:37.782] <TB3> INFO: Test took 1190ms.
[12:54:37.784] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:38.091] <TB3> INFO: Expecting 2560 events.
[12:54:38.978] <TB3> INFO: 2560 events read in total (295ms).
[12:54:38.979] <TB3> INFO: Test took 1195ms.
[12:54:38.980] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:39.287] <TB3> INFO: Expecting 2560 events.
[12:54:40.171] <TB3> INFO: 2560 events read in total (292ms).
[12:54:40.171] <TB3> INFO: Test took 1191ms.
[12:54:40.173] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:40.479] <TB3> INFO: Expecting 2560 events.
[12:54:41.360] <TB3> INFO: 2560 events read in total (289ms).
[12:54:41.360] <TB3> INFO: Test took 1187ms.
[12:54:41.362] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:41.668] <TB3> INFO: Expecting 2560 events.
[12:54:42.548] <TB3> INFO: 2560 events read in total (288ms).
[12:54:42.549] <TB3> INFO: Test took 1187ms.
[12:54:42.551] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:42.857] <TB3> INFO: Expecting 2560 events.
[12:54:43.741] <TB3> INFO: 2560 events read in total (293ms).
[12:54:43.741] <TB3> INFO: Test took 1190ms.
[12:54:43.743] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:44.050] <TB3> INFO: Expecting 2560 events.
[12:54:44.929] <TB3> INFO: 2560 events read in total (288ms).
[12:54:44.929] <TB3> INFO: Test took 1186ms.
[12:54:44.931] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:45.237] <TB3> INFO: Expecting 2560 events.
[12:54:46.122] <TB3> INFO: 2560 events read in total (293ms).
[12:54:46.122] <TB3> INFO: Test took 1192ms.
[12:54:46.124] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:46.430] <TB3> INFO: Expecting 2560 events.
[12:54:47.310] <TB3> INFO: 2560 events read in total (288ms).
[12:54:47.310] <TB3> INFO: Test took 1186ms.
[12:54:47.312] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:47.618] <TB3> INFO: Expecting 2560 events.
[12:54:48.497] <TB3> INFO: 2560 events read in total (287ms).
[12:54:48.498] <TB3> INFO: Test took 1186ms.
[12:54:48.500] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:48.806] <TB3> INFO: Expecting 2560 events.
[12:54:49.685] <TB3> INFO: 2560 events read in total (288ms).
[12:54:49.685] <TB3> INFO: Test took 1185ms.
[12:54:49.688] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:49.994] <TB3> INFO: Expecting 2560 events.
[12:54:50.877] <TB3> INFO: 2560 events read in total (292ms).
[12:54:50.878] <TB3> INFO: Test took 1190ms.
[12:54:50.879] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:51.186] <TB3> INFO: Expecting 2560 events.
[12:54:52.065] <TB3> INFO: 2560 events read in total (288ms).
[12:54:52.066] <TB3> INFO: Test took 1187ms.
[12:54:52.068] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:52.374] <TB3> INFO: Expecting 2560 events.
[12:54:53.253] <TB3> INFO: 2560 events read in total (287ms).
[12:54:53.253] <TB3> INFO: Test took 1186ms.
[12:54:53.255] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:53.562] <TB3> INFO: Expecting 2560 events.
[12:54:54.445] <TB3> INFO: 2560 events read in total (292ms).
[12:54:54.445] <TB3> INFO: Test took 1190ms.
[12:54:54.447] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:54.754] <TB3> INFO: Expecting 2560 events.
[12:54:55.634] <TB3> INFO: 2560 events read in total (288ms).
[12:54:55.634] <TB3> INFO: Test took 1187ms.
[12:54:55.636] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:55.942] <TB3> INFO: Expecting 2560 events.
[12:54:56.823] <TB3> INFO: 2560 events read in total (289ms).
[12:54:56.823] <TB3> INFO: Test took 1187ms.
[12:54:56.825] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:57.131] <TB3> INFO: Expecting 2560 events.
[12:54:58.014] <TB3> INFO: 2560 events read in total (291ms).
[12:54:58.015] <TB3> INFO: Test took 1190ms.
[12:54:58.017] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:58.323] <TB3> INFO: Expecting 2560 events.
[12:54:59.206] <TB3> INFO: 2560 events read in total (291ms).
[12:54:59.207] <TB3> INFO: Test took 1190ms.
[12:54:59.209] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:59.515] <TB3> INFO: Expecting 2560 events.
[12:55:00.401] <TB3> INFO: 2560 events read in total (294ms).
[12:55:00.402] <TB3> INFO: Test took 1193ms.
[12:55:00.404] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:00.710] <TB3> INFO: Expecting 2560 events.
[12:55:01.598] <TB3> INFO: 2560 events read in total (296ms).
[12:55:01.598] <TB3> INFO: Test took 1194ms.
[12:55:01.600] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:01.907] <TB3> INFO: Expecting 2560 events.
[12:55:02.795] <TB3> INFO: 2560 events read in total (297ms).
[12:55:02.795] <TB3> INFO: Test took 1195ms.
[12:55:02.797] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:03.103] <TB3> INFO: Expecting 2560 events.
[12:55:03.987] <TB3> INFO: 2560 events read in total (292ms).
[12:55:03.988] <TB3> INFO: Test took 1191ms.
[12:55:03.989] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:04.296] <TB3> INFO: Expecting 2560 events.
[12:55:05.180] <TB3> INFO: 2560 events read in total (292ms).
[12:55:05.180] <TB3> INFO: Test took 1191ms.
[12:55:05.182] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:05.489] <TB3> INFO: Expecting 2560 events.
[12:55:06.376] <TB3> INFO: 2560 events read in total (296ms).
[12:55:06.376] <TB3> INFO: Test took 1194ms.
[12:55:06.379] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:06.685] <TB3> INFO: Expecting 2560 events.
[12:55:07.572] <TB3> INFO: 2560 events read in total (295ms).
[12:55:07.572] <TB3> INFO: Test took 1193ms.
[12:55:07.574] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:07.881] <TB3> INFO: Expecting 2560 events.
[12:55:08.765] <TB3> INFO: 2560 events read in total (293ms).
[12:55:08.765] <TB3> INFO: Test took 1191ms.
[12:55:09.225] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 649 seconds
[12:55:09.225] <TB3> INFO: PH scale (per ROC): 63 42 63 64 67 64 57 47 53 46 62 61 50 71 59 48
[12:55:09.225] <TB3> INFO: PH offset (per ROC): 131 96 131 121 126 121 136 84 118 103 124 126 109 122 118 101
[12:55:09.232] <TB3> INFO: Decoding statistics:
[12:55:09.232] <TB3> INFO: General information:
[12:55:09.232] <TB3> INFO: 16bit words read: 127876
[12:55:09.232] <TB3> INFO: valid events total: 20480
[12:55:09.232] <TB3> INFO: empty events: 17982
[12:55:09.232] <TB3> INFO: valid events with pixels: 2498
[12:55:09.232] <TB3> INFO: valid pixel hits: 2498
[12:55:09.232] <TB3> INFO: Event errors: 0
[12:55:09.232] <TB3> INFO: start marker: 0
[12:55:09.232] <TB3> INFO: stop marker: 0
[12:55:09.232] <TB3> INFO: overflow: 0
[12:55:09.232] <TB3> INFO: invalid 5bit words: 0
[12:55:09.232] <TB3> INFO: invalid XOR eye diagram: 0
[12:55:09.232] <TB3> INFO: frame (failed synchr.): 0
[12:55:09.232] <TB3> INFO: idle data (no TBM trl): 0
[12:55:09.232] <TB3> INFO: no data (only TBM hdr): 0
[12:55:09.232] <TB3> INFO: TBM errors: 0
[12:55:09.232] <TB3> INFO: flawed TBM headers: 0
[12:55:09.232] <TB3> INFO: flawed TBM trailers: 0
[12:55:09.232] <TB3> INFO: event ID mismatches: 0
[12:55:09.232] <TB3> INFO: ROC errors: 0
[12:55:09.232] <TB3> INFO: missing ROC header(s): 0
[12:55:09.232] <TB3> INFO: misplaced readback start: 0
[12:55:09.232] <TB3> INFO: Pixel decoding errors: 0
[12:55:09.232] <TB3> INFO: pixel data incomplete: 0
[12:55:09.232] <TB3> INFO: pixel address: 0
[12:55:09.233] <TB3> INFO: pulse height fill bit: 0
[12:55:09.233] <TB3> INFO: buffer corruption: 0
[12:55:09.608] <TB3> INFO: ######################################################################
[12:55:09.608] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:55:09.608] <TB3> INFO: ######################################################################
[12:55:09.619] <TB3> INFO: scanning low vcal = 10
[12:55:09.850] <TB3> INFO: Expecting 41600 events.
[12:55:13.419] <TB3> INFO: 41600 events read in total (2977ms).
[12:55:13.419] <TB3> INFO: Test took 3799ms.
[12:55:13.421] <TB3> INFO: scanning low vcal = 20
[12:55:13.717] <TB3> INFO: Expecting 41600 events.
[12:55:17.308] <TB3> INFO: 41600 events read in total (2999ms).
[12:55:17.308] <TB3> INFO: Test took 3887ms.
[12:55:17.310] <TB3> INFO: scanning low vcal = 30
[12:55:17.609] <TB3> INFO: Expecting 41600 events.
[12:55:21.237] <TB3> INFO: 41600 events read in total (3036ms).
[12:55:21.238] <TB3> INFO: Test took 3928ms.
[12:55:21.240] <TB3> INFO: scanning low vcal = 40
[12:55:21.521] <TB3> INFO: Expecting 41600 events.
[12:55:25.456] <TB3> INFO: 41600 events read in total (3343ms).
[12:55:25.457] <TB3> INFO: Test took 4217ms.
[12:55:25.461] <TB3> INFO: scanning low vcal = 50
[12:55:25.737] <TB3> INFO: Expecting 41600 events.
[12:55:29.711] <TB3> INFO: 41600 events read in total (3382ms).
[12:55:29.711] <TB3> INFO: Test took 4250ms.
[12:55:29.714] <TB3> INFO: scanning low vcal = 60
[12:55:29.991] <TB3> INFO: Expecting 41600 events.
[12:55:33.962] <TB3> INFO: 41600 events read in total (3380ms).
[12:55:33.962] <TB3> INFO: Test took 4248ms.
[12:55:33.965] <TB3> INFO: scanning low vcal = 70
[12:55:34.242] <TB3> INFO: Expecting 41600 events.
[12:55:38.210] <TB3> INFO: 41600 events read in total (3377ms).
[12:55:38.210] <TB3> INFO: Test took 4245ms.
[12:55:38.213] <TB3> INFO: scanning low vcal = 80
[12:55:38.490] <TB3> INFO: Expecting 41600 events.
[12:55:42.438] <TB3> INFO: 41600 events read in total (3357ms).
[12:55:42.438] <TB3> INFO: Test took 4225ms.
[12:55:42.441] <TB3> INFO: scanning low vcal = 90
[12:55:42.717] <TB3> INFO: Expecting 41600 events.
[12:55:46.722] <TB3> INFO: 41600 events read in total (3413ms).
[12:55:46.722] <TB3> INFO: Test took 4281ms.
[12:55:46.725] <TB3> INFO: scanning low vcal = 100
[12:55:46.002] <TB3> INFO: Expecting 41600 events.
[12:55:50.975] <TB3> INFO: 41600 events read in total (3382ms).
[12:55:50.975] <TB3> INFO: Test took 4250ms.
[12:55:50.978] <TB3> INFO: scanning low vcal = 110
[12:55:51.274] <TB3> INFO: Expecting 41600 events.
[12:55:55.317] <TB3> INFO: 41600 events read in total (3451ms).
[12:55:55.317] <TB3> INFO: Test took 4339ms.
[12:55:55.320] <TB3> INFO: scanning low vcal = 120
[12:55:55.597] <TB3> INFO: Expecting 41600 events.
[12:55:59.601] <TB3> INFO: 41600 events read in total (3413ms).
[12:55:59.602] <TB3> INFO: Test took 4282ms.
[12:55:59.606] <TB3> INFO: scanning low vcal = 130
[12:55:59.898] <TB3> INFO: Expecting 41600 events.
[12:56:03.929] <TB3> INFO: 41600 events read in total (3440ms).
[12:56:03.930] <TB3> INFO: Test took 4324ms.
[12:56:03.933] <TB3> INFO: scanning low vcal = 140
[12:56:04.210] <TB3> INFO: Expecting 41600 events.
[12:56:08.283] <TB3> INFO: 41600 events read in total (3482ms).
[12:56:08.284] <TB3> INFO: Test took 4351ms.
[12:56:08.287] <TB3> INFO: scanning low vcal = 150
[12:56:08.564] <TB3> INFO: Expecting 41600 events.
[12:56:12.533] <TB3> INFO: 41600 events read in total (3378ms).
[12:56:12.533] <TB3> INFO: Test took 4246ms.
[12:56:12.536] <TB3> INFO: scanning low vcal = 160
[12:56:12.813] <TB3> INFO: Expecting 41600 events.
[12:56:16.869] <TB3> INFO: 41600 events read in total (3465ms).
[12:56:16.870] <TB3> INFO: Test took 4334ms.
[12:56:16.873] <TB3> INFO: scanning low vcal = 170
[12:56:17.149] <TB3> INFO: Expecting 41600 events.
[12:56:21.145] <TB3> INFO: 41600 events read in total (3404ms).
[12:56:21.146] <TB3> INFO: Test took 4273ms.
[12:56:21.149] <TB3> INFO: scanning low vcal = 180
[12:56:21.433] <TB3> INFO: Expecting 41600 events.
[12:56:25.478] <TB3> INFO: 41600 events read in total (3453ms).
[12:56:25.478] <TB3> INFO: Test took 4329ms.
[12:56:25.481] <TB3> INFO: scanning low vcal = 190
[12:56:25.758] <TB3> INFO: Expecting 41600 events.
[12:56:29.725] <TB3> INFO: 41600 events read in total (3376ms).
[12:56:29.725] <TB3> INFO: Test took 4244ms.
[12:56:29.728] <TB3> INFO: scanning low vcal = 200
[12:56:30.023] <TB3> INFO: Expecting 41600 events.
[12:56:33.982] <TB3> INFO: 41600 events read in total (3367ms).
[12:56:33.983] <TB3> INFO: Test took 4255ms.
[12:56:33.985] <TB3> INFO: scanning low vcal = 210
[12:56:34.262] <TB3> INFO: Expecting 41600 events.
[12:56:38.266] <TB3> INFO: 41600 events read in total (3412ms).
[12:56:38.266] <TB3> INFO: Test took 4280ms.
[12:56:38.269] <TB3> INFO: scanning low vcal = 220
[12:56:38.546] <TB3> INFO: Expecting 41600 events.
[12:56:42.575] <TB3> INFO: 41600 events read in total (3438ms).
[12:56:42.576] <TB3> INFO: Test took 4307ms.
[12:56:42.580] <TB3> INFO: scanning low vcal = 230
[12:56:42.866] <TB3> INFO: Expecting 41600 events.
[12:56:46.906] <TB3> INFO: 41600 events read in total (3449ms).
[12:56:46.907] <TB3> INFO: Test took 4327ms.
[12:56:46.910] <TB3> INFO: scanning low vcal = 240
[12:56:47.186] <TB3> INFO: Expecting 41600 events.
[12:56:51.152] <TB3> INFO: 41600 events read in total (3374ms).
[12:56:51.153] <TB3> INFO: Test took 4243ms.
[12:56:51.156] <TB3> INFO: scanning low vcal = 250
[12:56:51.432] <TB3> INFO: Expecting 41600 events.
[12:56:55.458] <TB3> INFO: 41600 events read in total (3434ms).
[12:56:55.459] <TB3> INFO: Test took 4303ms.
[12:56:55.463] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[12:56:55.749] <TB3> INFO: Expecting 41600 events.
[12:56:59.711] <TB3> INFO: 41600 events read in total (3371ms).
[12:56:59.712] <TB3> INFO: Test took 4249ms.
[12:56:59.715] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[12:56:59.991] <TB3> INFO: Expecting 41600 events.
[12:57:04.066] <TB3> INFO: 41600 events read in total (3483ms).
[12:57:04.066] <TB3> INFO: Test took 4351ms.
[12:57:04.069] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[12:57:04.376] <TB3> INFO: Expecting 41600 events.
[12:57:08.330] <TB3> INFO: 41600 events read in total (3362ms).
[12:57:08.331] <TB3> INFO: Test took 4261ms.
[12:57:08.334] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[12:57:08.611] <TB3> INFO: Expecting 41600 events.
[12:57:12.688] <TB3> INFO: 41600 events read in total (3485ms).
[12:57:12.689] <TB3> INFO: Test took 4355ms.
[12:57:12.692] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:57:12.001] <TB3> INFO: Expecting 41600 events.
[12:57:17.016] <TB3> INFO: 41600 events read in total (3423ms).
[12:57:17.017] <TB3> INFO: Test took 4325ms.
[12:57:17.417] <TB3> INFO: PixTestGainPedestal::measure() done
[12:57:49.466] <TB3> INFO: PixTestGainPedestal::fit() done
[12:57:49.466] <TB3> INFO: non-linearity mean: 0.976 0.961 0.980 0.987 0.984 0.986 0.980 0.933 0.971 0.910 0.980 0.985 0.933 0.985 0.978 0.931
[12:57:49.466] <TB3> INFO: non-linearity RMS: 0.005 0.174 0.004 0.003 0.003 0.004 0.007 0.070 0.008 0.117 0.003 0.003 0.090 0.004 0.004 0.058
[12:57:49.466] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[12:57:49.480] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[12:57:49.494] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[12:57:49.509] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[12:57:49.523] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[12:57:49.537] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[12:57:49.551] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[12:57:49.565] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[12:57:49.579] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[12:57:49.593] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[12:57:49.607] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[12:57:49.621] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[12:57:49.635] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[12:57:49.650] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[12:57:49.664] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[12:57:49.678] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1099_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[12:57:49.692] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 160 seconds
[12:57:49.692] <TB3> INFO: Decoding statistics:
[12:57:49.692] <TB3> INFO: General information:
[12:57:49.692] <TB3> INFO: 16bit words read: 3327946
[12:57:49.692] <TB3> INFO: valid events total: 332800
[12:57:49.692] <TB3> INFO: empty events: 0
[12:57:49.692] <TB3> INFO: valid events with pixels: 332800
[12:57:49.692] <TB3> INFO: valid pixel hits: 665573
[12:57:49.692] <TB3> INFO: Event errors: 0
[12:57:49.692] <TB3> INFO: start marker: 0
[12:57:49.692] <TB3> INFO: stop marker: 0
[12:57:49.692] <TB3> INFO: overflow: 0
[12:57:49.692] <TB3> INFO: invalid 5bit words: 0
[12:57:49.692] <TB3> INFO: invalid XOR eye diagram: 0
[12:57:49.692] <TB3> INFO: frame (failed synchr.): 0
[12:57:49.692] <TB3> INFO: idle data (no TBM trl): 0
[12:57:49.692] <TB3> INFO: no data (only TBM hdr): 0
[12:57:49.692] <TB3> INFO: TBM errors: 0
[12:57:49.692] <TB3> INFO: flawed TBM headers: 0
[12:57:49.692] <TB3> INFO: flawed TBM trailers: 0
[12:57:49.692] <TB3> INFO: event ID mismatches: 0
[12:57:49.692] <TB3> INFO: ROC errors: 0
[12:57:49.692] <TB3> INFO: missing ROC header(s): 0
[12:57:49.692] <TB3> INFO: misplaced readback start: 0
[12:57:49.692] <TB3> INFO: Pixel decoding errors: 0
[12:57:49.692] <TB3> INFO: pixel data incomplete: 0
[12:57:49.692] <TB3> INFO: pixel address: 0
[12:57:49.692] <TB3> INFO: pulse height fill bit: 0
[12:57:49.692] <TB3> INFO: buffer corruption: 0
[12:57:49.707] <TB3> INFO: Decoding statistics:
[12:57:49.707] <TB3> INFO: General information:
[12:57:49.707] <TB3> INFO: 16bit words read: 3457358
[12:57:49.707] <TB3> INFO: valid events total: 353536
[12:57:49.707] <TB3> INFO: empty events: 18238
[12:57:49.707] <TB3> INFO: valid events with pixels: 335298
[12:57:49.707] <TB3> INFO: valid pixel hits: 668071
[12:57:49.707] <TB3> INFO: Event errors: 0
[12:57:49.707] <TB3> INFO: start marker: 0
[12:57:49.707] <TB3> INFO: stop marker: 0
[12:57:49.707] <TB3> INFO: overflow: 0
[12:57:49.707] <TB3> INFO: invalid 5bit words: 0
[12:57:49.707] <TB3> INFO: invalid XOR eye diagram: 0
[12:57:49.707] <TB3> INFO: frame (failed synchr.): 0
[12:57:49.707] <TB3> INFO: idle data (no TBM trl): 0
[12:57:49.707] <TB3> INFO: no data (only TBM hdr): 0
[12:57:49.707] <TB3> INFO: TBM errors: 0
[12:57:49.707] <TB3> INFO: flawed TBM headers: 0
[12:57:49.707] <TB3> INFO: flawed TBM trailers: 0
[12:57:49.707] <TB3> INFO: event ID mismatches: 0
[12:57:49.707] <TB3> INFO: ROC errors: 0
[12:57:49.707] <TB3> INFO: missing ROC header(s): 0
[12:57:49.707] <TB3> INFO: misplaced readback start: 0
[12:57:49.707] <TB3> INFO: Pixel decoding errors: 0
[12:57:49.707] <TB3> INFO: pixel data incomplete: 0
[12:57:49.707] <TB3> INFO: pixel address: 0
[12:57:49.707] <TB3> INFO: pulse height fill bit: 0
[12:57:49.707] <TB3> INFO: buffer corruption: 0
[12:57:49.707] <TB3> INFO: enter test to run
[12:57:49.707] <TB3> INFO: test: exit no parameter change
[12:57:49.745] <TB3> QUIET: Connection to board 170 closed.
[12:57:49.746] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud