Test Date: 2016-10-31 10:37
Analysis date: 2016-10-31 15:37
Logfile
LogfileView
[11:34:24.584] <TB1> INFO: *** Welcome to pxar ***
[11:34:24.584] <TB1> INFO: *** Today: 2016/10/31
[11:34:24.590] <TB1> INFO: *** Version: c8ba-dirty
[11:34:24.590] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C15.dat
[11:34:24.590] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C1b.dat
[11:34:24.590] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//defaultMaskFile.dat
[11:34:24.590] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters_C15.dat
[11:34:24.645] <TB1> INFO: clk: 4
[11:34:24.645] <TB1> INFO: ctr: 4
[11:34:24.645] <TB1> INFO: sda: 19
[11:34:24.645] <TB1> INFO: tin: 9
[11:34:24.645] <TB1> INFO: level: 15
[11:34:24.645] <TB1> INFO: triggerdelay: 0
[11:34:24.645] <TB1> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[11:34:24.645] <TB1> INFO: Log level: INFO
[11:34:24.653] <TB1> INFO: Found DTB DTB_WXBYFL
[11:34:24.663] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[11:34:24.664] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[11:34:24.666] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[11:34:26.150] <TB1> INFO: DUT info:
[11:34:26.150] <TB1> INFO: The DUT currently contains the following objects:
[11:34:26.150] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[11:34:26.150] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:34:26.150] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:34:26.150] <TB1> INFO: TBM Core alpha (2): 7 registers set
[11:34:26.150] <TB1> INFO: TBM Core beta (3): 7 registers set
[11:34:26.150] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[11:34:26.150] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.150] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:34:26.551] <TB1> INFO: enter 'restricted' command line mode
[11:34:26.551] <TB1> INFO: enter test to run
[11:34:26.551] <TB1> INFO: test: pretest no parameter change
[11:34:26.551] <TB1> INFO: running: pretest
[11:34:27.461] <TB1> INFO: ######################################################################
[11:34:27.461] <TB1> INFO: PixTestPretest::doTest()
[11:34:27.461] <TB1> INFO: ######################################################################
[11:34:27.462] <TB1> INFO: ----------------------------------------------------------------------
[11:34:27.462] <TB1> INFO: PixTestPretest::programROC()
[11:34:27.462] <TB1> INFO: ----------------------------------------------------------------------
[11:34:45.475] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:34:45.475] <TB1> INFO: IA differences per ROC: 19.3 19.3 20.1 17.7 21.7 18.5 18.5 20.1 20.1 20.1 20.1 19.3 20.9 19.3 20.1 19.3
[11:34:45.511] <TB1> INFO: ----------------------------------------------------------------------
[11:34:45.511] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:34:45.511] <TB1> INFO: ----------------------------------------------------------------------
[11:35:06.752] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 380.2 mA = 23.7625 mA/ROC
[11:35:06.752] <TB1> INFO: i(loss) [mA/ROC]: 19.3 19.3 20.1 19.3 19.3 18.4 18.4 19.3 18.4 18.4 19.3 18.4 19.3 19.3 19.3 19.3
[11:35:06.780] <TB1> INFO: ----------------------------------------------------------------------
[11:35:06.780] <TB1> INFO: PixTestPretest::findTiming()
[11:35:06.780] <TB1> INFO: ----------------------------------------------------------------------
[11:35:06.780] <TB1> INFO: PixTestCmd::init()
[11:35:07.350] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[11:35:38.149] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 6, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[11:35:38.149] <TB1> INFO: (success/tries = 100/100), width = 3
[11:35:39.660] <TB1> INFO: ----------------------------------------------------------------------
[11:35:39.660] <TB1> INFO: PixTestPretest::findWorkingPixel()
[11:35:39.660] <TB1> INFO: ----------------------------------------------------------------------
[11:35:39.751] <TB1> INFO: Expecting 231680 events.
[11:35:49.426] <TB1> INFO: 231680 events read in total (9083ms).
[11:35:49.435] <TB1> INFO: Test took 9773ms.
[11:35:49.681] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:35:49.711] <TB1> INFO: ----------------------------------------------------------------------
[11:35:49.711] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[11:35:49.711] <TB1> INFO: ----------------------------------------------------------------------
[11:35:49.803] <TB1> INFO: Expecting 231680 events.
[11:35:59.448] <TB1> INFO: 231680 events read in total (9053ms).
[11:35:59.456] <TB1> INFO: Test took 9741ms.
[11:35:59.714] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[11:35:59.714] <TB1> INFO: CalDel: 113 94 100 111 106 89 97 93 110 116 91 94 84 104 111 104
[11:35:59.714] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 52 51 51 51 51 53 54 56 51
[11:35:59.717] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C0.dat
[11:35:59.717] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C1.dat
[11:35:59.717] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C2.dat
[11:35:59.717] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C3.dat
[11:35:59.717] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C4.dat
[11:35:59.717] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C5.dat
[11:35:59.717] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C6.dat
[11:35:59.717] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C7.dat
[11:35:59.717] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C8.dat
[11:35:59.718] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C9.dat
[11:35:59.718] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C10.dat
[11:35:59.718] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C11.dat
[11:35:59.718] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C12.dat
[11:35:59.718] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C13.dat
[11:35:59.718] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C14.dat
[11:35:59.718] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters_C15.dat
[11:35:59.718] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C0a.dat
[11:35:59.718] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C0b.dat
[11:35:59.718] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C1a.dat
[11:35:59.719] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//tbmParameters_C1b.dat
[11:35:59.719] <TB1> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[11:35:59.815] <TB1> INFO: enter test to run
[11:35:59.815] <TB1> INFO: test: FullTest no parameter change
[11:35:59.815] <TB1> INFO: running: fulltest
[11:35:59.816] <TB1> INFO: ######################################################################
[11:35:59.816] <TB1> INFO: PixTestFullTest::doTest()
[11:35:59.816] <TB1> INFO: ######################################################################
[11:35:59.817] <TB1> INFO: ######################################################################
[11:35:59.817] <TB1> INFO: PixTestAlive::doTest()
[11:35:59.817] <TB1> INFO: ######################################################################
[11:35:59.818] <TB1> INFO: ----------------------------------------------------------------------
[11:35:59.818] <TB1> 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:35:59.818] <TB1> INFO: ----------------------------------------------------------------------
[11:36:00.051] <TB1> INFO: Expecting 41600 events.
[11:36:03.478] <TB1> INFO: 41600 events read in total (2836ms).
[11:36:03.479] <TB1> INFO: Test took 3659ms.
[11:36:03.706] <TB1> INFO: PixTestAlive::aliveTest() done
[11:36:03.706] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:36:03.708] <TB1> INFO: ----------------------------------------------------------------------
[11:36:03.708] <TB1> 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:03.708] <TB1> INFO: ----------------------------------------------------------------------
[11:36:03.941] <TB1> INFO: Expecting 41600 events.
[11:36:06.949] <TB1> INFO: 41600 events read in total (2416ms).
[11:36:06.949] <TB1> INFO: Test took 3240ms.
[11:36:06.949] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:36:07.189] <TB1> INFO: PixTestAlive::maskTest() done
[11:36:07.189] <TB1> 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:07.190] <TB1> INFO: ----------------------------------------------------------------------
[11:36:07.190] <TB1> 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:07.190] <TB1> INFO: ----------------------------------------------------------------------
[11:36:07.449] <TB1> INFO: Expecting 41600 events.
[11:36:10.891] <TB1> INFO: 41600 events read in total (2850ms).
[11:36:10.891] <TB1> INFO: Test took 3699ms.
[11:36:11.118] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[11:36:11.118] <TB1> 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:11.118] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[11:36:11.118] <TB1> INFO: Decoding statistics:
[11:36:11.118] <TB1> INFO: General information:
[11:36:11.118] <TB1> INFO: 16bit words read: 0
[11:36:11.118] <TB1> INFO: valid events total: 0
[11:36:11.118] <TB1> INFO: empty events: 0
[11:36:11.118] <TB1> INFO: valid events with pixels: 0
[11:36:11.118] <TB1> INFO: valid pixel hits: 0
[11:36:11.118] <TB1> INFO: Event errors: 0
[11:36:11.118] <TB1> INFO: start marker: 0
[11:36:11.118] <TB1> INFO: stop marker: 0
[11:36:11.118] <TB1> INFO: overflow: 0
[11:36:11.119] <TB1> INFO: invalid 5bit words: 0
[11:36:11.119] <TB1> INFO: invalid XOR eye diagram: 0
[11:36:11.119] <TB1> INFO: frame (failed synchr.): 0
[11:36:11.119] <TB1> INFO: idle data (no TBM trl): 0
[11:36:11.119] <TB1> INFO: no data (only TBM hdr): 0
[11:36:11.119] <TB1> INFO: TBM errors: 0
[11:36:11.119] <TB1> INFO: flawed TBM headers: 0
[11:36:11.119] <TB1> INFO: flawed TBM trailers: 0
[11:36:11.119] <TB1> INFO: event ID mismatches: 0
[11:36:11.119] <TB1> INFO: ROC errors: 0
[11:36:11.119] <TB1> INFO: missing ROC header(s): 0
[11:36:11.119] <TB1> INFO: misplaced readback start: 0
[11:36:11.119] <TB1> INFO: Pixel decoding errors: 0
[11:36:11.119] <TB1> INFO: pixel data incomplete: 0
[11:36:11.119] <TB1> INFO: pixel address: 0
[11:36:11.119] <TB1> INFO: pulse height fill bit: 0
[11:36:11.119] <TB1> INFO: buffer corruption: 0
[11:36:11.126] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C15.dat
[11:36:11.126] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[11:36:11.126] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[11:36:11.126] <TB1> INFO: ######################################################################
[11:36:11.126] <TB1> INFO: PixTestReadback::doTest()
[11:36:11.126] <TB1> INFO: ######################################################################
[11:36:11.126] <TB1> INFO: ----------------------------------------------------------------------
[11:36:11.126] <TB1> INFO: PixTestReadback::CalibrateVd()
[11:36:11.126] <TB1> INFO: ----------------------------------------------------------------------
[11:36:21.091] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C0.dat
[11:36:21.091] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C1.dat
[11:36:21.091] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C2.dat
[11:36:21.091] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C3.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C4.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C5.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C6.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C7.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C8.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C9.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C10.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C11.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C12.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C13.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C14.dat
[11:36:21.092] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C15.dat
[11:36:21.122] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[11:36:21.122] <TB1> INFO: ----------------------------------------------------------------------
[11:36:21.122] <TB1> INFO: PixTestReadback::CalibrateVa()
[11:36:21.122] <TB1> INFO: ----------------------------------------------------------------------
[11:36:31.013] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C0.dat
[11:36:31.013] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C1.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C2.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C3.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C4.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C5.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C6.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C7.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C8.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C9.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C10.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C11.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C12.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C13.dat
[11:36:31.014] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C14.dat
[11:36:31.015] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C15.dat
[11:36:31.044] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[11:36:31.044] <TB1> INFO: ----------------------------------------------------------------------
[11:36:31.044] <TB1> INFO: PixTestReadback::readbackVbg()
[11:36:31.044] <TB1> INFO: ----------------------------------------------------------------------
[11:36:38.683] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[11:36:38.683] <TB1> INFO: ----------------------------------------------------------------------
[11:36:38.684] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[11:36:38.684] <TB1> INFO: ----------------------------------------------------------------------
[11:36:38.684] <TB1> INFO: Vbg will be calibrated using Vd calibration
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 159.9calibrated Vbg = 1.14458 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 157calibrated Vbg = 1.14268 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 153.4calibrated Vbg = 1.13979 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 160.6calibrated Vbg = 1.13762 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 155.9calibrated Vbg = 1.14386 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 158.5calibrated Vbg = 1.15059 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 152calibrated Vbg = 1.14239 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 146.8calibrated Vbg = 1.14622 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 155.9calibrated Vbg = 1.14463 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 149.4calibrated Vbg = 1.1348 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 155.1calibrated Vbg = 1.13814 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 155.7calibrated Vbg = 1.12824 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 165.8calibrated Vbg = 1.1384 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 150.7calibrated Vbg = 1.13292 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 160.9calibrated Vbg = 1.14255 :::*/*/*/*/
[11:36:38.684] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 152.6calibrated Vbg = 1.13972 :::*/*/*/*/
[11:36:38.686] <TB1> INFO: ----------------------------------------------------------------------
[11:36:38.686] <TB1> INFO: PixTestReadback::CalibrateIa()
[11:36:38.686] <TB1> INFO: ----------------------------------------------------------------------
[11:39:18.986] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C0.dat
[11:39:18.986] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C1.dat
[11:39:18.986] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C2.dat
[11:39:18.986] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C3.dat
[11:39:18.986] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C4.dat
[11:39:18.986] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C5.dat
[11:39:18.986] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C6.dat
[11:39:18.987] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C7.dat
[11:39:18.987] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C8.dat
[11:39:18.987] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C9.dat
[11:39:18.987] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C10.dat
[11:39:18.987] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C11.dat
[11:39:18.987] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C12.dat
[11:39:18.987] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C13.dat
[11:39:18.987] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C14.dat
[11:39:18.987] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//readbackCal_C15.dat
[11:39:19.014] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[11:39:19.015] <TB1> INFO: PixTestReadback::doTest() done
[11:39:19.015] <TB1> INFO: Decoding statistics:
[11:39:19.015] <TB1> INFO: General information:
[11:39:19.015] <TB1> INFO: 16bit words read: 1536
[11:39:19.015] <TB1> INFO: valid events total: 256
[11:39:19.015] <TB1> INFO: empty events: 256
[11:39:19.015] <TB1> INFO: valid events with pixels: 0
[11:39:19.015] <TB1> INFO: valid pixel hits: 0
[11:39:19.015] <TB1> INFO: Event errors: 0
[11:39:19.015] <TB1> INFO: start marker: 0
[11:39:19.015] <TB1> INFO: stop marker: 0
[11:39:19.015] <TB1> INFO: overflow: 0
[11:39:19.015] <TB1> INFO: invalid 5bit words: 0
[11:39:19.015] <TB1> INFO: invalid XOR eye diagram: 0
[11:39:19.015] <TB1> INFO: frame (failed synchr.): 0
[11:39:19.015] <TB1> INFO: idle data (no TBM trl): 0
[11:39:19.015] <TB1> INFO: no data (only TBM hdr): 0
[11:39:19.015] <TB1> INFO: TBM errors: 0
[11:39:19.015] <TB1> INFO: flawed TBM headers: 0
[11:39:19.015] <TB1> INFO: flawed TBM trailers: 0
[11:39:19.015] <TB1> INFO: event ID mismatches: 0
[11:39:19.015] <TB1> INFO: ROC errors: 0
[11:39:19.015] <TB1> INFO: missing ROC header(s): 0
[11:39:19.015] <TB1> INFO: misplaced readback start: 0
[11:39:19.015] <TB1> INFO: Pixel decoding errors: 0
[11:39:19.015] <TB1> INFO: pixel data incomplete: 0
[11:39:19.015] <TB1> INFO: pixel address: 0
[11:39:19.015] <TB1> INFO: pulse height fill bit: 0
[11:39:19.015] <TB1> INFO: buffer corruption: 0
[11:39:19.049] <TB1> INFO: ######################################################################
[11:39:19.049] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:39:19.049] <TB1> INFO: ######################################################################
[11:39:19.051] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[11:39:19.061] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:39:19.061] <TB1> INFO: run 1 of 1
[11:39:19.293] <TB1> INFO: Expecting 3120000 events.
[11:39:50.586] <TB1> INFO: 668120 events read in total (30701ms).
[11:40:02.780] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (89) != TBM ID (129)

[11:40:02.922] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 89 89 129 89 89 89 89 89

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

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

[11:40:02.922] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05d 80c0 4c00 262 25c4 4c00 262 25ef e022 c000

[11:40:02.922] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a057 8040 4c00 262 25c4 4c10 262 25ef e022 c000

[11:40:02.922] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a058 80b1 4c00 262 25c6 4c00 262 25ef e022 c000

[11:40:02.922] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c01 25c8 4c11 262 25ef e022 c000

[11:40:02.922] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05a 8000 4811 262 25c4 4c11 262 25ef e022 c000

[11:40:02.922] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05b 8040 4811 262 25c4 4c11 262 25ef e022 c000

[11:40:02.922] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05c 80b1 4c01 262 25c4 4c01 262 25ef e022 c000

[11:40:20.898] <TB1> INFO: 1331065 events read in total (61014ms).
[11:40:51.566] <TB1> INFO: 1992850 events read in total (91681ms).
[11:41:03.733] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (19) != TBM ID (250)

[11:41:03.733] <TB1> ERROR: <datapipe.cc/CheckEventValidity:L523> Channel 0 Number of ROCs (1) != Token Chain Length (2)

[11:41:03.874] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (251) != TBM ID (20)

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

[11:41:03.875] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a017 8040 4c00 4c00 e022 c000

[11:41:03.875] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a011 80c0 4c11 4c11 e022 c000

[11:41:03.875] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a012 8000 4c10 4c10 e022 c000

[11:41:03.875] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fa 8000 4c11 4c2 e022 c000

[11:41:03.875] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a014 80b1 4c10 4c10 e022 c000

[11:41:03.875] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a015 80c0 4c10 4c10 e022 c000

[11:41:03.875] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a016 8000 4c10 4c10 e022 c000

[11:41:21.731] <TB1> INFO: 2654215 events read in total (121846ms).
[11:41:30.371] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (136) != TBM ID (250)

[11:41:30.513] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 136 136 250 136 136 136 136 136

[11:41:30.513] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (251) != TBM ID (137)

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

[11:41:30.513] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08c 80b1 4c11 a84 25ef 4c01 a84 25cd e022 c000

[11:41:30.513] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a086 8000 4c10 a84 25ef 4c10 a84 25cd e022 c000

[11:41:30.513] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a087 8040 4c10 a84 25ef 4c10 a84 25e5 e022 c000

[11:41:30.513] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fa 8000 4c11 4c2 25ef 4c11 a84 25e5 e022 c000

[11:41:30.513] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a089 80c0 4810 a84 25ef 4c10 a84 25e0 e022 c000

[11:41:30.513] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08a 8000 4c10 a84 25ef 4c10 e022 c000

[11:41:30.513] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08b 8040 4c10 a84 25ef 4c00 e022 c000

[11:41:42.982] <TB1> INFO: 3120000 events read in total (143097ms).
[11:41:43.045] <TB1> INFO: Test took 143984ms.
[11:42:05.824] <TB1> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 166 seconds
[11:42:05.824] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 0 1 0 1 0 0 0 0 0 0 0 0 0
[11:42:05.824] <TB1> INFO: separation cut (per ROC): 104 105 106 97 104 101 100 109 104 109 106 103 108 110 106 105
[11:42:05.824] <TB1> INFO: Decoding statistics:
[11:42:05.824] <TB1> INFO: General information:
[11:42:05.824] <TB1> INFO: 16bit words read: 0
[11:42:05.824] <TB1> INFO: valid events total: 0
[11:42:05.824] <TB1> INFO: empty events: 0
[11:42:05.824] <TB1> INFO: valid events with pixels: 0
[11:42:05.824] <TB1> INFO: valid pixel hits: 0
[11:42:05.825] <TB1> INFO: Event errors: 0
[11:42:05.825] <TB1> INFO: start marker: 0
[11:42:05.825] <TB1> INFO: stop marker: 0
[11:42:05.825] <TB1> INFO: overflow: 0
[11:42:05.825] <TB1> INFO: invalid 5bit words: 0
[11:42:05.825] <TB1> INFO: invalid XOR eye diagram: 0
[11:42:05.825] <TB1> INFO: frame (failed synchr.): 0
[11:42:05.825] <TB1> INFO: idle data (no TBM trl): 0
[11:42:05.825] <TB1> INFO: no data (only TBM hdr): 0
[11:42:05.825] <TB1> INFO: TBM errors: 0
[11:42:05.825] <TB1> INFO: flawed TBM headers: 0
[11:42:05.825] <TB1> INFO: flawed TBM trailers: 0
[11:42:05.825] <TB1> INFO: event ID mismatches: 0
[11:42:05.825] <TB1> INFO: ROC errors: 0
[11:42:05.825] <TB1> INFO: missing ROC header(s): 0
[11:42:05.825] <TB1> INFO: misplaced readback start: 0
[11:42:05.825] <TB1> INFO: Pixel decoding errors: 0
[11:42:05.825] <TB1> INFO: pixel data incomplete: 0
[11:42:05.825] <TB1> INFO: pixel address: 0
[11:42:05.825] <TB1> INFO: pulse height fill bit: 0
[11:42:05.825] <TB1> INFO: buffer corruption: 0
[11:42:05.861] <TB1> INFO: ######################################################################
[11:42:05.861] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:42:05.861] <TB1> INFO: ######################################################################
[11:42:05.861] <TB1> INFO: ----------------------------------------------------------------------
[11:42:05.861] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:42:05.861] <TB1> INFO: ----------------------------------------------------------------------
[11:42:05.861] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[11:42:05.872] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[11:42:05.872] <TB1> INFO: run 1 of 1
[11:42:06.105] <TB1> INFO: Expecting 36608000 events.
[11:42:29.879] <TB1> INFO: 683000 events read in total (23182ms).
[11:42:53.034] <TB1> INFO: 1353700 events read in total (46337ms).
[11:43:15.928] <TB1> INFO: 2023050 events read in total (69231ms).
[11:43:38.956] <TB1> INFO: 2693100 events read in total (92259ms).
[11:44:02.415] <TB1> INFO: 3360050 events read in total (115718ms).
[11:44:25.471] <TB1> INFO: 4027650 events read in total (138774ms).
[11:44:48.813] <TB1> INFO: 4696100 events read in total (162116ms).
[11:45:12.418] <TB1> INFO: 5364600 events read in total (185721ms).
[11:45:35.674] <TB1> INFO: 6032400 events read in total (208977ms).
[11:45:58.878] <TB1> INFO: 6697050 events read in total (232181ms).
[11:46:22.311] <TB1> INFO: 7363950 events read in total (255614ms).
[11:46:45.688] <TB1> INFO: 8030550 events read in total (278991ms).
[11:47:09.134] <TB1> INFO: 8696750 events read in total (302437ms).
[11:47:32.884] <TB1> INFO: 9360950 events read in total (326187ms).
[11:47:56.008] <TB1> INFO: 10026200 events read in total (349311ms).
[11:48:19.306] <TB1> INFO: 10690000 events read in total (372609ms).
[11:48:42.619] <TB1> INFO: 11354050 events read in total (395922ms).
[11:49:05.699] <TB1> INFO: 12017350 events read in total (419002ms).
[11:49:28.661] <TB1> INFO: 12679350 events read in total (441964ms).
[11:49:51.978] <TB1> INFO: 13340750 events read in total (465281ms).
[11:50:15.257] <TB1> INFO: 14003100 events read in total (488560ms).
[11:50:38.349] <TB1> INFO: 14663400 events read in total (511652ms).
[11:51:01.423] <TB1> INFO: 15325400 events read in total (534726ms).
[11:51:24.625] <TB1> INFO: 15987800 events read in total (557928ms).
[11:51:47.948] <TB1> INFO: 16650700 events read in total (581251ms).
[11:52:11.408] <TB1> INFO: 17311800 events read in total (604711ms).
[11:52:34.253] <TB1> INFO: 17972550 events read in total (627556ms).
[11:52:57.836] <TB1> INFO: 18633250 events read in total (651139ms).
[11:53:21.124] <TB1> INFO: 19292650 events read in total (674427ms).
[11:53:44.566] <TB1> INFO: 19953950 events read in total (697869ms).
[11:54:07.853] <TB1> INFO: 20612400 events read in total (721156ms).
[11:54:30.919] <TB1> INFO: 21271600 events read in total (744222ms).
[11:54:53.959] <TB1> INFO: 21929400 events read in total (767262ms).
[11:55:17.146] <TB1> INFO: 22588950 events read in total (790449ms).
[11:55:40.502] <TB1> INFO: 23247450 events read in total (813805ms).
[11:56:03.448] <TB1> INFO: 23907100 events read in total (836751ms).
[11:56:26.047] <TB1> INFO: 24563250 events read in total (859350ms).
[11:56:49.348] <TB1> INFO: 25220400 events read in total (882651ms).
[11:57:12.609] <TB1> INFO: 25879150 events read in total (905912ms).
[11:57:35.418] <TB1> INFO: 26539450 events read in total (928721ms).
[11:57:58.242] <TB1> INFO: 27198300 events read in total (951545ms).
[11:58:21.526] <TB1> INFO: 27856700 events read in total (974829ms).
[11:58:44.589] <TB1> INFO: 28514450 events read in total (997892ms).
[11:59:07.541] <TB1> INFO: 29171800 events read in total (1020844ms).
[11:59:30.493] <TB1> INFO: 29829500 events read in total (1043796ms).
[11:59:53.798] <TB1> INFO: 30487950 events read in total (1067101ms).
[12:00:17.185] <TB1> INFO: 31144800 events read in total (1090488ms).
[12:00:40.526] <TB1> INFO: 31801750 events read in total (1113829ms).
[12:01:03.524] <TB1> INFO: 32461300 events read in total (1136827ms).
[12:01:26.418] <TB1> INFO: 33119250 events read in total (1159721ms).
[12:01:50.065] <TB1> INFO: 33779750 events read in total (1183368ms).
[12:02:13.278] <TB1> INFO: 34440450 events read in total (1206581ms).
[12:02:36.339] <TB1> INFO: 35099900 events read in total (1229642ms).
[12:02:59.618] <TB1> INFO: 35758200 events read in total (1252921ms).
[12:03:22.776] <TB1> INFO: 36427750 events read in total (1276079ms).
[12:03:29.456] <TB1> INFO: 36608000 events read in total (1282759ms).
[12:03:29.530] <TB1> INFO: Test took 1283657ms.
[12:03:29.947] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:31.404] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:32.926] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:34.973] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:37.193] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:38.764] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:40.309] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:41.897] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:43.535] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:45.162] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:46.603] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:48.214] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:49.719] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:51.381] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:53.270] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:55.101] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:03:56.682] <TB1> INFO: PixTestScurves::scurves() done
[12:03:56.682] <TB1> INFO: Vcal mean: 113.28 113.89 115.75 112.69 112.06 110.18 107.97 119.07 110.69 114.62 118.43 110.08 113.08 121.15 120.84 116.47
[12:03:56.682] <TB1> INFO: Vcal RMS: 6.07 5.22 5.26 5.14 5.95 4.93 4.95 5.82 5.31 5.85 7.04 5.31 5.45 6.33 7.36 5.90
[12:03:56.682] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1310 seconds
[12:03:56.682] <TB1> INFO: Decoding statistics:
[12:03:56.682] <TB1> INFO: General information:
[12:03:56.682] <TB1> INFO: 16bit words read: 0
[12:03:56.682] <TB1> INFO: valid events total: 0
[12:03:56.682] <TB1> INFO: empty events: 0
[12:03:56.682] <TB1> INFO: valid events with pixels: 0
[12:03:56.682] <TB1> INFO: valid pixel hits: 0
[12:03:56.682] <TB1> INFO: Event errors: 0
[12:03:56.682] <TB1> INFO: start marker: 0
[12:03:56.682] <TB1> INFO: stop marker: 0
[12:03:56.682] <TB1> INFO: overflow: 0
[12:03:56.682] <TB1> INFO: invalid 5bit words: 0
[12:03:56.682] <TB1> INFO: invalid XOR eye diagram: 0
[12:03:56.682] <TB1> INFO: frame (failed synchr.): 0
[12:03:56.682] <TB1> INFO: idle data (no TBM trl): 0
[12:03:56.682] <TB1> INFO: no data (only TBM hdr): 0
[12:03:56.682] <TB1> INFO: TBM errors: 0
[12:03:56.682] <TB1> INFO: flawed TBM headers: 0
[12:03:56.682] <TB1> INFO: flawed TBM trailers: 0
[12:03:56.682] <TB1> INFO: event ID mismatches: 0
[12:03:56.682] <TB1> INFO: ROC errors: 0
[12:03:56.682] <TB1> INFO: missing ROC header(s): 0
[12:03:56.682] <TB1> INFO: misplaced readback start: 0
[12:03:56.682] <TB1> INFO: Pixel decoding errors: 0
[12:03:56.682] <TB1> INFO: pixel data incomplete: 0
[12:03:56.682] <TB1> INFO: pixel address: 0
[12:03:56.682] <TB1> INFO: pulse height fill bit: 0
[12:03:56.682] <TB1> INFO: buffer corruption: 0
[12:03:56.767] <TB1> INFO: ######################################################################
[12:03:56.767] <TB1> INFO: PixTestTrim::doTest()
[12:03:56.767] <TB1> INFO: ######################################################################
[12:03:56.768] <TB1> INFO: ----------------------------------------------------------------------
[12:03:56.768] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[12:03:56.768] <TB1> INFO: ----------------------------------------------------------------------
[12:03:56.830] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:03:56.830] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:03:56.841] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:03:56.841] <TB1> INFO: run 1 of 1
[12:03:57.103] <TB1> INFO: Expecting 5025280 events.
[12:04:28.490] <TB1> INFO: 828768 events read in total (30795ms).
[12:04:58.977] <TB1> INFO: 1653840 events read in total (61282ms).
[12:05:29.576] <TB1> INFO: 2474944 events read in total (91882ms).
[12:06:00.603] <TB1> INFO: 3294160 events read in total (122908ms).
[12:06:30.742] <TB1> INFO: 4110696 events read in total (153048ms).
[12:07:00.894] <TB1> INFO: 4925704 events read in total (183199ms).
[12:07:04.922] <TB1> INFO: 5025280 events read in total (187227ms).
[12:07:04.965] <TB1> INFO: Test took 188124ms.
[12:07:24.185] <TB1> INFO: ROC 0 VthrComp = 111
[12:07:24.185] <TB1> INFO: ROC 1 VthrComp = 114
[12:07:24.186] <TB1> INFO: ROC 2 VthrComp = 117
[12:07:24.186] <TB1> INFO: ROC 3 VthrComp = 109
[12:07:24.186] <TB1> INFO: ROC 4 VthrComp = 113
[12:07:24.186] <TB1> INFO: ROC 5 VthrComp = 109
[12:07:24.186] <TB1> INFO: ROC 6 VthrComp = 108
[12:07:24.186] <TB1> INFO: ROC 7 VthrComp = 127
[12:07:24.186] <TB1> INFO: ROC 8 VthrComp = 111
[12:07:24.186] <TB1> INFO: ROC 9 VthrComp = 116
[12:07:24.187] <TB1> INFO: ROC 10 VthrComp = 120
[12:07:24.187] <TB1> INFO: ROC 11 VthrComp = 108
[12:07:24.187] <TB1> INFO: ROC 12 VthrComp = 119
[12:07:24.187] <TB1> INFO: ROC 13 VthrComp = 128
[12:07:24.187] <TB1> INFO: ROC 14 VthrComp = 123
[12:07:24.187] <TB1> INFO: ROC 15 VthrComp = 115
[12:07:24.456] <TB1> INFO: Expecting 41600 events.
[12:07:27.883] <TB1> INFO: 41600 events read in total (2835ms).
[12:07:27.883] <TB1> INFO: Test took 3694ms.
[12:07:27.893] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:07:27.893] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:07:27.901] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:07:27.901] <TB1> INFO: run 1 of 1
[12:07:28.179] <TB1> INFO: Expecting 5025280 events.
[12:07:54.711] <TB1> INFO: 590880 events read in total (25940ms).
[12:08:20.548] <TB1> INFO: 1179440 events read in total (51777ms).
[12:08:46.338] <TB1> INFO: 1768328 events read in total (77567ms).
[12:09:12.195] <TB1> INFO: 2356576 events read in total (103424ms).
[12:09:37.890] <TB1> INFO: 2942608 events read in total (129119ms).
[12:10:03.663] <TB1> INFO: 3528256 events read in total (154892ms).
[12:10:29.529] <TB1> INFO: 4113800 events read in total (180758ms).
[12:10:55.186] <TB1> INFO: 4699272 events read in total (206415ms).
[12:11:09.801] <TB1> INFO: 5025280 events read in total (221030ms).
[12:11:09.857] <TB1> INFO: Test took 221956ms.
[12:11:37.094] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 63.1708 for pixel 51/79 mean/min/max = 48.3611/33.512/63.2103
[12:11:37.095] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 61.3216 for pixel 0/13 mean/min/max = 46.6297/31.8034/61.4561
[12:11:37.095] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 60.053 for pixel 0/9 mean/min/max = 45.905/31.6456/60.1644
[12:11:37.095] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 65.7471 for pixel 45/22 mean/min/max = 50.0045/34.2526/65.7565
[12:11:37.096] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 60.5 for pixel 4/78 mean/min/max = 46.1054/31.6474/60.5634
[12:11:37.096] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 63.1691 for pixel 47/15 mean/min/max = 48.9438/34.6579/63.2296
[12:11:37.096] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 62.3607 for pixel 16/7 mean/min/max = 48.4228/34.2891/62.5565
[12:11:37.097] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 59.3145 for pixel 33/67 mean/min/max = 44.9994/30.5286/59.4702
[12:11:37.097] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 61.4466 for pixel 3/44 mean/min/max = 48.0269/34.4761/61.5777
[12:11:37.097] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 61.4495 for pixel 21/2 mean/min/max = 46.5553/31.4646/61.646
[12:11:37.098] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 61.4824 for pixel 1/79 mean/min/max = 46.4132/31.245/61.5813
[12:11:37.098] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 65.0202 for pixel 35/2 mean/min/max = 49.5642/34.064/65.0644
[12:11:37.098] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 59.117 for pixel 48/72 mean/min/max = 45.1442/31.1338/59.1545
[12:11:37.098] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 59.9117 for pixel 1/42 mean/min/max = 45.5938/31.1536/60.0339
[12:11:37.099] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 62.3745 for pixel 0/7 mean/min/max = 46.7346/30.7827/62.6864
[12:11:37.099] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 60.9305 for pixel 13/30 mean/min/max = 46.4674/31.8842/61.0506
[12:11:37.099] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:11:37.188] <TB1> INFO: Expecting 411648 events.
[12:11:46.661] <TB1> INFO: 411648 events read in total (8882ms).
[12:11:46.668] <TB1> INFO: Expecting 411648 events.
[12:11:56.031] <TB1> INFO: 411648 events read in total (8960ms).
[12:11:56.040] <TB1> INFO: Expecting 411648 events.
[12:12:05.338] <TB1> INFO: 411648 events read in total (8895ms).
[12:12:05.353] <TB1> INFO: Expecting 411648 events.
[12:12:14.697] <TB1> INFO: 411648 events read in total (8941ms).
[12:12:14.711] <TB1> INFO: Expecting 411648 events.
[12:12:23.001] <TB1> INFO: 411648 events read in total (8887ms).
[12:12:24.023] <TB1> INFO: Expecting 411648 events.
[12:12:33.377] <TB1> INFO: 411648 events read in total (8951ms).
[12:12:33.404] <TB1> INFO: Expecting 411648 events.
[12:12:42.732] <TB1> INFO: 411648 events read in total (8925ms).
[12:12:42.753] <TB1> INFO: Expecting 411648 events.
[12:12:52.205] <TB1> INFO: 411648 events read in total (9049ms).
[12:12:52.229] <TB1> INFO: Expecting 411648 events.
[12:13:01.539] <TB1> INFO: 411648 events read in total (8907ms).
[12:13:01.564] <TB1> INFO: Expecting 411648 events.
[12:13:10.837] <TB1> INFO: 411648 events read in total (8870ms).
[12:13:10.865] <TB1> INFO: Expecting 411648 events.
[12:13:20.114] <TB1> INFO: 411648 events read in total (8846ms).
[12:13:20.158] <TB1> INFO: Expecting 411648 events.
[12:13:29.430] <TB1> INFO: 411648 events read in total (8869ms).
[12:13:29.463] <TB1> INFO: Expecting 411648 events.
[12:13:38.753] <TB1> INFO: 411648 events read in total (8887ms).
[12:13:38.788] <TB1> INFO: Expecting 411648 events.
[12:13:48.108] <TB1> INFO: 411648 events read in total (8917ms).
[12:13:48.146] <TB1> INFO: Expecting 411648 events.
[12:13:57.432] <TB1> INFO: 411648 events read in total (8883ms).
[12:13:57.473] <TB1> INFO: Expecting 411648 events.
[12:14:06.744] <TB1> INFO: 411648 events read in total (8868ms).
[12:14:06.786] <TB1> INFO: Test took 149687ms.
[12:14:07.574] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[12:14:07.585] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:14:07.585] <TB1> INFO: run 1 of 1
[12:14:07.816] <TB1> INFO: Expecting 5025280 events.
[12:14:34.964] <TB1> INFO: 591312 events read in total (26557ms).
[12:15:01.504] <TB1> INFO: 1184552 events read in total (53097ms).
[12:15:27.836] <TB1> INFO: 1775776 events read in total (79429ms).
[12:15:54.041] <TB1> INFO: 2367152 events read in total (105634ms).
[12:16:20.433] <TB1> INFO: 2960160 events read in total (132026ms).
[12:16:47.276] <TB1> INFO: 3553384 events read in total (158869ms).
[12:17:13.399] <TB1> INFO: 4143920 events read in total (184992ms).
[12:17:39.822] <TB1> INFO: 4735360 events read in total (211415ms).
[12:17:53.047] <TB1> INFO: 5025280 events read in total (224640ms).
[12:17:53.146] <TB1> INFO: Test took 225561ms.
[12:18:15.037] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 2.500000 .. 147.558149
[12:18:15.271] <TB1> INFO: Expecting 208000 events.
[12:18:24.880] <TB1> INFO: 208000 events read in total (9018ms).
[12:18:24.881] <TB1> INFO: Test took 9842ms.
[12:18:24.927] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 2 .. 157 (-1/-1) hits flags = 528 (plus default)
[12:18:24.937] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:18:24.937] <TB1> INFO: run 1 of 1
[12:18:25.215] <TB1> INFO: Expecting 5191680 events.
[12:18:52.056] <TB1> INFO: 582960 events read in total (26250ms).
[12:19:17.098] <TB1> INFO: 1165632 events read in total (51293ms).
[12:19:43.425] <TB1> INFO: 1748136 events read in total (77619ms).
[12:20:09.096] <TB1> INFO: 2330920 events read in total (103290ms).
[12:20:34.215] <TB1> INFO: 2912816 events read in total (128409ms).
[12:20:59.855] <TB1> INFO: 3494832 events read in total (154049ms).
[12:21:26.008] <TB1> INFO: 4076608 events read in total (180202ms).
[12:21:52.053] <TB1> INFO: 4658192 events read in total (206247ms).
[12:22:15.998] <TB1> INFO: 5191680 events read in total (230192ms).
[12:22:16.068] <TB1> INFO: Test took 231131ms.
[12:22:39.748] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 26.326387 .. 46.350286
[12:22:40.045] <TB1> INFO: Expecting 208000 events.
[12:22:50.275] <TB1> INFO: 208000 events read in total (9638ms).
[12:22:50.276] <TB1> INFO: Test took 10526ms.
[12:22:50.322] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 56 (-1/-1) hits flags = 528 (plus default)
[12:22:50.332] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:22:50.332] <TB1> INFO: run 1 of 1
[12:22:50.610] <TB1> INFO: Expecting 1364480 events.
[12:23:19.321] <TB1> INFO: 660184 events read in total (28120ms).
[12:23:47.601] <TB1> INFO: 1317520 events read in total (56400ms).
[12:23:50.017] <TB1> INFO: 1364480 events read in total (58816ms).
[12:23:50.042] <TB1> INFO: Test took 59711ms.
[12:24:03.781] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 27.839330 .. 48.227578
[12:24:04.073] <TB1> INFO: Expecting 208000 events.
[12:24:13.839] <TB1> INFO: 208000 events read in total (9174ms).
[12:24:13.839] <TB1> INFO: Test took 10057ms.
[12:24:13.886] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 17 .. 58 (-1/-1) hits flags = 528 (plus default)
[12:24:13.895] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:24:13.895] <TB1> INFO: run 1 of 1
[12:24:14.173] <TB1> INFO: Expecting 1397760 events.
[12:24:42.252] <TB1> INFO: 648592 events read in total (27488ms).
[12:25:09.761] <TB1> INFO: 1295616 events read in total (54997ms).
[12:25:14.466] <TB1> INFO: 1397760 events read in total (59702ms).
[12:25:14.498] <TB1> INFO: Test took 60603ms.
[12:25:26.172] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 25.451453 .. 49.803544
[12:25:26.405] <TB1> INFO: Expecting 208000 events.
[12:25:36.099] <TB1> INFO: 208000 events read in total (9102ms).
[12:25:36.100] <TB1> INFO: Test took 9927ms.
[12:25:36.148] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 15 .. 59 (-1/-1) hits flags = 528 (plus default)
[12:25:36.161] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:25:36.161] <TB1> INFO: run 1 of 1
[12:25:36.439] <TB1> INFO: Expecting 1497600 events.
[12:26:04.230] <TB1> INFO: 652240 events read in total (27200ms).
[12:26:32.362] <TB1> INFO: 1304272 events read in total (55332ms).
[12:26:40.789] <TB1> INFO: 1497600 events read in total (63759ms).
[12:26:40.824] <TB1> INFO: Test took 64664ms.
[12:26:52.306] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:26:52.306] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[12:26:52.316] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:26:52.316] <TB1> INFO: run 1 of 1
[12:26:52.548] <TB1> INFO: Expecting 1364480 events.
[12:27:21.828] <TB1> INFO: 667696 events read in total (28688ms).
[12:27:49.977] <TB1> INFO: 1334600 events read in total (56837ms).
[12:27:51.726] <TB1> INFO: 1364480 events read in total (58587ms).
[12:27:51.748] <TB1> INFO: Test took 59432ms.
[12:28:02.827] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C0.dat
[12:28:02.827] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C1.dat
[12:28:02.827] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C2.dat
[12:28:02.827] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C3.dat
[12:28:02.827] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C4.dat
[12:28:02.827] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C5.dat
[12:28:02.827] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C6.dat
[12:28:02.828] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C7.dat
[12:28:02.828] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C8.dat
[12:28:02.828] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C9.dat
[12:28:02.828] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C10.dat
[12:28:02.828] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C11.dat
[12:28:02.828] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C12.dat
[12:28:02.828] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C13.dat
[12:28:02.828] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C14.dat
[12:28:02.828] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C15.dat
[12:28:02.828] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C0.dat
[12:28:02.837] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C1.dat
[12:28:02.844] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C2.dat
[12:28:02.851] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C3.dat
[12:28:02.859] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C4.dat
[12:28:02.867] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C5.dat
[12:28:02.875] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C6.dat
[12:28:02.883] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C7.dat
[12:28:02.892] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C8.dat
[12:28:02.900] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C9.dat
[12:28:02.908] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C10.dat
[12:28:02.916] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C11.dat
[12:28:02.924] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C12.dat
[12:28:02.932] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C13.dat
[12:28:02.940] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C14.dat
[12:28:02.946] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//trimParameters35_C15.dat
[12:28:02.952] <TB1> INFO: PixTestTrim::trimTest() done
[12:28:02.952] <TB1> INFO: vtrim: 127 156 126 149 130 131 140 143 116 146 126 151 128 122 122 136
[12:28:02.952] <TB1> INFO: vthrcomp: 111 114 117 109 113 109 108 127 111 116 120 108 119 128 123 115
[12:28:02.952] <TB1> INFO: vcal mean: 35.04 34.98 34.95 35.47 34.98 35.08 35.00 34.97 34.99 35.02 34.95 35.18 34.92 34.96 35.06 34.97
[12:28:02.952] <TB1> INFO: vcal RMS: 1.10 1.19 1.16 1.62 1.07 1.22 1.11 1.14 1.01 1.28 1.13 1.35 1.09 1.21 1.31 1.11
[12:28:02.952] <TB1> INFO: bits mean: 8.98 10.21 9.82 9.51 9.83 9.02 9.23 10.02 9.06 10.12 9.24 9.38 10.04 9.64 9.57 9.75
[12:28:02.952] <TB1> INFO: bits RMS: 2.54 2.39 2.58 2.34 2.56 2.44 2.37 2.73 2.42 2.46 2.87 2.34 2.59 2.76 2.75 2.56
[12:28:02.958] <TB1> INFO: ----------------------------------------------------------------------
[12:28:02.958] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[12:28:02.958] <TB1> INFO: ----------------------------------------------------------------------
[12:28:02.961] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[12:28:02.970] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:28:02.970] <TB1> INFO: run 1 of 1
[12:28:03.232] <TB1> INFO: Expecting 4160000 events.
[12:28:36.150] <TB1> INFO: 755465 events read in total (32326ms).
[12:29:08.032] <TB1> INFO: 1501975 events read in total (64208ms).
[12:29:39.837] <TB1> INFO: 2244300 events read in total (96013ms).
[12:30:11.824] <TB1> INFO: 2982585 events read in total (128000ms).
[12:30:43.533] <TB1> INFO: 3719925 events read in total (159709ms).
[12:31:02.626] <TB1> INFO: 4160000 events read in total (178802ms).
[12:31:02.685] <TB1> INFO: Test took 179715ms.
[12:31:26.270] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 201 (-1/-1) hits flags = 528 (plus default)
[12:31:26.279] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:31:26.279] <TB1> INFO: run 1 of 1
[12:31:26.576] <TB1> INFO: Expecting 4201600 events.
[12:31:59.125] <TB1> INFO: 728060 events read in total (31957ms).
[12:32:30.428] <TB1> INFO: 1448330 events read in total (63260ms).
[12:33:01.761] <TB1> INFO: 2164350 events read in total (94593ms).
[12:33:33.372] <TB1> INFO: 2876670 events read in total (126204ms).
[12:34:04.984] <TB1> INFO: 3588320 events read in total (157817ms).
[12:34:31.916] <TB1> INFO: 4201600 events read in total (184748ms).
[12:34:31.968] <TB1> INFO: Test took 185689ms.
[12:34:58.335] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 201 (-1/-1) hits flags = 528 (plus default)
[12:34:58.344] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:34:58.344] <TB1> INFO: run 1 of 1
[12:34:58.576] <TB1> INFO: Expecting 4201600 events.
[12:35:31.054] <TB1> INFO: 728060 events read in total (31887ms).
[12:36:02.501] <TB1> INFO: 1448375 events read in total (63334ms).
[12:36:34.045] <TB1> INFO: 2164330 events read in total (94878ms).
[12:37:05.521] <TB1> INFO: 2876455 events read in total (126354ms).
[12:37:36.775] <TB1> INFO: 3588245 events read in total (157608ms).
[12:38:03.845] <TB1> INFO: 4201600 events read in total (184678ms).
[12:38:03.902] <TB1> INFO: Test took 185557ms.
[12:38:29.196] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 202 (-1/-1) hits flags = 528 (plus default)
[12:38:29.206] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:38:29.206] <TB1> INFO: run 1 of 1
[12:38:29.437] <TB1> INFO: Expecting 4222400 events.
[12:39:01.390] <TB1> INFO: 726820 events read in total (31362ms).
[12:39:33.145] <TB1> INFO: 1446110 events read in total (63117ms).
[12:40:04.808] <TB1> INFO: 2160860 events read in total (94780ms).
[12:40:36.600] <TB1> INFO: 2872155 events read in total (126572ms).
[12:41:08.017] <TB1> INFO: 3582720 events read in total (157989ms).
[12:41:36.302] <TB1> INFO: 4222400 events read in total (186274ms).
[12:41:36.356] <TB1> INFO: Test took 187150ms.
[12:42:01.026] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 200 (-1/-1) hits flags = 528 (plus default)
[12:42:01.036] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:42:01.036] <TB1> INFO: run 1 of 1
[12:42:01.268] <TB1> INFO: Expecting 4180800 events.
[12:42:33.583] <TB1> INFO: 729590 events read in total (31724ms).
[12:43:05.082] <TB1> INFO: 1451505 events read in total (63223ms).
[12:43:36.889] <TB1> INFO: 2168620 events read in total (95031ms).
[12:44:08.261] <TB1> INFO: 2881995 events read in total (126402ms).
[12:44:39.629] <TB1> INFO: 3594775 events read in total (157770ms).
[12:45:05.764] <TB1> INFO: 4180800 events read in total (183905ms).
[12:45:05.817] <TB1> INFO: Test took 184780ms.
[12:45:33.702] <TB1> INFO: PixTestTrim::trimBitTest() done
[12:45:33.703] <TB1> INFO: PixTestTrim::doTest() done, duration: 2496 seconds
[12:45:33.703] <TB1> INFO: Decoding statistics:
[12:45:33.704] <TB1> INFO: General information:
[12:45:33.704] <TB1> INFO: 16bit words read: 0
[12:45:33.704] <TB1> INFO: valid events total: 0
[12:45:33.704] <TB1> INFO: empty events: 0
[12:45:33.704] <TB1> INFO: valid events with pixels: 0
[12:45:33.704] <TB1> INFO: valid pixel hits: 0
[12:45:33.704] <TB1> INFO: Event errors: 0
[12:45:33.704] <TB1> INFO: start marker: 0
[12:45:33.704] <TB1> INFO: stop marker: 0
[12:45:33.704] <TB1> INFO: overflow: 0
[12:45:33.704] <TB1> INFO: invalid 5bit words: 0
[12:45:33.704] <TB1> INFO: invalid XOR eye diagram: 0
[12:45:33.704] <TB1> INFO: frame (failed synchr.): 0
[12:45:33.704] <TB1> INFO: idle data (no TBM trl): 0
[12:45:33.704] <TB1> INFO: no data (only TBM hdr): 0
[12:45:33.704] <TB1> INFO: TBM errors: 0
[12:45:33.704] <TB1> INFO: flawed TBM headers: 0
[12:45:33.704] <TB1> INFO: flawed TBM trailers: 0
[12:45:33.704] <TB1> INFO: event ID mismatches: 0
[12:45:33.704] <TB1> INFO: ROC errors: 0
[12:45:33.704] <TB1> INFO: missing ROC header(s): 0
[12:45:33.704] <TB1> INFO: misplaced readback start: 0
[12:45:33.704] <TB1> INFO: Pixel decoding errors: 0
[12:45:33.704] <TB1> INFO: pixel data incomplete: 0
[12:45:33.704] <TB1> INFO: pixel address: 0
[12:45:33.704] <TB1> INFO: pulse height fill bit: 0
[12:45:33.704] <TB1> INFO: buffer corruption: 0
[12:45:34.319] <TB1> INFO: ######################################################################
[12:45:34.319] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:45:34.319] <TB1> INFO: ######################################################################
[12:45:34.552] <TB1> INFO: Expecting 41600 events.
[12:45:38.099] <TB1> INFO: 41600 events read in total (2955ms).
[12:45:38.100] <TB1> INFO: Test took 3779ms.
[12:45:38.538] <TB1> INFO: Expecting 41600 events.
[12:45:42.223] <TB1> INFO: 41600 events read in total (3094ms).
[12:45:42.224] <TB1> INFO: Test took 3918ms.
[12:45:42.542] <TB1> INFO: Expecting 41600 events.
[12:45:46.117] <TB1> INFO: 41600 events read in total (2983ms).
[12:45:46.117] <TB1> INFO: Test took 3870ms.
[12:45:46.409] <TB1> INFO: Expecting 41600 events.
[12:45:49.000] <TB1> INFO: 41600 events read in total (2999ms).
[12:45:49.001] <TB1> INFO: Test took 3857ms.
[12:45:50.289] <TB1> INFO: Expecting 41600 events.
[12:45:53.922] <TB1> INFO: 41600 events read in total (3041ms).
[12:45:53.923] <TB1> INFO: Test took 3898ms.
[12:45:54.211] <TB1> INFO: Expecting 41600 events.
[12:45:57.832] <TB1> INFO: 41600 events read in total (3029ms).
[12:45:57.833] <TB1> INFO: Test took 3887ms.
[12:45:58.154] <TB1> INFO: Expecting 41600 events.
[12:46:01.788] <TB1> INFO: 41600 events read in total (3043ms).
[12:46:01.789] <TB1> INFO: Test took 3930ms.
[12:46:02.077] <TB1> INFO: Expecting 41600 events.
[12:46:05.816] <TB1> INFO: 41600 events read in total (3147ms).
[12:46:05.817] <TB1> INFO: Test took 4004ms.
[12:46:06.105] <TB1> INFO: Expecting 41600 events.
[12:46:09.577] <TB1> INFO: 41600 events read in total (2881ms).
[12:46:09.578] <TB1> INFO: Test took 3738ms.
[12:46:09.866] <TB1> INFO: Expecting 41600 events.
[12:46:13.648] <TB1> INFO: 41600 events read in total (3191ms).
[12:46:13.649] <TB1> INFO: Test took 4048ms.
[12:46:13.936] <TB1> INFO: Expecting 41600 events.
[12:46:17.630] <TB1> INFO: 41600 events read in total (3102ms).
[12:46:17.631] <TB1> INFO: Test took 3959ms.
[12:46:17.919] <TB1> INFO: Expecting 41600 events.
[12:46:21.544] <TB1> INFO: 41600 events read in total (3033ms).
[12:46:21.545] <TB1> INFO: Test took 3890ms.
[12:46:21.832] <TB1> INFO: Expecting 41600 events.
[12:46:25.561] <TB1> INFO: 41600 events read in total (3137ms).
[12:46:25.562] <TB1> INFO: Test took 3994ms.
[12:46:25.850] <TB1> INFO: Expecting 41600 events.
[12:46:29.405] <TB1> INFO: 41600 events read in total (2964ms).
[12:46:29.406] <TB1> INFO: Test took 3821ms.
[12:46:29.693] <TB1> INFO: Expecting 41600 events.
[12:46:33.163] <TB1> INFO: 41600 events read in total (2878ms).
[12:46:33.163] <TB1> INFO: Test took 3734ms.
[12:46:33.451] <TB1> INFO: Expecting 41600 events.
[12:46:37.077] <TB1> INFO: 41600 events read in total (3034ms).
[12:46:37.078] <TB1> INFO: Test took 3891ms.
[12:46:37.371] <TB1> INFO: Expecting 41600 events.
[12:46:40.837] <TB1> INFO: 41600 events read in total (2874ms).
[12:46:40.837] <TB1> INFO: Test took 3732ms.
[12:46:41.125] <TB1> INFO: Expecting 41600 events.
[12:46:44.663] <TB1> INFO: 41600 events read in total (2946ms).
[12:46:44.664] <TB1> INFO: Test took 3803ms.
[12:46:44.952] <TB1> INFO: Expecting 41600 events.
[12:46:48.555] <TB1> INFO: 41600 events read in total (3011ms).
[12:46:48.555] <TB1> INFO: Test took 3868ms.
[12:46:48.843] <TB1> INFO: Expecting 41600 events.
[12:46:52.420] <TB1> INFO: 41600 events read in total (2985ms).
[12:46:52.420] <TB1> INFO: Test took 3841ms.
[12:46:52.708] <TB1> INFO: Expecting 41600 events.
[12:46:56.209] <TB1> INFO: 41600 events read in total (2909ms).
[12:46:56.210] <TB1> INFO: Test took 3766ms.
[12:46:56.501] <TB1> INFO: Expecting 41600 events.
[12:47:00.248] <TB1> INFO: 41600 events read in total (3156ms).
[12:47:00.249] <TB1> INFO: Test took 4013ms.
[12:47:00.541] <TB1> INFO: Expecting 41600 events.
[12:47:04.187] <TB1> INFO: 41600 events read in total (3054ms).
[12:47:04.188] <TB1> INFO: Test took 3912ms.
[12:47:04.479] <TB1> INFO: Expecting 41600 events.
[12:47:08.060] <TB1> INFO: 41600 events read in total (2989ms).
[12:47:08.061] <TB1> INFO: Test took 3846ms.
[12:47:08.349] <TB1> INFO: Expecting 41600 events.
[12:47:12.060] <TB1> INFO: 41600 events read in total (3120ms).
[12:47:12.061] <TB1> INFO: Test took 3977ms.
[12:47:12.352] <TB1> INFO: Expecting 41600 events.
[12:47:16.170] <TB1> INFO: 41600 events read in total (3227ms).
[12:47:16.170] <TB1> INFO: Test took 4083ms.
[12:47:16.459] <TB1> INFO: Expecting 41600 events.
[12:47:20.165] <TB1> INFO: 41600 events read in total (3115ms).
[12:47:20.166] <TB1> INFO: Test took 3972ms.
[12:47:20.481] <TB1> INFO: Expecting 41600 events.
[12:47:23.962] <TB1> INFO: 41600 events read in total (2889ms).
[12:47:23.962] <TB1> INFO: Test took 3773ms.
[12:47:24.251] <TB1> INFO: Expecting 41600 events.
[12:47:27.976] <TB1> INFO: 41600 events read in total (3134ms).
[12:47:27.977] <TB1> INFO: Test took 3991ms.
[12:47:28.268] <TB1> INFO: Expecting 41600 events.
[12:47:31.796] <TB1> INFO: 41600 events read in total (2936ms).
[12:47:31.797] <TB1> INFO: Test took 3793ms.
[12:47:32.085] <TB1> INFO: Expecting 41600 events.
[12:47:35.806] <TB1> INFO: 41600 events read in total (3129ms).
[12:47:35.806] <TB1> INFO: Test took 3986ms.
[12:47:36.094] <TB1> INFO: Expecting 41600 events.
[12:47:39.701] <TB1> INFO: 41600 events read in total (3015ms).
[12:47:39.702] <TB1> INFO: Test took 3872ms.
[12:47:39.990] <TB1> INFO: Expecting 41600 events.
[12:47:43.610] <TB1> INFO: 41600 events read in total (3029ms).
[12:47:43.611] <TB1> INFO: Test took 3886ms.
[12:47:43.914] <TB1> INFO: Expecting 41600 events.
[12:47:47.394] <TB1> INFO: 41600 events read in total (2889ms).
[12:47:47.394] <TB1> INFO: Test took 3756ms.
[12:47:47.706] <TB1> INFO: Expecting 41600 events.
[12:47:51.182] <TB1> INFO: 41600 events read in total (2884ms).
[12:47:51.183] <TB1> INFO: Test took 3765ms.
[12:47:51.502] <TB1> INFO: Expecting 41600 events.
[12:47:55.308] <TB1> INFO: 41600 events read in total (3214ms).
[12:47:55.308] <TB1> INFO: Test took 4102ms.
[12:47:55.621] <TB1> INFO: Expecting 41600 events.
[12:47:59.303] <TB1> INFO: 41600 events read in total (3090ms).
[12:47:59.304] <TB1> INFO: Test took 3972ms.
[12:47:59.619] <TB1> INFO: Expecting 41600 events.
[12:48:03.310] <TB1> INFO: 41600 events read in total (3099ms).
[12:48:03.311] <TB1> INFO: Test took 3984ms.
[12:48:03.601] <TB1> INFO: Expecting 41600 events.
[12:48:07.309] <TB1> INFO: 41600 events read in total (3117ms).
[12:48:07.310] <TB1> INFO: Test took 3974ms.
[12:48:07.602] <TB1> INFO: Expecting 41600 events.
[12:48:11.112] <TB1> INFO: 41600 events read in total (2919ms).
[12:48:11.113] <TB1> INFO: Test took 3776ms.
[12:48:11.401] <TB1> INFO: Expecting 41600 events.
[12:48:14.977] <TB1> INFO: 41600 events read in total (2985ms).
[12:48:14.978] <TB1> INFO: Test took 3842ms.
[12:48:15.270] <TB1> INFO: Expecting 41600 events.
[12:48:18.959] <TB1> INFO: 41600 events read in total (3098ms).
[12:48:18.960] <TB1> INFO: Test took 3955ms.
[12:48:19.248] <TB1> INFO: Expecting 41600 events.
[12:48:22.873] <TB1> INFO: 41600 events read in total (3033ms).
[12:48:22.874] <TB1> INFO: Test took 3891ms.
[12:48:23.162] <TB1> INFO: Expecting 41600 events.
[12:48:26.698] <TB1> INFO: 41600 events read in total (2944ms).
[12:48:26.698] <TB1> INFO: Test took 3800ms.
[12:48:27.019] <TB1> INFO: Expecting 41600 events.
[12:48:30.633] <TB1> INFO: 41600 events read in total (3022ms).
[12:48:30.634] <TB1> INFO: Test took 3908ms.
[12:48:30.926] <TB1> INFO: Expecting 41600 events.
[12:48:34.519] <TB1> INFO: 41600 events read in total (3002ms).
[12:48:34.520] <TB1> INFO: Test took 3859ms.
[12:48:34.808] <TB1> INFO: Expecting 41600 events.
[12:48:38.474] <TB1> INFO: 41600 events read in total (3075ms).
[12:48:38.475] <TB1> INFO: Test took 3932ms.
[12:48:38.782] <TB1> INFO: Expecting 41600 events.
[12:48:42.381] <TB1> INFO: 41600 events read in total (3008ms).
[12:48:42.382] <TB1> INFO: Test took 3883ms.
[12:48:42.675] <TB1> INFO: Expecting 41600 events.
[12:48:46.310] <TB1> INFO: 41600 events read in total (3043ms).
[12:48:46.311] <TB1> INFO: Test took 3901ms.
[12:48:46.652] <TB1> INFO: Expecting 41600 events.
[12:48:50.168] <TB1> INFO: 41600 events read in total (2924ms).
[12:48:50.168] <TB1> INFO: Test took 3834ms.
[12:48:50.456] <TB1> INFO: Expecting 41600 events.
[12:48:54.008] <TB1> INFO: 41600 events read in total (2960ms).
[12:48:54.009] <TB1> INFO: Test took 3817ms.
[12:48:54.298] <TB1> INFO: Expecting 41600 events.
[12:48:57.872] <TB1> INFO: 41600 events read in total (2982ms).
[12:48:57.873] <TB1> INFO: Test took 3840ms.
[12:48:58.165] <TB1> INFO: Expecting 41600 events.
[12:49:01.677] <TB1> INFO: 41600 events read in total (2920ms).
[12:49:01.678] <TB1> INFO: Test took 3777ms.
[12:49:01.968] <TB1> INFO: Expecting 41600 events.
[12:49:05.558] <TB1> INFO: 41600 events read in total (2998ms).
[12:49:05.559] <TB1> INFO: Test took 3855ms.
[12:49:05.847] <TB1> INFO: Expecting 2560 events.
[12:49:06.732] <TB1> INFO: 2560 events read in total (293ms).
[12:49:06.732] <TB1> INFO: Test took 1161ms.
[12:49:07.040] <TB1> INFO: Expecting 2560 events.
[12:49:07.923] <TB1> INFO: 2560 events read in total (292ms).
[12:49:07.924] <TB1> INFO: Test took 1192ms.
[12:49:08.231] <TB1> INFO: Expecting 2560 events.
[12:49:09.115] <TB1> INFO: 2560 events read in total (292ms).
[12:49:09.116] <TB1> INFO: Test took 1192ms.
[12:49:09.423] <TB1> INFO: Expecting 2560 events.
[12:49:10.311] <TB1> INFO: 2560 events read in total (296ms).
[12:49:10.311] <TB1> INFO: Test took 1195ms.
[12:49:10.619] <TB1> INFO: Expecting 2560 events.
[12:49:11.499] <TB1> INFO: 2560 events read in total (288ms).
[12:49:11.499] <TB1> INFO: Test took 1187ms.
[12:49:11.807] <TB1> INFO: Expecting 2560 events.
[12:49:12.685] <TB1> INFO: 2560 events read in total (287ms).
[12:49:12.686] <TB1> INFO: Test took 1186ms.
[12:49:12.994] <TB1> INFO: Expecting 2560 events.
[12:49:13.873] <TB1> INFO: 2560 events read in total (288ms).
[12:49:13.873] <TB1> INFO: Test took 1187ms.
[12:49:14.181] <TB1> INFO: Expecting 2560 events.
[12:49:15.065] <TB1> INFO: 2560 events read in total (292ms).
[12:49:15.065] <TB1> INFO: Test took 1191ms.
[12:49:15.373] <TB1> INFO: Expecting 2560 events.
[12:49:16.252] <TB1> INFO: 2560 events read in total (287ms).
[12:49:16.252] <TB1> INFO: Test took 1187ms.
[12:49:16.560] <TB1> INFO: Expecting 2560 events.
[12:49:17.444] <TB1> INFO: 2560 events read in total (292ms).
[12:49:17.444] <TB1> INFO: Test took 1191ms.
[12:49:17.752] <TB1> INFO: Expecting 2560 events.
[12:49:18.631] <TB1> INFO: 2560 events read in total (288ms).
[12:49:18.632] <TB1> INFO: Test took 1187ms.
[12:49:18.939] <TB1> INFO: Expecting 2560 events.
[12:49:19.818] <TB1> INFO: 2560 events read in total (287ms).
[12:49:19.819] <TB1> INFO: Test took 1187ms.
[12:49:20.127] <TB1> INFO: Expecting 2560 events.
[12:49:21.009] <TB1> INFO: 2560 events read in total (291ms).
[12:49:21.010] <TB1> INFO: Test took 1191ms.
[12:49:21.318] <TB1> INFO: Expecting 2560 events.
[12:49:22.199] <TB1> INFO: 2560 events read in total (290ms).
[12:49:22.199] <TB1> INFO: Test took 1189ms.
[12:49:22.506] <TB1> INFO: Expecting 2560 events.
[12:49:23.392] <TB1> INFO: 2560 events read in total (294ms).
[12:49:23.392] <TB1> INFO: Test took 1193ms.
[12:49:23.700] <TB1> INFO: Expecting 2560 events.
[12:49:24.586] <TB1> INFO: 2560 events read in total (295ms).
[12:49:24.586] <TB1> INFO: Test took 1193ms.
[12:49:24.894] <TB1> INFO: Expecting 655360 events.
[12:49:46.103] <TB1> INFO: 531260 events read in total (20617ms).
[12:49:51.085] <TB1> INFO: 655360 events read in total (25599ms).
[12:49:51.099] <TB1> INFO: Test took 26511ms.
[12:49:51.121] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:49:51.386] <TB1> INFO: Expecting 655360 events.
[12:50:06.049] <TB1> INFO: 655360 events read in total (14072ms).
[12:50:06.064] <TB1> INFO: Expecting 655360 events.
[12:50:20.387] <TB1> INFO: 655360 events read in total (13920ms).
[12:50:20.408] <TB1> INFO: Expecting 655360 events.
[12:50:34.762] <TB1> INFO: 655360 events read in total (13951ms).
[12:50:34.780] <TB1> INFO: Expecting 655360 events.
[12:50:49.283] <TB1> INFO: 655360 events read in total (14100ms).
[12:50:49.316] <TB1> INFO: Expecting 655360 events.
[12:51:03.591] <TB1> INFO: 655360 events read in total (13873ms).
[12:51:03.618] <TB1> INFO: Expecting 655360 events.
[12:51:18.104] <TB1> INFO: 655360 events read in total (14083ms).
[12:51:18.137] <TB1> INFO: Expecting 655360 events.
[12:51:32.599] <TB1> INFO: 655360 events read in total (14059ms).
[12:51:32.633] <TB1> INFO: Expecting 655360 events.
[12:51:47.264] <TB1> INFO: 655360 events read in total (14229ms).
[12:51:47.322] <TB1> INFO: Expecting 655360 events.
[12:52:01.760] <TB1> INFO: 655360 events read in total (14035ms).
[12:52:01.819] <TB1> INFO: Expecting 655360 events.
[12:52:16.336] <TB1> INFO: 655360 events read in total (14114ms).
[12:52:16.384] <TB1> INFO: Expecting 655360 events.
[12:52:30.934] <TB1> INFO: 655360 events read in total (14147ms).
[12:52:31.012] <TB1> INFO: Expecting 655360 events.
[12:52:45.529] <TB1> INFO: 655360 events read in total (14114ms).
[12:52:45.614] <TB1> INFO: Expecting 655360 events.
[12:52:59.696] <TB1> INFO: 655360 events read in total (13679ms).
[12:52:59.756] <TB1> INFO: Expecting 655360 events.
[12:53:14.187] <TB1> INFO: 655360 events read in total (14028ms).
[12:53:14.252] <TB1> INFO: Expecting 655360 events.
[12:53:28.797] <TB1> INFO: 655360 events read in total (14142ms).
[12:53:28.905] <TB1> INFO: Expecting 655360 events.
[12:53:43.243] <TB1> INFO: 655360 events read in total (13935ms).
[12:53:43.316] <TB1> INFO: Test took 232195ms.
[12:53:43.470] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.475] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:53:43.479] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.484] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:53:43.488] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:53:43.493] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.497] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.502] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.506] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.511] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:53:43.515] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.520] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.524] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.529] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.533] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:53:43.537] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:53:43.542] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:53:43.547] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[12:53:43.551] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[12:53:43.555] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[12:53:43.560] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[12:53:43.564] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[12:53:43.569] <TB1> INFO: safety margin for low PH: adding 9, margin is now 29
[12:53:43.573] <TB1> INFO: safety margin for low PH: adding 10, margin is now 30
[12:53:43.578] <TB1> INFO: safety margin for low PH: adding 11, margin is now 31
[12:53:43.582] <TB1> INFO: safety margin for low PH: adding 12, margin is now 32
[12:53:43.587] <TB1> INFO: safety margin for low PH: adding 13, margin is now 33
[12:53:43.591] <TB1> INFO: safety margin for low PH: adding 14, margin is now 34
[12:53:43.596] <TB1> INFO: safety margin for low PH: adding 15, margin is now 35
[12:53:43.601] <TB1> INFO: safety margin for low PH: adding 16, margin is now 36
[12:53:43.605] <TB1> INFO: safety margin for low PH: adding 17, margin is now 37
[12:53:43.610] <TB1> INFO: safety margin for low PH: adding 18, margin is now 38
[12:53:43.614] <TB1> INFO: safety margin for low PH: adding 19, margin is now 39
[12:53:43.619] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.623] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.628] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.632] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:53:43.636] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:53:43.641] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:53:43.645] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[12:53:43.650] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[12:53:43.654] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.659] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.663] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:53:43.697] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C0.dat
[12:53:43.697] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C1.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C2.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C3.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C4.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C5.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C6.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C7.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C8.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C9.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C10.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C11.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C12.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C13.dat
[12:53:43.698] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C14.dat
[12:53:43.699] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//dacParameters35_C15.dat
[12:53:43.991] <TB1> INFO: Expecting 41600 events.
[12:53:47.173] <TB1> INFO: 41600 events read in total (2591ms).
[12:53:47.174] <TB1> INFO: Test took 3473ms.
[12:53:47.616] <TB1> INFO: Expecting 41600 events.
[12:53:50.651] <TB1> INFO: 41600 events read in total (2443ms).
[12:53:50.652] <TB1> INFO: Test took 3268ms.
[12:53:51.158] <TB1> INFO: Expecting 41600 events.
[12:53:54.340] <TB1> INFO: 41600 events read in total (2591ms).
[12:53:54.341] <TB1> INFO: Test took 3478ms.
[12:53:54.561] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:54.649] <TB1> INFO: Expecting 2560 events.
[12:53:55.538] <TB1> INFO: 2560 events read in total (297ms).
[12:53:55.538] <TB1> INFO: Test took 977ms.
[12:53:55.540] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:55.846] <TB1> INFO: Expecting 2560 events.
[12:53:56.734] <TB1> INFO: 2560 events read in total (296ms).
[12:53:56.734] <TB1> INFO: Test took 1194ms.
[12:53:56.736] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:57.042] <TB1> INFO: Expecting 2560 events.
[12:53:57.926] <TB1> INFO: 2560 events read in total (293ms).
[12:53:57.926] <TB1> INFO: Test took 1190ms.
[12:53:57.928] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:58.234] <TB1> INFO: Expecting 2560 events.
[12:53:59.117] <TB1> INFO: 2560 events read in total (292ms).
[12:53:59.117] <TB1> INFO: Test took 1189ms.
[12:53:59.119] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:53:59.426] <TB1> INFO: Expecting 2560 events.
[12:54:00.313] <TB1> INFO: 2560 events read in total (296ms).
[12:54:00.313] <TB1> INFO: Test took 1194ms.
[12:54:00.315] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:00.622] <TB1> INFO: Expecting 2560 events.
[12:54:01.508] <TB1> INFO: 2560 events read in total (295ms).
[12:54:01.509] <TB1> INFO: Test took 1194ms.
[12:54:01.511] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:01.817] <TB1> INFO: Expecting 2560 events.
[12:54:02.702] <TB1> INFO: 2560 events read in total (293ms).
[12:54:02.702] <TB1> INFO: Test took 1192ms.
[12:54:02.705] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:03.010] <TB1> INFO: Expecting 2560 events.
[12:54:03.894] <TB1> INFO: 2560 events read in total (292ms).
[12:54:03.895] <TB1> INFO: Test took 1190ms.
[12:54:03.896] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:04.203] <TB1> INFO: Expecting 2560 events.
[12:54:05.082] <TB1> INFO: 2560 events read in total (288ms).
[12:54:05.082] <TB1> INFO: Test took 1186ms.
[12:54:05.084] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:05.390] <TB1> INFO: Expecting 2560 events.
[12:54:06.268] <TB1> INFO: 2560 events read in total (286ms).
[12:54:06.269] <TB1> INFO: Test took 1185ms.
[12:54:06.271] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:06.577] <TB1> INFO: Expecting 2560 events.
[12:54:07.461] <TB1> INFO: 2560 events read in total (292ms).
[12:54:07.461] <TB1> INFO: Test took 1191ms.
[12:54:07.463] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:07.769] <TB1> INFO: Expecting 2560 events.
[12:54:08.653] <TB1> INFO: 2560 events read in total (292ms).
[12:54:08.654] <TB1> INFO: Test took 1191ms.
[12:54:08.656] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:08.962] <TB1> INFO: Expecting 2560 events.
[12:54:09.846] <TB1> INFO: 2560 events read in total (292ms).
[12:54:09.846] <TB1> INFO: Test took 1191ms.
[12:54:09.848] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:10.154] <TB1> INFO: Expecting 2560 events.
[12:54:11.034] <TB1> INFO: 2560 events read in total (288ms).
[12:54:11.034] <TB1> INFO: Test took 1186ms.
[12:54:11.036] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:11.343] <TB1> INFO: Expecting 2560 events.
[12:54:12.226] <TB1> INFO: 2560 events read in total (292ms).
[12:54:12.226] <TB1> INFO: Test took 1190ms.
[12:54:12.227] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:12.534] <TB1> INFO: Expecting 2560 events.
[12:54:13.414] <TB1> INFO: 2560 events read in total (288ms).
[12:54:13.414] <TB1> INFO: Test took 1187ms.
[12:54:13.416] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:13.722] <TB1> INFO: Expecting 2560 events.
[12:54:14.602] <TB1> INFO: 2560 events read in total (288ms).
[12:54:14.602] <TB1> INFO: Test took 1186ms.
[12:54:14.604] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:14.910] <TB1> INFO: Expecting 2560 events.
[12:54:15.794] <TB1> INFO: 2560 events read in total (292ms).
[12:54:15.794] <TB1> INFO: Test took 1191ms.
[12:54:15.796] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:16.102] <TB1> INFO: Expecting 2560 events.
[12:54:16.981] <TB1> INFO: 2560 events read in total (287ms).
[12:54:16.981] <TB1> INFO: Test took 1185ms.
[12:54:16.984] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:17.289] <TB1> INFO: Expecting 2560 events.
[12:54:18.169] <TB1> INFO: 2560 events read in total (288ms).
[12:54:18.169] <TB1> INFO: Test took 1186ms.
[12:54:18.171] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:18.478] <TB1> INFO: Expecting 2560 events.
[12:54:19.360] <TB1> INFO: 2560 events read in total (291ms).
[12:54:19.361] <TB1> INFO: Test took 1190ms.
[12:54:19.363] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:19.669] <TB1> INFO: Expecting 2560 events.
[12:54:20.549] <TB1> INFO: 2560 events read in total (288ms).
[12:54:20.550] <TB1> INFO: Test took 1187ms.
[12:54:20.552] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:20.858] <TB1> INFO: Expecting 2560 events.
[12:54:21.738] <TB1> INFO: 2560 events read in total (289ms).
[12:54:21.738] <TB1> INFO: Test took 1187ms.
[12:54:21.740] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:22.046] <TB1> INFO: Expecting 2560 events.
[12:54:22.926] <TB1> INFO: 2560 events read in total (288ms).
[12:54:22.926] <TB1> INFO: Test took 1186ms.
[12:54:22.928] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:23.235] <TB1> INFO: Expecting 2560 events.
[12:54:24.123] <TB1> INFO: 2560 events read in total (297ms).
[12:54:24.123] <TB1> INFO: Test took 1195ms.
[12:54:24.125] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:24.431] <TB1> INFO: Expecting 2560 events.
[12:54:25.314] <TB1> INFO: 2560 events read in total (291ms).
[12:54:25.314] <TB1> INFO: Test took 1189ms.
[12:54:25.317] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:25.623] <TB1> INFO: Expecting 2560 events.
[12:54:26.507] <TB1> INFO: 2560 events read in total (293ms).
[12:54:26.507] <TB1> INFO: Test took 1191ms.
[12:54:26.509] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:26.815] <TB1> INFO: Expecting 2560 events.
[12:54:27.703] <TB1> INFO: 2560 events read in total (296ms).
[12:54:27.704] <TB1> INFO: Test took 1195ms.
[12:54:27.706] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:28.012] <TB1> INFO: Expecting 2560 events.
[12:54:28.900] <TB1> INFO: 2560 events read in total (296ms).
[12:54:28.900] <TB1> INFO: Test took 1195ms.
[12:54:28.902] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:29.208] <TB1> INFO: Expecting 2560 events.
[12:54:30.092] <TB1> INFO: 2560 events read in total (292ms).
[12:54:30.092] <TB1> INFO: Test took 1190ms.
[12:54:30.093] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:30.400] <TB1> INFO: Expecting 2560 events.
[12:54:31.284] <TB1> INFO: 2560 events read in total (292ms).
[12:54:31.284] <TB1> INFO: Test took 1191ms.
[12:54:31.287] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:54:31.593] <TB1> INFO: Expecting 2560 events.
[12:54:32.477] <TB1> INFO: 2560 events read in total (292ms).
[12:54:32.477] <TB1> INFO: Test took 1191ms.
[12:54:32.939] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 538 seconds
[12:54:32.939] <TB1> INFO: PH scale (per ROC): 36 44 49 47 20 60 52 44 44 33 53 48 46 55 37 35
[12:54:32.939] <TB1> INFO: PH offset (per ROC): 99 84 135 134 118 129 139 131 128 112 127 132 142 134 96 106
[12:54:32.946] <TB1> INFO: Decoding statistics:
[12:54:32.946] <TB1> INFO: General information:
[12:54:32.946] <TB1> INFO: 16bit words read: 127886
[12:54:32.946] <TB1> INFO: valid events total: 20480
[12:54:32.946] <TB1> INFO: empty events: 17977
[12:54:32.946] <TB1> INFO: valid events with pixels: 2503
[12:54:32.946] <TB1> INFO: valid pixel hits: 2503
[12:54:32.946] <TB1> INFO: Event errors: 0
[12:54:32.946] <TB1> INFO: start marker: 0
[12:54:32.946] <TB1> INFO: stop marker: 0
[12:54:32.946] <TB1> INFO: overflow: 0
[12:54:32.946] <TB1> INFO: invalid 5bit words: 0
[12:54:32.946] <TB1> INFO: invalid XOR eye diagram: 0
[12:54:32.946] <TB1> INFO: frame (failed synchr.): 0
[12:54:32.946] <TB1> INFO: idle data (no TBM trl): 0
[12:54:32.946] <TB1> INFO: no data (only TBM hdr): 0
[12:54:32.946] <TB1> INFO: TBM errors: 0
[12:54:32.946] <TB1> INFO: flawed TBM headers: 0
[12:54:32.946] <TB1> INFO: flawed TBM trailers: 0
[12:54:32.946] <TB1> INFO: event ID mismatches: 0
[12:54:32.946] <TB1> INFO: ROC errors: 0
[12:54:32.946] <TB1> INFO: missing ROC header(s): 0
[12:54:32.946] <TB1> INFO: misplaced readback start: 0
[12:54:32.946] <TB1> INFO: Pixel decoding errors: 0
[12:54:32.946] <TB1> INFO: pixel data incomplete: 0
[12:54:32.946] <TB1> INFO: pixel address: 0
[12:54:32.946] <TB1> INFO: pulse height fill bit: 0
[12:54:32.946] <TB1> INFO: buffer corruption: 0
[12:54:33.323] <TB1> INFO: ######################################################################
[12:54:33.323] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:54:33.323] <TB1> INFO: ######################################################################
[12:54:33.334] <TB1> INFO: scanning low vcal = 10
[12:54:33.565] <TB1> INFO: Expecting 41600 events.
[12:54:37.188] <TB1> INFO: 41600 events read in total (3031ms).
[12:54:37.188] <TB1> INFO: Test took 3854ms.
[12:54:37.190] <TB1> INFO: scanning low vcal = 20
[12:54:37.489] <TB1> INFO: Expecting 41600 events.
[12:54:41.125] <TB1> INFO: 41600 events read in total (3044ms).
[12:54:41.126] <TB1> INFO: Test took 3936ms.
[12:54:41.127] <TB1> INFO: scanning low vcal = 30
[12:54:41.423] <TB1> INFO: Expecting 41600 events.
[12:54:45.117] <TB1> INFO: 41600 events read in total (3102ms).
[12:54:45.118] <TB1> INFO: Test took 3991ms.
[12:54:45.121] <TB1> INFO: scanning low vcal = 40
[12:54:45.398] <TB1> INFO: Expecting 41600 events.
[12:54:49.313] <TB1> INFO: 41600 events read in total (3324ms).
[12:54:49.314] <TB1> INFO: Test took 4193ms.
[12:54:49.317] <TB1> INFO: scanning low vcal = 50
[12:54:49.593] <TB1> INFO: Expecting 41600 events.
[12:54:53.644] <TB1> INFO: 41600 events read in total (3459ms).
[12:54:53.644] <TB1> INFO: Test took 4327ms.
[12:54:53.647] <TB1> INFO: scanning low vcal = 60
[12:54:53.923] <TB1> INFO: Expecting 41600 events.
[12:54:57.877] <TB1> INFO: 41600 events read in total (3362ms).
[12:54:57.878] <TB1> INFO: Test took 4231ms.
[12:54:57.881] <TB1> INFO: scanning low vcal = 70
[12:54:58.157] <TB1> INFO: Expecting 41600 events.
[12:55:02.154] <TB1> INFO: 41600 events read in total (3405ms).
[12:55:02.155] <TB1> INFO: Test took 4274ms.
[12:55:02.157] <TB1> INFO: scanning low vcal = 80
[12:55:02.450] <TB1> INFO: Expecting 41600 events.
[12:55:06.405] <TB1> INFO: 41600 events read in total (3363ms).
[12:55:06.406] <TB1> INFO: Test took 4249ms.
[12:55:06.408] <TB1> INFO: scanning low vcal = 90
[12:55:06.702] <TB1> INFO: Expecting 41600 events.
[12:55:10.678] <TB1> INFO: 41600 events read in total (3385ms).
[12:55:10.679] <TB1> INFO: Test took 4271ms.
[12:55:10.681] <TB1> INFO: scanning low vcal = 100
[12:55:10.958] <TB1> INFO: Expecting 41600 events.
[12:55:14.984] <TB1> INFO: 41600 events read in total (3435ms).
[12:55:14.984] <TB1> INFO: Test took 4302ms.
[12:55:14.987] <TB1> INFO: scanning low vcal = 110
[12:55:15.277] <TB1> INFO: Expecting 41600 events.
[12:55:19.224] <TB1> INFO: 41600 events read in total (3355ms).
[12:55:19.224] <TB1> INFO: Test took 4237ms.
[12:55:19.228] <TB1> INFO: scanning low vcal = 120
[12:55:19.520] <TB1> INFO: Expecting 41600 events.
[12:55:23.553] <TB1> INFO: 41600 events read in total (3441ms).
[12:55:23.553] <TB1> INFO: Test took 4325ms.
[12:55:23.556] <TB1> INFO: scanning low vcal = 130
[12:55:23.833] <TB1> INFO: Expecting 41600 events.
[12:55:27.812] <TB1> INFO: 41600 events read in total (3388ms).
[12:55:27.813] <TB1> INFO: Test took 4257ms.
[12:55:27.816] <TB1> INFO: scanning low vcal = 140
[12:55:28.092] <TB1> INFO: Expecting 41600 events.
[12:55:32.069] <TB1> INFO: 41600 events read in total (3385ms).
[12:55:32.070] <TB1> INFO: Test took 4254ms.
[12:55:32.072] <TB1> INFO: scanning low vcal = 150
[12:55:32.349] <TB1> INFO: Expecting 41600 events.
[12:55:36.346] <TB1> INFO: 41600 events read in total (3405ms).
[12:55:36.347] <TB1> INFO: Test took 4274ms.
[12:55:36.350] <TB1> INFO: scanning low vcal = 160
[12:55:36.647] <TB1> INFO: Expecting 41600 events.
[12:55:40.622] <TB1> INFO: 41600 events read in total (3384ms).
[12:55:40.623] <TB1> INFO: Test took 4273ms.
[12:55:40.626] <TB1> INFO: scanning low vcal = 170
[12:55:40.917] <TB1> INFO: Expecting 41600 events.
[12:55:44.924] <TB1> INFO: 41600 events read in total (3415ms).
[12:55:44.925] <TB1> INFO: Test took 4299ms.
[12:55:44.927] <TB1> INFO: scanning low vcal = 180
[12:55:45.204] <TB1> INFO: Expecting 41600 events.
[12:55:49.179] <TB1> INFO: 41600 events read in total (3383ms).
[12:55:49.180] <TB1> INFO: Test took 4253ms.
[12:55:49.183] <TB1> INFO: scanning low vcal = 190
[12:55:49.460] <TB1> INFO: Expecting 41600 events.
[12:55:53.509] <TB1> INFO: 41600 events read in total (3458ms).
[12:55:53.510] <TB1> INFO: Test took 4327ms.
[12:55:53.513] <TB1> INFO: scanning low vcal = 200
[12:55:53.790] <TB1> INFO: Expecting 41600 events.
[12:55:57.769] <TB1> INFO: 41600 events read in total (3388ms).
[12:55:57.769] <TB1> INFO: Test took 4256ms.
[12:55:57.772] <TB1> INFO: scanning low vcal = 210
[12:55:58.061] <TB1> INFO: Expecting 41600 events.
[12:56:02.110] <TB1> INFO: 41600 events read in total (3457ms).
[12:56:02.110] <TB1> INFO: Test took 4338ms.
[12:56:02.113] <TB1> INFO: scanning low vcal = 220
[12:56:02.405] <TB1> INFO: Expecting 41600 events.
[12:56:06.361] <TB1> INFO: 41600 events read in total (3365ms).
[12:56:06.362] <TB1> INFO: Test took 4249ms.
[12:56:06.364] <TB1> INFO: scanning low vcal = 230
[12:56:06.652] <TB1> INFO: Expecting 41600 events.
[12:56:10.630] <TB1> INFO: 41600 events read in total (3387ms).
[12:56:10.631] <TB1> INFO: Test took 4267ms.
[12:56:10.634] <TB1> INFO: scanning low vcal = 240
[12:56:10.910] <TB1> INFO: Expecting 41600 events.
[12:56:14.886] <TB1> INFO: 41600 events read in total (3384ms).
[12:56:14.886] <TB1> INFO: Test took 4252ms.
[12:56:14.889] <TB1> INFO: scanning low vcal = 250
[12:56:15.165] <TB1> INFO: Expecting 41600 events.
[12:56:19.136] <TB1> INFO: 41600 events read in total (3379ms).
[12:56:19.137] <TB1> INFO: Test took 4248ms.
[12:56:19.140] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[12:56:19.416] <TB1> INFO: Expecting 41600 events.
[12:56:23.413] <TB1> INFO: 41600 events read in total (3405ms).
[12:56:23.414] <TB1> INFO: Test took 4273ms.
[12:56:23.417] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[12:56:23.694] <TB1> INFO: Expecting 41600 events.
[12:56:27.691] <TB1> INFO: 41600 events read in total (3406ms).
[12:56:27.692] <TB1> INFO: Test took 4275ms.
[12:56:27.694] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[12:56:27.971] <TB1> INFO: Expecting 41600 events.
[12:56:32.024] <TB1> INFO: 41600 events read in total (3461ms).
[12:56:32.025] <TB1> INFO: Test took 4330ms.
[12:56:32.028] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[12:56:32.320] <TB1> INFO: Expecting 41600 events.
[12:56:36.293] <TB1> INFO: 41600 events read in total (3382ms).
[12:56:36.294] <TB1> INFO: Test took 4265ms.
[12:56:36.297] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:56:36.573] <TB1> INFO: Expecting 41600 events.
[12:56:40.578] <TB1> INFO: 41600 events read in total (3413ms).
[12:56:40.579] <TB1> INFO: Test took 4282ms.
[12:56:41.084] <TB1> INFO: PixTestGainPedestal::measure() done
[12:57:18.302] <TB1> INFO: PixTestGainPedestal::fit() done
[12:57:18.302] <TB1> INFO: non-linearity mean: 1.044 0.968 0.971 0.975 1.030 0.983 0.979 0.962 0.976 0.926 0.981 0.976 0.969 0.980 0.925 0.942
[12:57:18.302] <TB1> INFO: non-linearity RMS: 0.164 0.215 0.004 0.005 0.187 0.002 0.004 0.008 0.003 0.072 0.003 0.004 0.006 0.006 0.144 0.159
[12:57:18.302] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[12:57:18.325] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[12:57:18.348] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[12:57:18.371] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[12:57:18.394] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[12:57:18.417] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[12:57:18.440] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[12:57:18.463] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[12:57:18.486] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[12:57:18.509] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[12:57:18.532] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[12:57:18.555] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[12:57:18.578] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[12:57:18.601] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[12:57:18.624] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[12:57:18.647] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1091_FullQualification_2016-10-31_10h37m_1477906653//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[12:57:18.670] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 165 seconds
[12:57:18.670] <TB1> INFO: Decoding statistics:
[12:57:18.670] <TB1> INFO: General information:
[12:57:18.670] <TB1> INFO: 16bit words read: 3327792
[12:57:18.670] <TB1> INFO: valid events total: 332800
[12:57:18.670] <TB1> INFO: empty events: 0
[12:57:18.670] <TB1> INFO: valid events with pixels: 332800
[12:57:18.670] <TB1> INFO: valid pixel hits: 665496
[12:57:18.670] <TB1> INFO: Event errors: 0
[12:57:18.670] <TB1> INFO: start marker: 0
[12:57:18.670] <TB1> INFO: stop marker: 0
[12:57:18.670] <TB1> INFO: overflow: 0
[12:57:18.670] <TB1> INFO: invalid 5bit words: 0
[12:57:18.670] <TB1> INFO: invalid XOR eye diagram: 0
[12:57:18.670] <TB1> INFO: frame (failed synchr.): 0
[12:57:18.670] <TB1> INFO: idle data (no TBM trl): 0
[12:57:18.670] <TB1> INFO: no data (only TBM hdr): 0
[12:57:18.670] <TB1> INFO: TBM errors: 0
[12:57:18.670] <TB1> INFO: flawed TBM headers: 0
[12:57:18.670] <TB1> INFO: flawed TBM trailers: 0
[12:57:18.670] <TB1> INFO: event ID mismatches: 0
[12:57:18.670] <TB1> INFO: ROC errors: 0
[12:57:18.670] <TB1> INFO: missing ROC header(s): 0
[12:57:18.670] <TB1> INFO: misplaced readback start: 0
[12:57:18.670] <TB1> INFO: Pixel decoding errors: 0
[12:57:18.670] <TB1> INFO: pixel data incomplete: 0
[12:57:18.670] <TB1> INFO: pixel address: 0
[12:57:18.670] <TB1> INFO: pulse height fill bit: 0
[12:57:18.670] <TB1> INFO: buffer corruption: 0
[12:57:18.694] <TB1> INFO: Decoding statistics:
[12:57:18.694] <TB1> INFO: General information:
[12:57:18.694] <TB1> INFO: 16bit words read: 3457214
[12:57:18.694] <TB1> INFO: valid events total: 353536
[12:57:18.694] <TB1> INFO: empty events: 18233
[12:57:18.694] <TB1> INFO: valid events with pixels: 335303
[12:57:18.694] <TB1> INFO: valid pixel hits: 667999
[12:57:18.694] <TB1> INFO: Event errors: 0
[12:57:18.694] <TB1> INFO: start marker: 0
[12:57:18.694] <TB1> INFO: stop marker: 0
[12:57:18.694] <TB1> INFO: overflow: 0
[12:57:18.694] <TB1> INFO: invalid 5bit words: 0
[12:57:18.694] <TB1> INFO: invalid XOR eye diagram: 0
[12:57:18.694] <TB1> INFO: frame (failed synchr.): 0
[12:57:18.694] <TB1> INFO: idle data (no TBM trl): 0
[12:57:18.694] <TB1> INFO: no data (only TBM hdr): 0
[12:57:18.694] <TB1> INFO: TBM errors: 0
[12:57:18.695] <TB1> INFO: flawed TBM headers: 0
[12:57:18.695] <TB1> INFO: flawed TBM trailers: 0
[12:57:18.695] <TB1> INFO: event ID mismatches: 0
[12:57:18.695] <TB1> INFO: ROC errors: 0
[12:57:18.695] <TB1> INFO: missing ROC header(s): 0
[12:57:18.695] <TB1> INFO: misplaced readback start: 0
[12:57:18.695] <TB1> INFO: Pixel decoding errors: 0
[12:57:18.695] <TB1> INFO: pixel data incomplete: 0
[12:57:18.695] <TB1> INFO: pixel address: 0
[12:57:18.695] <TB1> INFO: pulse height fill bit: 0
[12:57:18.695] <TB1> INFO: buffer corruption: 0
[12:57:18.695] <TB1> INFO: enter test to run
[12:57:18.695] <TB1> INFO: test: exit no parameter change
[12:57:18.780] <TB1> QUIET: Connection to board 153 closed.
[12:57:18.781] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud