Test Date: 2016-10-25 08:01
Analysis date: 2016-10-25 10:18
Logfile
LogfileView
[18:01:44.511] <TB3> INFO: *** Welcome to pxar ***
[18:01:44.511] <TB3> INFO: *** Today: 2016/10/24
[18:01:44.517] <TB3> INFO: *** Version: c8ba-dirty
[18:01:44.517] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C15.dat
[18:01:44.518] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//tbmParameters_C1b.dat
[18:01:44.518] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//defaultMaskFile.dat
[18:01:44.518] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters_C15.dat
[18:01:44.585] <TB3> INFO: clk: 4
[18:01:44.585] <TB3> INFO: ctr: 4
[18:01:44.585] <TB3> INFO: sda: 19
[18:01:44.585] <TB3> INFO: tin: 9
[18:01:44.585] <TB3> INFO: level: 15
[18:01:44.585] <TB3> INFO: triggerdelay: 0
[18:01:44.585] <TB3> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[18:01:44.585] <TB3> INFO: Log level: INFO
[18:01:44.593] <TB3> INFO: Found DTB DTB_WWVASW
[18:01:44.601] <TB3> QUIET: Connection to board DTB_WWVASW opened.
[18:01:44.603] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 126
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWVASW
MAC address: 40D85511807E
Hostname: pixelDTB126
Comment:
------------------------------------------------------
[18:01:44.605] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[18:01:46.102] <TB3> INFO: DUT info:
[18:01:46.103] <TB3> INFO: The DUT currently contains the following objects:
[18:01:46.103] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[18:01:46.103] <TB3> INFO: TBM Core alpha (0): 7 registers set
[18:01:46.103] <TB3> INFO: TBM Core beta (1): 7 registers set
[18:01:46.103] <TB3> INFO: TBM Core alpha (2): 7 registers set
[18:01:46.103] <TB3> INFO: TBM Core beta (3): 7 registers set
[18:01:46.103] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[18:01:46.103] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.103] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:01:46.504] <TB3> INFO: enter 'restricted' command line mode
[18:01:46.504] <TB3> INFO: enter test to run
[18:01:46.504] <TB3> INFO: test: pretest no parameter change
[18:01:46.504] <TB3> INFO: running: pretest
[18:01:46.511] <TB3> INFO: ######################################################################
[18:01:46.511] <TB3> INFO: PixTestPretest::doTest()
[18:01:46.511] <TB3> INFO: ######################################################################
[18:01:46.513] <TB3> INFO: ----------------------------------------------------------------------
[18:01:46.513] <TB3> INFO: PixTestPretest::programROC()
[18:01:46.513] <TB3> INFO: ----------------------------------------------------------------------
[18:02:04.528] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[18:02:04.528] <TB3> INFO: IA differences per ROC: 21.7 19.3 18.5 20.9 18.5 21.7 19.3 19.3 20.1 24.2 20.1 21.7 21.7 20.1 18.5 21.7
[18:02:04.594] <TB3> INFO: ----------------------------------------------------------------------
[18:02:04.594] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[18:02:04.594] <TB3> INFO: ----------------------------------------------------------------------
[18:02:12.403] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 374.6 mA = 23.4125 mA/ROC
[18:02:12.403] <TB3> INFO: i(loss) [mA/ROC]: 18.5 18.5 18.5 17.7 18.5 18.5 18.5 18.5 17.7 17.7 17.7 18.5 17.7 18.5 17.7 18.5
[18:02:12.440] <TB3> INFO: ----------------------------------------------------------------------
[18:02:12.440] <TB3> INFO: PixTestPretest::findTiming()
[18:02:12.440] <TB3> INFO: ----------------------------------------------------------------------
[18:02:12.440] <TB3> INFO: PixTestCmd::init()
[18:02:13.020] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!

[18:02:44.626] <TB3> INFO: TBM phases: 160MHz: 7, 400MHz: 6, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[18:02:44.627] <TB3> INFO: (success/tries = 100/100), width = 3
[18:02:46.144] <TB3> INFO: ----------------------------------------------------------------------
[18:02:46.144] <TB3> INFO: PixTestPretest::findWorkingPixel()
[18:02:46.144] <TB3> INFO: ----------------------------------------------------------------------
[18:02:46.236] <TB3> INFO: Expecting 231680 events.
[18:02:56.246] <TB3> INFO: 231680 events read in total (9411ms).
[18:02:56.256] <TB3> INFO: Test took 10109ms.
[18:02:56.507] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[18:02:56.538] <TB3> INFO: ----------------------------------------------------------------------
[18:02:56.538] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[18:02:56.538] <TB3> INFO: ----------------------------------------------------------------------
[18:02:56.632] <TB3> INFO: Expecting 231680 events.
[18:03:06.678] <TB3> INFO: 231680 events read in total (9454ms).
[18:03:06.686] <TB3> INFO: Test took 10143ms.
[18:03:06.943] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[18:03:06.943] <TB3> INFO: CalDel: 98 85 116 114 107 96 107 102 103 112 84 96 102 101 109 110
[18:03:06.943] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 52 51
[18:03:06.951] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C0.dat
[18:03:06.951] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C1.dat
[18:03:06.951] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C2.dat
[18:03:06.951] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C3.dat
[18:03:06.951] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C4.dat
[18:03:06.952] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C5.dat
[18:03:06.952] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C6.dat
[18:03:06.952] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C7.dat
[18:03:06.952] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C8.dat
[18:03:06.952] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C9.dat
[18:03:06.952] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C10.dat
[18:03:06.952] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C11.dat
[18:03:06.952] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C12.dat
[18:03:06.953] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C13.dat
[18:03:06.953] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C14.dat
[18:03:06.953] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters_C15.dat
[18:03:06.953] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//tbmParameters_C0a.dat
[18:03:06.953] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//tbmParameters_C0b.dat
[18:03:06.953] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//tbmParameters_C1a.dat
[18:03:06.953] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//tbmParameters_C1b.dat
[18:03:06.953] <TB3> INFO: PixTestPretest::doTest() done, duration: 80 seconds
[18:03:07.029] <TB3> INFO: enter test to run
[18:03:07.031] <TB3> INFO: test: FullTest no parameter change
[18:03:07.031] <TB3> INFO: running: fulltest
[18:03:07.031] <TB3> INFO: ######################################################################
[18:03:07.031] <TB3> INFO: PixTestFullTest::doTest()
[18:03:07.031] <TB3> INFO: ######################################################################
[18:03:07.032] <TB3> INFO: ######################################################################
[18:03:07.037] <TB3> INFO: PixTestAlive::doTest()
[18:03:07.037] <TB3> INFO: ######################################################################
[18:03:07.038] <TB3> INFO: ----------------------------------------------------------------------
[18:03:07.038] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:03:07.038] <TB3> INFO: ----------------------------------------------------------------------
[18:03:07.293] <TB3> INFO: Expecting 41600 events.
[18:03:10.002] <TB3> INFO: 41600 events read in total (3117ms).
[18:03:10.003] <TB3> INFO: Test took 3963ms.
[18:03:11.233] <TB3> INFO: PixTestAlive::aliveTest() done
[18:03:11.241] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[18:03:11.242] <TB3> INFO: ----------------------------------------------------------------------
[18:03:11.244] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:03:11.244] <TB3> INFO: ----------------------------------------------------------------------
[18:03:11.534] <TB3> INFO: Expecting 41600 events.
[18:03:14.592] <TB3> INFO: 41600 events read in total (2463ms).
[18:03:14.592] <TB3> INFO: Test took 3339ms.
[18:03:14.593] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[18:03:14.825] <TB3> INFO: PixTestAlive::maskTest() done
[18:03:14.825] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[18:03:14.826] <TB3> INFO: ----------------------------------------------------------------------
[18:03:14.826] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:03:14.826] <TB3> INFO: ----------------------------------------------------------------------
[18:03:15.067] <TB3> INFO: Expecting 41600 events.
[18:03:18.787] <TB3> INFO: 41600 events read in total (3128ms).
[18:03:18.787] <TB3> INFO: Test took 3959ms.
[18:03:19.018] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[18:03:19.018] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[18:03:19.018] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[18:03:19.018] <TB3> INFO: Decoding statistics:
[18:03:19.018] <TB3> INFO: General information:
[18:03:19.018] <TB3> INFO: 16bit words read: 0
[18:03:19.018] <TB3> INFO: valid events total: 0
[18:03:19.018] <TB3> INFO: empty events: 0
[18:03:19.018] <TB3> INFO: valid events with pixels: 0
[18:03:19.018] <TB3> INFO: valid pixel hits: 0
[18:03:19.018] <TB3> INFO: Event errors: 0
[18:03:19.018] <TB3> INFO: start marker: 0
[18:03:19.018] <TB3> INFO: stop marker: 0
[18:03:19.018] <TB3> INFO: overflow: 0
[18:03:19.018] <TB3> INFO: invalid 5bit words: 0
[18:03:19.018] <TB3> INFO: invalid XOR eye diagram: 0
[18:03:19.018] <TB3> INFO: frame (failed synchr.): 0
[18:03:19.018] <TB3> INFO: idle data (no TBM trl): 0
[18:03:19.018] <TB3> INFO: no data (only TBM hdr): 0
[18:03:19.018] <TB3> INFO: TBM errors: 0
[18:03:19.018] <TB3> INFO: flawed TBM headers: 0
[18:03:19.018] <TB3> INFO: flawed TBM trailers: 0
[18:03:19.018] <TB3> INFO: event ID mismatches: 0
[18:03:19.018] <TB3> INFO: ROC errors: 0
[18:03:19.018] <TB3> INFO: missing ROC header(s): 0
[18:03:19.018] <TB3> INFO: misplaced readback start: 0
[18:03:19.018] <TB3> INFO: Pixel decoding errors: 0
[18:03:19.018] <TB3> INFO: pixel data incomplete: 0
[18:03:19.018] <TB3> INFO: pixel address: 0
[18:03:19.018] <TB3> INFO: pulse height fill bit: 0
[18:03:19.018] <TB3> INFO: buffer corruption: 0
[18:03:19.023] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C15.dat
[18:03:19.024] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[18:03:19.024] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[18:03:19.024] <TB3> INFO: ######################################################################
[18:03:19.024] <TB3> INFO: PixTestReadback::doTest()
[18:03:19.024] <TB3> INFO: ######################################################################
[18:03:19.024] <TB3> INFO: ----------------------------------------------------------------------
[18:03:19.024] <TB3> INFO: PixTestReadback::CalibrateVd()
[18:03:19.024] <TB3> INFO: ----------------------------------------------------------------------
[18:03:28.002] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C0.dat
[18:03:28.002] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C1.dat
[18:03:28.003] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C2.dat
[18:03:28.003] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C3.dat
[18:03:29.003] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C4.dat
[18:03:29.003] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C5.dat
[18:03:29.003] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C6.dat
[18:03:29.003] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C7.dat
[18:03:29.003] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C8.dat
[18:03:29.004] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C9.dat
[18:03:29.004] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C10.dat
[18:03:29.004] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C11.dat
[18:03:29.004] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C12.dat
[18:03:29.004] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C13.dat
[18:03:29.004] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C14.dat
[18:03:29.004] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C15.dat
[18:03:29.034] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[18:03:29.034] <TB3> INFO: ----------------------------------------------------------------------
[18:03:29.034] <TB3> INFO: PixTestReadback::CalibrateVa()
[18:03:29.034] <TB3> INFO: ----------------------------------------------------------------------
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C0.dat
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C1.dat
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C2.dat
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C3.dat
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C4.dat
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C5.dat
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C6.dat
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C7.dat
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C8.dat
[18:03:38.998] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C9.dat
[18:03:38.999] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C10.dat
[18:03:38.999] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C11.dat
[18:03:38.999] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C12.dat
[18:03:38.999] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C13.dat
[18:03:38.999] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C14.dat
[18:03:38.999] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C15.dat
[18:03:39.027] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[18:03:39.027] <TB3> INFO: ----------------------------------------------------------------------
[18:03:39.027] <TB3> INFO: PixTestReadback::readbackVbg()
[18:03:39.027] <TB3> INFO: ----------------------------------------------------------------------
[18:03:46.699] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[18:03:46.699] <TB3> INFO: ----------------------------------------------------------------------
[18:03:46.700] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[18:03:46.700] <TB3> INFO: ----------------------------------------------------------------------
[18:03:46.700] <TB3> INFO: Vbg will be calibrated using Vd calibration
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 158.1calibrated Vbg = 1.19073 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 156.6calibrated Vbg = 1.18514 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 155calibrated Vbg = 1.18396 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 158.9calibrated Vbg = 1.1807 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 154.5calibrated Vbg = 1.18676 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 151.6calibrated Vbg = 1.18687 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 158.9calibrated Vbg = 1.1915 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 159.2calibrated Vbg = 1.18873 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 145.6calibrated Vbg = 1.18485 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 153.1calibrated Vbg = 1.18723 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 158.2calibrated Vbg = 1.18364 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 148.6calibrated Vbg = 1.1778 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 149.8calibrated Vbg = 1.18746 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 162.8calibrated Vbg = 1.1871 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 164.8calibrated Vbg = 1.18379 :::*/*/*/*/
[18:03:46.700] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 151.4calibrated Vbg = 1.18519 :::*/*/*/*/
[18:03:46.703] <TB3> INFO: ----------------------------------------------------------------------
[18:03:46.703] <TB3> INFO: PixTestReadback::CalibrateIa()
[18:03:46.703] <TB3> INFO: ----------------------------------------------------------------------
[18:06:27.511] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C0.dat
[18:06:27.511] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C1.dat
[18:06:27.511] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C2.dat
[18:06:27.511] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C3.dat
[18:06:27.511] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C4.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C5.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C6.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C7.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C8.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C9.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C10.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C11.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C12.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C13.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C14.dat
[18:06:27.512] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//readbackCal_C15.dat
[18:06:27.542] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[18:06:27.544] <TB3> INFO: PixTestReadback::doTest() done
[18:06:27.544] <TB3> INFO: Decoding statistics:
[18:06:27.544] <TB3> INFO: General information:
[18:06:27.544] <TB3> INFO: 16bit words read: 1536
[18:06:27.544] <TB3> INFO: valid events total: 256
[18:06:27.544] <TB3> INFO: empty events: 256
[18:06:27.544] <TB3> INFO: valid events with pixels: 0
[18:06:27.544] <TB3> INFO: valid pixel hits: 0
[18:06:27.544] <TB3> INFO: Event errors: 0
[18:06:27.544] <TB3> INFO: start marker: 0
[18:06:27.544] <TB3> INFO: stop marker: 0
[18:06:27.544] <TB3> INFO: overflow: 0
[18:06:27.544] <TB3> INFO: invalid 5bit words: 0
[18:06:27.544] <TB3> INFO: invalid XOR eye diagram: 0
[18:06:27.544] <TB3> INFO: frame (failed synchr.): 0
[18:06:27.544] <TB3> INFO: idle data (no TBM trl): 0
[18:06:27.544] <TB3> INFO: no data (only TBM hdr): 0
[18:06:27.544] <TB3> INFO: TBM errors: 0
[18:06:27.544] <TB3> INFO: flawed TBM headers: 0
[18:06:27.544] <TB3> INFO: flawed TBM trailers: 0
[18:06:27.544] <TB3> INFO: event ID mismatches: 0
[18:06:27.544] <TB3> INFO: ROC errors: 0
[18:06:27.544] <TB3> INFO: missing ROC header(s): 0
[18:06:27.544] <TB3> INFO: misplaced readback start: 0
[18:06:27.544] <TB3> INFO: Pixel decoding errors: 0
[18:06:27.544] <TB3> INFO: pixel data incomplete: 0
[18:06:27.544] <TB3> INFO: pixel address: 0
[18:06:27.544] <TB3> INFO: pulse height fill bit: 0
[18:06:27.544] <TB3> INFO: buffer corruption: 0
[18:06:27.596] <TB3> INFO: ######################################################################
[18:06:27.596] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[18:06:27.596] <TB3> INFO: ######################################################################
[18:06:27.598] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[18:06:27.652] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[18:06:27.652] <TB3> INFO: run 1 of 1
[18:06:27.892] <TB3> INFO: Expecting 3120000 events.
[18:07:00.095] <TB3> INFO: 663630 events read in total (31611ms).
[18:07:12.206] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (207) != TBM ID (129)

[18:07:12.367] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 207 207 129 207 207 207 207 207

[18:07:12.375] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (208)

[18:07:12.375] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:07:12.375] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d3 8040 4600 260 29ef 4601 260 29ef e022 c000

[18:07:12.375] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0cd 80c0 4600 260 29ef 4700 260 29ef e022 c000

[18:07:12.375] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ce 8000 4701 260 29ef 4601 260 29ef e022 c000

[18:07:12.375] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4701 4701 29ef 4703 260 29ef e022 c000

[18:07:12.375] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d0 80b1 4600 260 29ef 4600 260 29ef e022 c000

[18:07:12.375] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d1 80c0 4601 260 29ef 4601 260 29ef e022 c000

[18:07:12.375] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d2 8000 4700 260 29ef 4600 260 29ef e022 c000

[18:07:12.376] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 32 readouts!

[18:07:12.377] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 32 readouts!

[18:07:12.377] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:07:12.377] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e2 8000 4700 260 29ef 4600 260 29ef e022 c000

[18:07:12.377] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dc 80b1 4601 260 29ef 4601 260 29ef e022 c000

[18:07:12.377] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dd 80c0 4701 260 29ef 4701 260 29ef e022 c000

[18:07:12.377] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0de 8000 4601 260 29ef 4701 260 29ef e022 c000

[18:07:12.377] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0df 8040 4602 260 29ef 4602 260 29ef e022 c000

[18:07:12.377] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e0 80b1 4600 260 29ef 4600 260 29ef e022 c000

[18:07:12.377] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e1 80c0 4701 260 29ef 4601 260 29ef e022 c000

[18:07:32.852] <TB3> INFO: 1321940 events read in total (64368ms).
[18:07:44.900] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (85) != TBM ID (129)

[18:07:45.043] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 85 85 129 85 85 85 85 85

[18:07:45.043] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (86)

[18:07:45.043] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:07:45.043] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a059 80c0 4601 4c0 25ef 4601 4c0 25ef e022 c000

[18:07:45.043] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a053 8040 4600 4c0 25ef 4701 4c0 25ef e022 c000

[18:07:45.043] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a054 80b1 4700 4c0 25ef 4600 4c0 25ef e022 c000

[18:07:45.043] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4701 4701 25ef 4600 4c0 25ef e022 c000

[18:07:45.043] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a056 8000 4600 4c0 25ef 4700 4c0 25ef e022 c000

[18:07:45.043] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a057 8040 4600 4c0 25ef 4600 4c0 25ef e022 c000

[18:07:45.043] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a058 80b1 4600 4c0 25ef 4600 4c0 25ef e022 c000

[18:08:05.388] <TB3> INFO: 1976835 events read in total (96904ms).
[18:08:17.490] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (132) != TBM ID (129)

[18:08:17.641] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 132 132 129 132 132 132 132 132

[18:08:17.641] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (133)

[18:08:17.641] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:08:17.641] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a088 80b1 4600 812 27ef 4600 812 27ef e022 c000

[18:08:17.641] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a082 8000 4600 812 27ef 4600 812 27ef e022 c000

[18:08:17.641] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a083 8040 4600 812 27ef 4601 812 27ef e022 c000

[18:08:17.641] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4701 4701 27ef 4600 812 27ef e022 c000

[18:08:17.641] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a085 80c0 4600 812 27ef 4600 812 27ef e022 c000

[18:08:17.641] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a086 8000 4600 812 27ef 4600 812 27ef e022 c000

[18:08:17.641] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a087 8040 4600 812 27ef 4600 812 27ef e022 c000

[18:08:37.344] <TB3> INFO: 2633690 events read in total (128860ms).
[18:08:46.384] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (91) != TBM ID (129)

[18:08:46.531] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 91 91 129 91 91 91 91 91

[18:08:46.535] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (92)

[18:08:46.535] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:08:46.535] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05f 8040 4603 a70 2fef 4603 a70 2fef e022 c000

[18:08:46.535] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a059 80c0 4601 a70 2fef 4601 a70 2fef e022 c000

[18:08:46.535] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05a 8000 4600 a70 2fef 4700 a70 2fef e022 c000

[18:08:46.535] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4701 4701 2fef 4601 a70 2fef e022 c000

[18:08:46.535] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05c 80b1 4600 a70 2fef 4600 a70 2fef e022 c000

[18:08:46.535] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05d 80c0 4601 a70 2fef 4601 a70 2fef e022 c000

[18:08:46.535] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a05e 8000 4600 a70 2fef 4600 a70 2fef e022 c000

[18:09:01.617] <TB3> INFO: 3120000 events read in total (153133ms).
[18:09:01.735] <TB3> INFO: Test took 154084ms.
[18:09:24.599] <TB3> INFO: PixTestBBMap::doTest() done with 4 decoding errors: , duration: 177 seconds
[18:09:24.599] <TB3> INFO: number of dead bumps (per ROC): 0 0 0 0 0 1 0 0 0 1 1 0 0 1 0 0
[18:09:24.599] <TB3> INFO: separation cut (per ROC): 111 91 89 102 93 108 104 100 98 102 104 115 104 97 104 102
[18:09:24.600] <TB3> INFO: Decoding statistics:
[18:09:24.600] <TB3> INFO: General information:
[18:09:24.600] <TB3> INFO: 16bit words read: 0
[18:09:24.600] <TB3> INFO: valid events total: 0
[18:09:24.600] <TB3> INFO: empty events: 0
[18:09:24.600] <TB3> INFO: valid events with pixels: 0
[18:09:24.600] <TB3> INFO: valid pixel hits: 0
[18:09:24.600] <TB3> INFO: Event errors: 0
[18:09:24.600] <TB3> INFO: start marker: 0
[18:09:24.600] <TB3> INFO: stop marker: 0
[18:09:24.600] <TB3> INFO: overflow: 0
[18:09:24.600] <TB3> INFO: invalid 5bit words: 0
[18:09:24.600] <TB3> INFO: invalid XOR eye diagram: 0
[18:09:24.600] <TB3> INFO: frame (failed synchr.): 0
[18:09:24.600] <TB3> INFO: idle data (no TBM trl): 0
[18:09:24.600] <TB3> INFO: no data (only TBM hdr): 0
[18:09:24.600] <TB3> INFO: TBM errors: 0
[18:09:24.600] <TB3> INFO: flawed TBM headers: 0
[18:09:24.600] <TB3> INFO: flawed TBM trailers: 0
[18:09:24.600] <TB3> INFO: event ID mismatches: 0
[18:09:24.600] <TB3> INFO: ROC errors: 0
[18:09:24.600] <TB3> INFO: missing ROC header(s): 0
[18:09:24.600] <TB3> INFO: misplaced readback start: 0
[18:09:24.600] <TB3> INFO: Pixel decoding errors: 0
[18:09:24.600] <TB3> INFO: pixel data incomplete: 0
[18:09:24.600] <TB3> INFO: pixel address: 0
[18:09:24.600] <TB3> INFO: pulse height fill bit: 0
[18:09:24.600] <TB3> INFO: buffer corruption: 0
[18:09:24.637] <TB3> INFO: ######################################################################
[18:09:24.637] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[18:09:24.637] <TB3> INFO: ######################################################################
[18:09:24.638] <TB3> INFO: ----------------------------------------------------------------------
[18:09:24.638] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[18:09:24.638] <TB3> INFO: ----------------------------------------------------------------------
[18:09:24.638] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[18:09:24.651] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[18:09:24.651] <TB3> INFO: run 1 of 1
[18:09:24.887] <TB3> INFO: Expecting 36608000 events.
[18:09:50.737] <TB3> INFO: 665350 events read in total (25258ms).
[18:10:15.201] <TB3> INFO: 1320350 events read in total (49722ms).
[18:10:40.305] <TB3> INFO: 1977600 events read in total (74826ms).
[18:11:03.167] <TB3> INFO: 2634650 events read in total (97688ms).
[18:11:28.485] <TB3> INFO: 3289050 events read in total (123006ms).
[18:11:53.214] <TB3> INFO: 3942500 events read in total (147735ms).
[18:12:18.315] <TB3> INFO: 4597150 events read in total (172836ms).
[18:12:42.910] <TB3> INFO: 5250400 events read in total (197431ms).
[18:13:08.363] <TB3> INFO: 5903800 events read in total (222884ms).
[18:13:33.533] <TB3> INFO: 6558650 events read in total (248054ms).
[18:13:58.441] <TB3> INFO: 7212400 events read in total (272962ms).
[18:14:23.557] <TB3> INFO: 7865300 events read in total (298078ms).
[18:14:48.159] <TB3> INFO: 8519400 events read in total (322680ms).
[18:15:13.455] <TB3> INFO: 9174400 events read in total (347976ms).
[18:15:38.332] <TB3> INFO: 9826750 events read in total (372853ms).
[18:16:02.949] <TB3> INFO: 10477850 events read in total (397470ms).
[18:16:28.260] <TB3> INFO: 11130200 events read in total (422781ms).
[18:16:53.407] <TB3> INFO: 11782900 events read in total (447928ms).
[18:17:18.591] <TB3> INFO: 12437500 events read in total (473112ms).
[18:17:43.401] <TB3> INFO: 13089400 events read in total (497922ms).
[18:18:07.986] <TB3> INFO: 13739400 events read in total (522507ms).
[18:18:33.176] <TB3> INFO: 14390350 events read in total (547697ms).
[18:18:58.423] <TB3> INFO: 15040900 events read in total (572944ms).
[18:19:23.627] <TB3> INFO: 15691850 events read in total (598148ms).
[18:19:48.249] <TB3> INFO: 16342100 events read in total (622770ms).
[18:20:13.301] <TB3> INFO: 16992600 events read in total (647822ms).
[18:20:39.315] <TB3> INFO: 17640850 events read in total (673836ms).
[18:21:04.105] <TB3> INFO: 18287050 events read in total (698626ms).
[18:21:29.271] <TB3> INFO: 18933050 events read in total (723792ms).
[18:21:54.049] <TB3> INFO: 19579000 events read in total (748570ms).
[18:22:18.824] <TB3> INFO: 20225500 events read in total (773345ms).
[18:22:44.064] <TB3> INFO: 20870300 events read in total (798585ms).
[18:23:08.769] <TB3> INFO: 21515600 events read in total (823290ms).
[18:23:33.953] <TB3> INFO: 22160800 events read in total (848474ms).
[18:23:58.896] <TB3> INFO: 22805850 events read in total (873417ms).
[18:24:23.802] <TB3> INFO: 23450050 events read in total (898323ms).
[18:24:48.523] <TB3> INFO: 24095950 events read in total (923044ms).
[18:25:12.948] <TB3> INFO: 24742150 events read in total (947469ms).
[18:25:37.000] <TB3> INFO: 25387500 events read in total (972521ms).
[18:26:02.232] <TB3> INFO: 26030900 events read in total (996753ms).
[18:26:27.256] <TB3> INFO: 26675300 events read in total (1021777ms).
[18:26:52.328] <TB3> INFO: 27318750 events read in total (1046849ms).
[18:27:16.406] <TB3> INFO: 27960400 events read in total (1070927ms).
[18:27:41.229] <TB3> INFO: 28603850 events read in total (1095750ms).
[18:28:05.735] <TB3> INFO: 29246750 events read in total (1120256ms).
[18:28:30.470] <TB3> INFO: 29889150 events read in total (1144991ms).
[18:28:55.295] <TB3> INFO: 30532600 events read in total (1169816ms).
[18:29:20.036] <TB3> INFO: 31175550 events read in total (1194557ms).
[18:29:45.046] <TB3> INFO: 31818100 events read in total (1219567ms).
[18:30:09.739] <TB3> INFO: 32461350 events read in total (1244260ms).
[18:30:34.522] <TB3> INFO: 33102450 events read in total (1269043ms).
[18:30:59.049] <TB3> INFO: 33745500 events read in total (1293570ms).
[18:31:24.037] <TB3> INFO: 34388050 events read in total (1318558ms).
[18:31:48.917] <TB3> INFO: 35030500 events read in total (1343438ms).
[18:32:13.446] <TB3> INFO: 35674450 events read in total (1367967ms).
[18:32:39.047] <TB3> INFO: 36325550 events read in total (1393568ms).
[18:32:50.408] <TB3> INFO: 36608000 events read in total (1404929ms).
[18:32:50.487] <TB3> INFO: Test took 1405836ms.
[18:32:50.909] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:32:52.398] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:32:53.912] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:32:55.338] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:32:57.070] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:32:58.793] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:00.516] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:02.258] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:04.256] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:06.287] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:07.937] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:09.796] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:11.925] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:13.965] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:15.732] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:17.524] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:33:19.505] <TB3> INFO: PixTestScurves::scurves() done
[18:33:19.505] <TB3> INFO: Vcal mean: 125.80 108.26 100.54 107.79 114.82 118.60 107.71 112.39 105.46 113.34 113.70 113.13 107.44 102.60 111.90 111.08
[18:33:19.505] <TB3> INFO: Vcal RMS: 6.28 4.94 6.07 5.96 6.75 5.80 4.89 5.19 5.29 5.28 5.57 5.23 4.56 5.09 5.37 4.59
[18:33:19.505] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1434 seconds
[18:33:19.505] <TB3> INFO: Decoding statistics:
[18:33:19.505] <TB3> INFO: General information:
[18:33:19.505] <TB3> INFO: 16bit words read: 0
[18:33:19.505] <TB3> INFO: valid events total: 0
[18:33:19.505] <TB3> INFO: empty events: 0
[18:33:19.505] <TB3> INFO: valid events with pixels: 0
[18:33:19.505] <TB3> INFO: valid pixel hits: 0
[18:33:19.505] <TB3> INFO: Event errors: 0
[18:33:19.505] <TB3> INFO: start marker: 0
[18:33:19.505] <TB3> INFO: stop marker: 0
[18:33:19.505] <TB3> INFO: overflow: 0
[18:33:19.505] <TB3> INFO: invalid 5bit words: 0
[18:33:19.505] <TB3> INFO: invalid XOR eye diagram: 0
[18:33:19.505] <TB3> INFO: frame (failed synchr.): 0
[18:33:19.505] <TB3> INFO: idle data (no TBM trl): 0
[18:33:19.505] <TB3> INFO: no data (only TBM hdr): 0
[18:33:19.505] <TB3> INFO: TBM errors: 0
[18:33:19.505] <TB3> INFO: flawed TBM headers: 0
[18:33:19.505] <TB3> INFO: flawed TBM trailers: 0
[18:33:19.505] <TB3> INFO: event ID mismatches: 0
[18:33:19.505] <TB3> INFO: ROC errors: 0
[18:33:19.505] <TB3> INFO: missing ROC header(s): 0
[18:33:19.505] <TB3> INFO: misplaced readback start: 0
[18:33:19.505] <TB3> INFO: Pixel decoding errors: 0
[18:33:19.505] <TB3> INFO: pixel data incomplete: 0
[18:33:19.505] <TB3> INFO: pixel address: 0
[18:33:19.505] <TB3> INFO: pulse height fill bit: 0
[18:33:19.505] <TB3> INFO: buffer corruption: 0
[18:33:19.589] <TB3> INFO: ######################################################################
[18:33:19.598] <TB3> INFO: PixTestTrim::doTest()
[18:33:19.598] <TB3> INFO: ######################################################################
[18:33:19.601] <TB3> INFO: ----------------------------------------------------------------------
[18:33:19.603] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[18:33:19.603] <TB3> INFO: ----------------------------------------------------------------------
[18:33:19.663] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[18:33:19.663] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[18:33:19.677] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[18:33:19.678] <TB3> INFO: run 1 of 1
[18:33:19.949] <TB3> INFO: Expecting 5025280 events.
[18:33:52.615] <TB3> INFO: 819432 events read in total (32067ms).
[18:34:24.894] <TB3> INFO: 1636896 events read in total (64347ms).
[18:34:57.718] <TB3> INFO: 2450464 events read in total (97170ms).
[18:35:30.433] <TB3> INFO: 3262640 events read in total (129885ms).
[18:36:03.056] <TB3> INFO: 4072864 events read in total (162509ms).
[18:36:35.046] <TB3> INFO: 4880688 events read in total (194498ms).
[18:36:41.258] <TB3> INFO: 5025280 events read in total (200710ms).
[18:36:41.369] <TB3> INFO: Test took 201692ms.
[18:37:03.099] <TB3> INFO: ROC 0 VthrComp = 129
[18:37:03.099] <TB3> INFO: ROC 1 VthrComp = 108
[18:37:03.099] <TB3> INFO: ROC 2 VthrComp = 99
[18:37:03.099] <TB3> INFO: ROC 3 VthrComp = 105
[18:37:03.099] <TB3> INFO: ROC 4 VthrComp = 112
[18:37:03.099] <TB3> INFO: ROC 5 VthrComp = 126
[18:37:03.099] <TB3> INFO: ROC 6 VthrComp = 110
[18:37:03.100] <TB3> INFO: ROC 7 VthrComp = 111
[18:37:03.100] <TB3> INFO: ROC 8 VthrComp = 105
[18:37:03.100] <TB3> INFO: ROC 9 VthrComp = 113
[18:37:03.100] <TB3> INFO: ROC 10 VthrComp = 114
[18:37:03.100] <TB3> INFO: ROC 11 VthrComp = 119
[18:37:03.100] <TB3> INFO: ROC 12 VthrComp = 112
[18:37:03.100] <TB3> INFO: ROC 13 VthrComp = 107
[18:37:03.100] <TB3> INFO: ROC 14 VthrComp = 113
[18:37:03.100] <TB3> INFO: ROC 15 VthrComp = 110
[18:37:03.375] <TB3> INFO: Expecting 41600 events.
[18:37:06.950] <TB3> INFO: 41600 events read in total (2984ms).
[18:37:06.951] <TB3> INFO: Test took 3849ms.
[18:37:06.960] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[18:37:06.960] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[18:37:06.971] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[18:37:06.971] <TB3> INFO: run 1 of 1
[18:37:07.250] <TB3> INFO: Expecting 5025280 events.
[18:37:36.007] <TB3> INFO: 591888 events read in total (28165ms).
[18:38:03.932] <TB3> INFO: 1182544 events read in total (56090ms).
[18:38:32.144] <TB3> INFO: 1773080 events read in total (84302ms).
[18:39:00.191] <TB3> INFO: 2363040 events read in total (112349ms).
[18:39:27.753] <TB3> INFO: 2950344 events read in total (139911ms).
[18:39:56.057] <TB3> INFO: 3536344 events read in total (168215ms).
[18:40:24.386] <TB3> INFO: 4121616 events read in total (196544ms).
[18:40:52.389] <TB3> INFO: 4706712 events read in total (224547ms).
[18:41:08.159] <TB3> INFO: 5025280 events read in total (240317ms).
[18:41:08.288] <TB3> INFO: Test took 241317ms.
[18:41:33.426] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 61.9962 for pixel 23/8 mean/min/max = 47.745/33.2955/62.1945
[18:41:33.427] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 63.2225 for pixel 2/17 mean/min/max = 48.9792/34.62/63.3384
[18:41:33.427] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 62.3002 for pixel 3/45 mean/min/max = 46.934/31.5231/62.345
[18:41:33.428] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 64.6122 for pixel 2/53 mean/min/max = 49.0499/33.3573/64.7425
[18:41:33.428] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 62.5528 for pixel 21/75 mean/min/max = 47.0224/31.2617/62.7831
[18:41:33.429] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 58.5895 for pixel 12/4 mean/min/max = 44.9071/31.2158/58.5984
[18:41:33.429] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 59.6056 for pixel 48/79 mean/min/max = 47.1926/34.5095/59.8757
[18:41:33.430] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 63.8602 for pixel 18/72 mean/min/max = 49.1795/34.4034/63.9556
[18:41:33.430] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 61.7201 for pixel 0/38 mean/min/max = 48.2784/34.7406/61.8162
[18:41:33.431] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 61.2334 for pixel 19/77 mean/min/max = 46.7849/32.2396/61.3302
[18:41:33.431] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 61.421 for pixel 38/20 mean/min/max = 46.6193/31.7388/61.4997
[18:41:33.432] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 58.9055 for pixel 23/9 mean/min/max = 45.3001/31.4421/59.158
[18:41:33.432] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 58.5135 for pixel 43/0 mean/min/max = 45.4606/32.3655/58.5556
[18:41:33.433] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 59.3533 for pixel 4/12 mean/min/max = 47.2493/34.9834/59.5151
[18:41:33.433] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 60.6115 for pixel 24/4 mean/min/max = 46.4106/32.086/60.7351
[18:41:33.434] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 61.0147 for pixel 11/3 mean/min/max = 47.8695/34.702/61.0371
[18:41:33.434] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:41:33.524] <TB3> INFO: Expecting 411648 events.
[18:41:43.431] <TB3> INFO: 411648 events read in total (9314ms).
[18:41:43.441] <TB3> INFO: Expecting 411648 events.
[18:41:53.168] <TB3> INFO: 411648 events read in total (9324ms).
[18:41:53.184] <TB3> INFO: Expecting 411648 events.
[18:42:02.818] <TB3> INFO: 411648 events read in total (9231ms).
[18:42:02.835] <TB3> INFO: Expecting 411648 events.
[18:42:12.625] <TB3> INFO: 411648 events read in total (9386ms).
[18:42:12.648] <TB3> INFO: Expecting 411648 events.
[18:42:22.391] <TB3> INFO: 411648 events read in total (9328ms).
[18:42:22.417] <TB3> INFO: Expecting 411648 events.
[18:42:32.076] <TB3> INFO: 411648 events read in total (9256ms).
[18:42:32.108] <TB3> INFO: Expecting 411648 events.
[18:42:41.812] <TB3> INFO: 411648 events read in total (9301ms).
[18:42:41.835] <TB3> INFO: Expecting 411648 events.
[18:42:51.464] <TB3> INFO: 411648 events read in total (9226ms).
[18:42:51.502] <TB3> INFO: Expecting 411648 events.
[18:43:01.179] <TB3> INFO: 411648 events read in total (9273ms).
[18:43:01.216] <TB3> INFO: Expecting 411648 events.
[18:43:10.862] <TB3> INFO: 411648 events read in total (9243ms).
[18:43:10.903] <TB3> INFO: Expecting 411648 events.
[18:43:20.636] <TB3> INFO: 411648 events read in total (9325ms).
[18:43:20.682] <TB3> INFO: Expecting 411648 events.
[18:43:30.490] <TB3> INFO: 411648 events read in total (9405ms).
[18:43:30.539] <TB3> INFO: Expecting 411648 events.
[18:43:40.389] <TB3> INFO: 411648 events read in total (9445ms).
[18:43:40.436] <TB3> INFO: Expecting 411648 events.
[18:43:50.254] <TB3> INFO: 411648 events read in total (9414ms).
[18:43:50.328] <TB3> INFO: Expecting 411648 events.
[18:44:00.118] <TB3> INFO: 411648 events read in total (9387ms).
[18:44:00.199] <TB3> INFO: Expecting 411648 events.
[18:44:09.878] <TB3> INFO: 411648 events read in total (9276ms).
[18:44:09.960] <TB3> INFO: Test took 156526ms.
[18:44:10.766] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[18:44:10.781] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[18:44:10.781] <TB3> INFO: run 1 of 1
[18:44:11.041] <TB3> INFO: Expecting 5025280 events.
[18:44:40.134] <TB3> INFO: 588800 events read in total (28501ms).
[18:45:08.702] <TB3> INFO: 1177240 events read in total (57069ms).
[18:45:36.929] <TB3> INFO: 1764696 events read in total (85297ms).
[18:46:05.881] <TB3> INFO: 2353168 events read in total (114248ms).
[18:46:34.753] <TB3> INFO: 2941632 events read in total (143120ms).
[18:47:03.124] <TB3> INFO: 3530880 events read in total (171491ms).
[18:47:31.524] <TB3> INFO: 4115960 events read in total (199891ms).
[18:48:01.075] <TB3> INFO: 4703432 events read in total (229442ms).
[18:48:16.565] <TB3> INFO: 5025280 events read in total (244932ms).
[18:48:16.726] <TB3> INFO: Test took 245946ms.
[18:48:42.283] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 4.500000 .. 141.620299
[18:48:42.530] <TB3> INFO: Expecting 208000 events.
[18:48:53.101] <TB3> INFO: 208000 events read in total (9977ms).
[18:48:53.103] <TB3> INFO: Test took 10818ms.
[18:48:53.167] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 4 .. 151 (-1/-1) hits flags = 528 (plus default)
[18:48:53.181] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[18:48:53.181] <TB3> INFO: run 1 of 1
[18:48:53.460] <TB3> INFO: Expecting 4925440 events.
[18:49:22.467] <TB3> INFO: 582256 events read in total (28415ms).
[18:49:50.131] <TB3> INFO: 1164472 events read in total (56079ms).
[18:50:18.604] <TB3> INFO: 1746344 events read in total (84552ms).
[18:50:44.982] <TB3> INFO: 2328176 events read in total (110930ms).
[18:51:11.971] <TB3> INFO: 2909912 events read in total (137919ms).
[18:51:40.386] <TB3> INFO: 3490792 events read in total (166334ms).
[18:52:08.004] <TB3> INFO: 4071880 events read in total (193952ms).
[18:52:37.316] <TB3> INFO: 4652984 events read in total (223264ms).
[18:52:50.598] <TB3> INFO: 4925440 events read in total (236547ms).
[18:52:50.694] <TB3> INFO: Test took 237513ms.
[18:53:15.709] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 27.412450 .. 45.264765
[18:53:15.971] <TB3> INFO: Expecting 208000 events.
[18:53:27.262] <TB3> INFO: 208000 events read in total (10697ms).
[18:53:27.264] <TB3> INFO: Test took 11550ms.
[18:53:27.338] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 55 (-1/-1) hits flags = 528 (plus default)
[18:53:27.355] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[18:53:27.355] <TB3> INFO: run 1 of 1
[18:53:27.633] <TB3> INFO: Expecting 1297920 events.
[18:53:57.506] <TB3> INFO: 659728 events read in total (29278ms).
[18:54:27.573] <TB3> INFO: 1297920 events read in total (59346ms).
[18:54:27.622] <TB3> INFO: Test took 60268ms.
[18:54:42.027] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 26.603797 .. 46.964857
[18:54:42.269] <TB3> INFO: Expecting 208000 events.
[18:54:52.449] <TB3> INFO: 208000 events read in total (9589ms).
[18:54:52.450] <TB3> INFO: Test took 10421ms.
[18:54:52.500] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 56 (-1/-1) hits flags = 528 (plus default)
[18:54:52.513] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[18:54:52.514] <TB3> INFO: run 1 of 1
[18:54:52.792] <TB3> INFO: Expecting 1364480 events.
[18:55:23.614] <TB3> INFO: 659640 events read in total (30230ms).
[18:55:51.972] <TB3> INFO: 1317472 events read in total (58588ms).
[18:55:54.617] <TB3> INFO: 1364480 events read in total (61234ms).
[18:55:54.655] <TB3> INFO: Test took 62141ms.
[18:56:09.415] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 24.730052 .. 44.844082
[18:56:09.665] <TB3> INFO: Expecting 208000 events.
[18:56:20.576] <TB3> INFO: 208000 events read in total (10319ms).
[18:56:20.584] <TB3> INFO: Test took 11168ms.
[18:56:20.649] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 14 .. 54 (-1/-1) hits flags = 528 (plus default)
[18:56:20.665] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[18:56:20.666] <TB3> INFO: run 1 of 1
[18:56:20.976] <TB3> INFO: Expecting 1364480 events.
[18:56:51.306] <TB3> INFO: 675704 events read in total (29731ms).
[18:57:20.224] <TB3> INFO: 1350656 events read in total (58650ms).
[18:57:21.268] <TB3> INFO: 1364480 events read in total (59694ms).
[18:57:21.303] <TB3> INFO: Test took 60638ms.
[18:57:35.544] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[18:57:35.550] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[18:57:35.564] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[18:57:35.564] <TB3> INFO: run 1 of 1
[18:57:35.807] <TB3> INFO: Expecting 1364480 events.
[18:58:06.054] <TB3> INFO: 667080 events read in total (29654ms).
[18:58:37.118] <TB3> INFO: 1333480 events read in total (60718ms).
[18:58:38.977] <TB3> INFO: 1364480 events read in total (62578ms).
[18:58:39.007] <TB3> INFO: Test took 63442ms.
[18:58:52.460] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C0.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C1.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C2.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C3.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C4.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C5.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C6.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C7.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C8.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C9.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C10.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C11.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C12.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C13.dat
[18:58:52.461] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C14.dat
[18:58:52.462] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C15.dat
[18:58:52.462] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C0.dat
[18:58:52.470] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C1.dat
[18:58:52.478] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C2.dat
[18:58:52.483] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C3.dat
[18:58:52.488] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C4.dat
[18:58:52.493] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C5.dat
[18:58:52.499] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C6.dat
[18:58:52.505] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C7.dat
[18:58:52.512] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C8.dat
[18:58:52.518] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C9.dat
[18:58:52.525] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C10.dat
[18:58:52.531] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C11.dat
[18:58:52.537] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C12.dat
[18:58:52.544] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C13.dat
[18:58:52.551] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C14.dat
[18:58:52.557] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//trimParameters35_C15.dat
[18:58:52.564] <TB3> INFO: PixTestTrim::trimTest() done
[18:58:52.564] <TB3> INFO: vtrim: 142 123 108 138 134 121 108 142 116 117 121 127 117 118 122 124
[18:58:52.564] <TB3> INFO: vthrcomp: 129 108 99 105 112 126 110 111 105 113 114 119 112 107 113 110
[18:58:52.564] <TB3> INFO: vcal mean: 34.94 35.07 34.98 35.01 34.98 34.91 34.99 35.18 35.03 35.02 34.94 34.90 34.97 34.99 34.96 34.98
[18:58:52.564] <TB3> INFO: vcal RMS: 1.04 1.08 1.29 1.05 1.17 1.15 0.90 1.23 0.92 1.08 1.20 1.02 0.98 0.95 1.07 0.96
[18:58:52.564] <TB3> INFO: bits mean: 8.68 8.40 9.38 8.84 9.85 10.14 8.16 8.97 8.34 9.41 9.46 9.61 9.73 8.81 9.54 9.00
[18:58:52.564] <TB3> INFO: bits RMS: 2.76 2.62 2.78 2.58 2.56 2.56 2.82 2.49 2.65 2.67 2.74 2.77 2.59 2.50 2.63 2.43
[18:58:52.571] <TB3> INFO: ----------------------------------------------------------------------
[18:58:52.571] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[18:58:52.571] <TB3> INFO: ----------------------------------------------------------------------
[18:58:52.573] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[18:58:52.589] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[18:58:52.589] <TB3> INFO: run 1 of 1
[18:58:52.844] <TB3> INFO: Expecting 4160000 events.
[18:59:26.713] <TB3> INFO: 733935 events read in total (33277ms).
[19:00:00.377] <TB3> INFO: 1464130 events read in total (66941ms).
[19:00:33.994] <TB3> INFO: 2188885 events read in total (100558ms).
[19:01:07.613] <TB3> INFO: 2911320 events read in total (134177ms).
[19:01:40.597] <TB3> INFO: 3633650 events read in total (167161ms).
[19:02:05.637] <TB3> INFO: 4160000 events read in total (192201ms).
[19:02:05.743] <TB3> INFO: Test took 193155ms.
[19:02:32.162] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 200 (-1/-1) hits flags = 528 (plus default)
[19:02:32.175] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[19:02:32.187] <TB3> INFO: run 1 of 1
[19:02:32.445] <TB3> INFO: Expecting 4180800 events.
[19:03:05.893] <TB3> INFO: 708180 events read in total (32844ms).
[19:03:37.388] <TB3> INFO: 1413450 events read in total (64339ms).
[19:04:10.284] <TB3> INFO: 2114315 events read in total (97236ms).
[19:04:42.952] <TB3> INFO: 2812655 events read in total (129903ms).
[19:05:15.799] <TB3> INFO: 3510570 events read in total (162750ms).
[19:05:47.206] <TB3> INFO: 4180800 events read in total (194157ms).
[19:05:47.377] <TB3> INFO: Test took 195190ms.
[19:06:19.411] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 186 (-1/-1) hits flags = 528 (plus default)
[19:06:19.427] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[19:06:19.427] <TB3> INFO: run 1 of 1
[19:06:19.693] <TB3> INFO: Expecting 3889600 events.
[19:06:53.279] <TB3> INFO: 726325 events read in total (32989ms).
[19:07:26.536] <TB3> INFO: 1448825 events read in total (66246ms).
[19:07:59.740] <TB3> INFO: 2166185 events read in total (99450ms).
[19:08:32.805] <TB3> INFO: 2881460 events read in total (132515ms).
[19:09:05.724] <TB3> INFO: 3595825 events read in total (165434ms).
[19:09:19.817] <TB3> INFO: 3889600 events read in total (179527ms).
[19:09:19.972] <TB3> INFO: Test took 180544ms.
[19:09:45.176] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 185 (-1/-1) hits flags = 528 (plus default)
[19:09:45.190] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[19:09:45.190] <TB3> INFO: run 1 of 1
[19:09:45.449] <TB3> INFO: Expecting 3868800 events.
[19:10:19.810] <TB3> INFO: 727730 events read in total (33770ms).
[19:10:53.562] <TB3> INFO: 1451630 events read in total (67522ms).
[19:11:27.448] <TB3> INFO: 2170695 events read in total (101408ms).
[19:12:00.438] <TB3> INFO: 2887350 events read in total (134398ms).
[19:12:33.768] <TB3> INFO: 3603145 events read in total (167728ms).
[19:12:46.647] <TB3> INFO: 3868800 events read in total (180607ms).
[19:12:46.820] <TB3> INFO: Test took 181630ms.
[19:13:21.298] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 186 (-1/-1) hits flags = 528 (plus default)
[19:13:21.314] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[19:13:21.314] <TB3> INFO: run 1 of 1
[19:13:21.589] <TB3> INFO: Expecting 3889600 events.
[19:13:55.230] <TB3> INFO: 726555 events read in total (33046ms).
[19:14:28.994] <TB3> INFO: 1449350 events read in total (66810ms).
[19:15:02.944] <TB3> INFO: 2167245 events read in total (100760ms).
[19:15:36.635] <TB3> INFO: 2882795 events read in total (134451ms).
[19:16:09.551] <TB3> INFO: 3597340 events read in total (167367ms).
[19:16:23.656] <TB3> INFO: 3889600 events read in total (181472ms).
[19:16:23.779] <TB3> INFO: Test took 182464ms.
[19:16:53.231] <TB3> INFO: PixTestTrim::trimBitTest() done
[19:16:53.232] <TB3> INFO: PixTestTrim::doTest() done, duration: 2613 seconds
[19:16:53.232] <TB3> INFO: Decoding statistics:
[19:16:53.232] <TB3> INFO: General information:
[19:16:53.232] <TB3> INFO: 16bit words read: 0
[19:16:53.232] <TB3> INFO: valid events total: 0
[19:16:53.232] <TB3> INFO: empty events: 0
[19:16:53.232] <TB3> INFO: valid events with pixels: 0
[19:16:53.232] <TB3> INFO: valid pixel hits: 0
[19:16:53.232] <TB3> INFO: Event errors: 0
[19:16:53.232] <TB3> INFO: start marker: 0
[19:16:53.232] <TB3> INFO: stop marker: 0
[19:16:53.232] <TB3> INFO: overflow: 0
[19:16:53.232] <TB3> INFO: invalid 5bit words: 0
[19:16:53.232] <TB3> INFO: invalid XOR eye diagram: 0
[19:16:53.232] <TB3> INFO: frame (failed synchr.): 0
[19:16:53.232] <TB3> INFO: idle data (no TBM trl): 0
[19:16:53.232] <TB3> INFO: no data (only TBM hdr): 0
[19:16:53.232] <TB3> INFO: TBM errors: 0
[19:16:53.232] <TB3> INFO: flawed TBM headers: 0
[19:16:53.232] <TB3> INFO: flawed TBM trailers: 0
[19:16:53.232] <TB3> INFO: event ID mismatches: 0
[19:16:53.232] <TB3> INFO: ROC errors: 0
[19:16:53.232] <TB3> INFO: missing ROC header(s): 0
[19:16:53.232] <TB3> INFO: misplaced readback start: 0
[19:16:53.232] <TB3> INFO: Pixel decoding errors: 0
[19:16:53.232] <TB3> INFO: pixel data incomplete: 0
[19:16:53.232] <TB3> INFO: pixel address: 0
[19:16:53.232] <TB3> INFO: pulse height fill bit: 0
[19:16:53.232] <TB3> INFO: buffer corruption: 0
[19:16:53.846] <TB3> INFO: ######################################################################
[19:16:53.846] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[19:16:53.846] <TB3> INFO: ######################################################################
[19:16:54.085] <TB3> INFO: Expecting 41600 events.
[19:16:57.709] <TB3> INFO: 41600 events read in total (3033ms).
[19:16:57.723] <TB3> INFO: Test took 3875ms.
[19:16:58.208] <TB3> INFO: Expecting 41600 events.
[19:17:01.961] <TB3> INFO: 41600 events read in total (3142ms).
[19:17:01.989] <TB3> INFO: Test took 4051ms.
[19:17:02.281] <TB3> INFO: Expecting 41600 events.
[19:17:06.043] <TB3> INFO: 41600 events read in total (3168ms).
[19:17:06.048] <TB3> INFO: Test took 4034ms.
[19:17:06.342] <TB3> INFO: Expecting 41600 events.
[19:17:10.068] <TB3> INFO: 41600 events read in total (3131ms).
[19:17:10.069] <TB3> INFO: Test took 3996ms.
[19:17:10.366] <TB3> INFO: Expecting 41600 events.
[19:17:14.076] <TB3> INFO: 41600 events read in total (3118ms).
[19:17:14.109] <TB3> INFO: Test took 4011ms.
[19:17:14.416] <TB3> INFO: Expecting 41600 events.
[19:17:18.215] <TB3> INFO: 41600 events read in total (3196ms).
[19:17:18.220] <TB3> INFO: Test took 4083ms.
[19:17:18.531] <TB3> INFO: Expecting 41600 events.
[19:17:22.243] <TB3> INFO: 41600 events read in total (3117ms).
[19:17:22.244] <TB3> INFO: Test took 3997ms.
[19:17:22.537] <TB3> INFO: Expecting 41600 events.
[19:17:26.186] <TB3> INFO: 41600 events read in total (3051ms).
[19:17:26.187] <TB3> INFO: Test took 3915ms.
[19:17:26.490] <TB3> INFO: Expecting 41600 events.
[19:17:30.144] <TB3> INFO: 41600 events read in total (3051ms).
[19:17:30.161] <TB3> INFO: Test took 3950ms.
[19:17:30.462] <TB3> INFO: Expecting 41600 events.
[19:17:34.121] <TB3> INFO: 41600 events read in total (3065ms).
[19:17:34.122] <TB3> INFO: Test took 3929ms.
[19:17:34.413] <TB3> INFO: Expecting 41600 events.
[19:17:38.010] <TB3> INFO: 41600 events read in total (3005ms).
[19:17:38.011] <TB3> INFO: Test took 3863ms.
[19:17:38.301] <TB3> INFO: Expecting 41600 events.
[19:17:42.021] <TB3> INFO: 41600 events read in total (3129ms).
[19:17:42.023] <TB3> INFO: Test took 3988ms.
[19:17:42.327] <TB3> INFO: Expecting 41600 events.
[19:17:46.073] <TB3> INFO: 41600 events read in total (3140ms).
[19:17:46.074] <TB3> INFO: Test took 4023ms.
[19:17:46.364] <TB3> INFO: Expecting 41600 events.
[19:17:50.126] <TB3> INFO: 41600 events read in total (3170ms).
[19:17:50.127] <TB3> INFO: Test took 4028ms.
[19:17:50.433] <TB3> INFO: Expecting 41600 events.
[19:17:54.143] <TB3> INFO: 41600 events read in total (3119ms).
[19:17:54.144] <TB3> INFO: Test took 3992ms.
[19:17:54.452] <TB3> INFO: Expecting 41600 events.
[19:17:58.158] <TB3> INFO: 41600 events read in total (3114ms).
[19:17:58.160] <TB3> INFO: Test took 3991ms.
[19:17:58.453] <TB3> INFO: Expecting 41600 events.
[19:18:02.180] <TB3> INFO: 41600 events read in total (3136ms).
[19:18:02.181] <TB3> INFO: Test took 3995ms.
[19:18:02.482] <TB3> INFO: Expecting 41600 events.
[19:18:06.227] <TB3> INFO: 41600 events read in total (3148ms).
[19:18:06.228] <TB3> INFO: Test took 4021ms.
[19:18:06.521] <TB3> INFO: Expecting 41600 events.
[19:18:10.231] <TB3> INFO: 41600 events read in total (3116ms).
[19:18:10.232] <TB3> INFO: Test took 3978ms.
[19:18:10.572] <TB3> INFO: Expecting 41600 events.
[19:18:14.300] <TB3> INFO: 41600 events read in total (3134ms).
[19:18:14.301] <TB3> INFO: Test took 4043ms.
[19:18:14.602] <TB3> INFO: Expecting 41600 events.
[19:18:18.261] <TB3> INFO: 41600 events read in total (3056ms).
[19:18:18.262] <TB3> INFO: Test took 3935ms.
[19:18:18.552] <TB3> INFO: Expecting 41600 events.
[19:18:22.170] <TB3> INFO: 41600 events read in total (3027ms).
[19:18:22.171] <TB3> INFO: Test took 3885ms.
[19:18:22.483] <TB3> INFO: Expecting 41600 events.
[19:18:26.215] <TB3> INFO: 41600 events read in total (3140ms).
[19:18:26.216] <TB3> INFO: Test took 4022ms.
[19:18:26.527] <TB3> INFO: Expecting 41600 events.
[19:18:30.311] <TB3> INFO: 41600 events read in total (3178ms).
[19:18:30.312] <TB3> INFO: Test took 4068ms.
[19:18:30.605] <TB3> INFO: Expecting 41600 events.
[19:18:34.353] <TB3> INFO: 41600 events read in total (3156ms).
[19:18:34.355] <TB3> INFO: Test took 4015ms.
[19:18:34.664] <TB3> INFO: Expecting 41600 events.
[19:18:38.362] <TB3> INFO: 41600 events read in total (3106ms).
[19:18:38.363] <TB3> INFO: Test took 3978ms.
[19:18:38.652] <TB3> INFO: Expecting 41600 events.
[19:18:42.369] <TB3> INFO: 41600 events read in total (3125ms).
[19:18:42.374] <TB3> INFO: Test took 3987ms.
[19:18:42.686] <TB3> INFO: Expecting 41600 events.
[19:18:46.439] <TB3> INFO: 41600 events read in total (3160ms).
[19:18:46.440] <TB3> INFO: Test took 4037ms.
[19:18:46.735] <TB3> INFO: Expecting 41600 events.
[19:18:50.377] <TB3> INFO: 41600 events read in total (3045ms).
[19:18:50.377] <TB3> INFO: Test took 3912ms.
[19:18:50.669] <TB3> INFO: Expecting 41600 events.
[19:18:54.507] <TB3> INFO: 41600 events read in total (3246ms).
[19:18:54.526] <TB3> INFO: Test took 4123ms.
[19:18:54.821] <TB3> INFO: Expecting 41600 events.
[19:18:58.575] <TB3> INFO: 41600 events read in total (3162ms).
[19:18:58.579] <TB3> INFO: Test took 4024ms.
[19:18:58.886] <TB3> INFO: Expecting 2560 events.
[19:18:59.774] <TB3> INFO: 2560 events read in total (296ms).
[19:18:59.775] <TB3> INFO: Test took 1175ms.
[19:19:00.082] <TB3> INFO: Expecting 2560 events.
[19:19:00.970] <TB3> INFO: 2560 events read in total (296ms).
[19:19:00.984] <TB3> INFO: Test took 1208ms.
[19:19:01.279] <TB3> INFO: Expecting 2560 events.
[19:19:02.173] <TB3> INFO: 2560 events read in total (303ms).
[19:19:02.174] <TB3> INFO: Test took 1189ms.
[19:19:02.481] <TB3> INFO: Expecting 2560 events.
[19:19:03.375] <TB3> INFO: 2560 events read in total (303ms).
[19:19:03.376] <TB3> INFO: Test took 1202ms.
[19:19:03.683] <TB3> INFO: Expecting 2560 events.
[19:19:04.576] <TB3> INFO: 2560 events read in total (302ms).
[19:19:04.577] <TB3> INFO: Test took 1200ms.
[19:19:04.884] <TB3> INFO: Expecting 2560 events.
[19:19:05.775] <TB3> INFO: 2560 events read in total (299ms).
[19:19:05.775] <TB3> INFO: Test took 1196ms.
[19:19:06.083] <TB3> INFO: Expecting 2560 events.
[19:19:06.975] <TB3> INFO: 2560 events read in total (300ms).
[19:19:06.975] <TB3> INFO: Test took 1199ms.
[19:19:07.283] <TB3> INFO: Expecting 2560 events.
[19:19:08.174] <TB3> INFO: 2560 events read in total (300ms).
[19:19:08.174] <TB3> INFO: Test took 1199ms.
[19:19:08.482] <TB3> INFO: Expecting 2560 events.
[19:19:09.376] <TB3> INFO: 2560 events read in total (302ms).
[19:19:09.376] <TB3> INFO: Test took 1201ms.
[19:19:09.684] <TB3> INFO: Expecting 2560 events.
[19:19:10.567] <TB3> INFO: 2560 events read in total (291ms).
[19:19:10.567] <TB3> INFO: Test took 1190ms.
[19:19:10.877] <TB3> INFO: Expecting 2560 events.
[19:19:11.758] <TB3> INFO: 2560 events read in total (289ms).
[19:19:11.759] <TB3> INFO: Test took 1191ms.
[19:19:12.067] <TB3> INFO: Expecting 2560 events.
[19:19:12.959] <TB3> INFO: 2560 events read in total (296ms).
[19:19:12.960] <TB3> INFO: Test took 1201ms.
[19:19:13.271] <TB3> INFO: Expecting 2560 events.
[19:19:14.165] <TB3> INFO: 2560 events read in total (302ms).
[19:19:14.165] <TB3> INFO: Test took 1205ms.
[19:19:14.472] <TB3> INFO: Expecting 2560 events.
[19:19:15.366] <TB3> INFO: 2560 events read in total (299ms).
[19:19:15.368] <TB3> INFO: Test took 1202ms.
[19:19:15.675] <TB3> INFO: Expecting 2560 events.
[19:19:16.565] <TB3> INFO: 2560 events read in total (299ms).
[19:19:16.565] <TB3> INFO: Test took 1196ms.
[19:19:16.873] <TB3> INFO: Expecting 2560 events.
[19:19:17.764] <TB3> INFO: 2560 events read in total (300ms).
[19:19:17.767] <TB3> INFO: Test took 1201ms.
[19:19:17.770] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:19:18.074] <TB3> INFO: Expecting 655360 events.
[19:19:33.468] <TB3> INFO: 655360 events read in total (14789ms).
[19:19:33.482] <TB3> INFO: Expecting 655360 events.
[19:19:48.550] <TB3> INFO: 655360 events read in total (14665ms).
[19:19:48.570] <TB3> INFO: Expecting 655360 events.
[19:20:03.748] <TB3> INFO: 655360 events read in total (14775ms).
[19:20:03.776] <TB3> INFO: Expecting 655360 events.
[19:20:19.055] <TB3> INFO: 655360 events read in total (14875ms).
[19:20:19.091] <TB3> INFO: Expecting 655360 events.
[19:20:34.088] <TB3> INFO: 655360 events read in total (14590ms).
[19:20:34.117] <TB3> INFO: Expecting 655360 events.
[19:20:49.441] <TB3> INFO: 655360 events read in total (14920ms).
[19:20:49.490] <TB3> INFO: Expecting 655360 events.
[19:21:04.654] <TB3> INFO: 655360 events read in total (14758ms).
[19:21:04.724] <TB3> INFO: Expecting 655360 events.
[19:21:19.741] <TB3> INFO: 655360 events read in total (14614ms).
[19:21:19.796] <TB3> INFO: Expecting 655360 events.
[19:21:34.891] <TB3> INFO: 655360 events read in total (14691ms).
[19:21:34.970] <TB3> INFO: Expecting 655360 events.
[19:21:50.149] <TB3> INFO: 655360 events read in total (14750ms).
[19:21:50.218] <TB3> INFO: Expecting 655360 events.
[19:22:05.489] <TB3> INFO: 655360 events read in total (14868ms).
[19:22:05.572] <TB3> INFO: Expecting 655360 events.
[19:22:20.771] <TB3> INFO: 655360 events read in total (14796ms).
[19:22:20.863] <TB3> INFO: Expecting 655360 events.
[19:22:35.726] <TB3> INFO: 655360 events read in total (14457ms).
[19:22:35.807] <TB3> INFO: Expecting 655360 events.
[19:22:50.220] <TB3> INFO: 655360 events read in total (14010ms).
[19:22:50.343] <TB3> INFO: Expecting 655360 events.
[19:23:05.508] <TB3> INFO: 655360 events read in total (14762ms).
[19:23:05.623] <TB3> INFO: Expecting 655360 events.
[19:23:20.926] <TB3> INFO: 655360 events read in total (14891ms).
[19:23:21.042] <TB3> INFO: Test took 243272ms.
[19:23:21.155] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:23:21.410] <TB3> INFO: Expecting 655360 events.
[19:23:36.613] <TB3> INFO: 655360 events read in total (14611ms).
[19:23:36.627] <TB3> INFO: Expecting 655360 events.
[19:23:51.584] <TB3> INFO: 655360 events read in total (14548ms).
[19:23:51.608] <TB3> INFO: Expecting 655360 events.
[19:24:06.636] <TB3> INFO: 655360 events read in total (14625ms).
[19:24:06.658] <TB3> INFO: Expecting 655360 events.
[19:24:21.876] <TB3> INFO: 655360 events read in total (14799ms).
[19:24:21.915] <TB3> INFO: Expecting 655360 events.
[19:24:36.965] <TB3> INFO: 655360 events read in total (14646ms).
[19:24:37.007] <TB3> INFO: Expecting 655360 events.
[19:24:51.933] <TB3> INFO: 655360 events read in total (14521ms).
[19:24:51.989] <TB3> INFO: Expecting 655360 events.
[19:25:07.117] <TB3> INFO: 655360 events read in total (14724ms).
[19:25:07.164] <TB3> INFO: Expecting 655360 events.
[19:25:21.176] <TB3> INFO: 655360 events read in total (13609ms).
[19:25:21.218] <TB3> INFO: Expecting 655360 events.
[19:25:36.300] <TB3> INFO: 655360 events read in total (14679ms).
[19:25:36.374] <TB3> INFO: Expecting 655360 events.
[19:25:51.565] <TB3> INFO: 655360 events read in total (14788ms).
[19:25:51.633] <TB3> INFO: Expecting 655360 events.
[19:26:06.817] <TB3> INFO: 655360 events read in total (14780ms).
[19:26:06.897] <TB3> INFO: Expecting 655360 events.
[19:26:22.089] <TB3> INFO: 655360 events read in total (14789ms).
[19:26:22.176] <TB3> INFO: Expecting 655360 events.
[19:26:37.087] <TB3> INFO: 655360 events read in total (14508ms).
[19:26:37.194] <TB3> INFO: Expecting 655360 events.
[19:26:52.377] <TB3> INFO: 655360 events read in total (14780ms).
[19:26:52.514] <TB3> INFO: Expecting 655360 events.
[19:27:07.633] <TB3> INFO: 655360 events read in total (14713ms).
[19:27:07.795] <TB3> INFO: Expecting 655360 events.
[19:27:22.869] <TB3> INFO: 655360 events read in total (14671ms).
[19:27:22.000] <TB3> INFO: Test took 241845ms.
[19:27:23.264] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.273] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.281] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.307] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.322] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:27:23.329] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[19:27:23.342] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[19:27:23.355] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[19:27:23.364] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[19:27:23.380] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.391] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:27:23.411] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.424] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.431] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.438] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.445] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.452] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.459] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:27:23.483] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.494] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.506] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.512] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.522] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:27:23.529] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:27:23.571] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C0.dat
[19:27:23.571] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C1.dat
[19:27:23.572] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C2.dat
[19:27:23.572] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C3.dat
[19:27:23.572] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C4.dat
[19:27:23.572] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C5.dat
[19:27:23.572] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C6.dat
[19:27:23.572] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C7.dat
[19:27:23.573] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C8.dat
[19:27:23.573] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C9.dat
[19:27:23.573] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C10.dat
[19:27:23.573] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C11.dat
[19:27:23.573] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C12.dat
[19:27:23.573] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C13.dat
[19:27:23.573] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C14.dat
[19:27:23.574] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//dacParameters35_C15.dat
[19:27:23.835] <TB3> INFO: Expecting 41600 events.
[19:27:27.096] <TB3> INFO: 41600 events read in total (2649ms).
[19:27:27.097] <TB3> INFO: Test took 3519ms.
[19:27:27.599] <TB3> INFO: Expecting 41600 events.
[19:27:30.707] <TB3> INFO: 41600 events read in total (2515ms).
[19:27:30.716] <TB3> INFO: Test took 3403ms.
[19:27:31.177] <TB3> INFO: Expecting 41600 events.
[19:27:34.299] <TB3> INFO: 41600 events read in total (2530ms).
[19:27:34.300] <TB3> INFO: Test took 3372ms.
[19:27:34.516] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:34.605] <TB3> INFO: Expecting 2560 events.
[19:27:35.488] <TB3> INFO: 2560 events read in total (291ms).
[19:27:35.489] <TB3> INFO: Test took 973ms.
[19:27:35.490] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:35.797] <TB3> INFO: Expecting 2560 events.
[19:27:36.684] <TB3> INFO: 2560 events read in total (295ms).
[19:27:36.684] <TB3> INFO: Test took 1194ms.
[19:27:36.686] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:36.993] <TB3> INFO: Expecting 2560 events.
[19:27:37.877] <TB3> INFO: 2560 events read in total (293ms).
[19:27:37.878] <TB3> INFO: Test took 1192ms.
[19:27:37.880] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:38.185] <TB3> INFO: Expecting 2560 events.
[19:27:39.070] <TB3> INFO: 2560 events read in total (293ms).
[19:27:39.070] <TB3> INFO: Test took 1190ms.
[19:27:39.072] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:39.378] <TB3> INFO: Expecting 2560 events.
[19:27:40.262] <TB3> INFO: 2560 events read in total (292ms).
[19:27:40.263] <TB3> INFO: Test took 1191ms.
[19:27:40.265] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:40.571] <TB3> INFO: Expecting 2560 events.
[19:27:41.454] <TB3> INFO: 2560 events read in total (292ms).
[19:27:41.455] <TB3> INFO: Test took 1190ms.
[19:27:41.457] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:41.763] <TB3> INFO: Expecting 2560 events.
[19:27:42.648] <TB3> INFO: 2560 events read in total (293ms).
[19:27:42.648] <TB3> INFO: Test took 1191ms.
[19:27:42.651] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:42.956] <TB3> INFO: Expecting 2560 events.
[19:27:43.852] <TB3> INFO: 2560 events read in total (304ms).
[19:27:43.853] <TB3> INFO: Test took 1202ms.
[19:27:43.856] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:44.160] <TB3> INFO: Expecting 2560 events.
[19:27:45.054] <TB3> INFO: 2560 events read in total (302ms).
[19:27:45.054] <TB3> INFO: Test took 1199ms.
[19:27:45.059] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:45.362] <TB3> INFO: Expecting 2560 events.
[19:27:46.248] <TB3> INFO: 2560 events read in total (294ms).
[19:27:46.248] <TB3> INFO: Test took 1189ms.
[19:27:46.250] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:46.557] <TB3> INFO: Expecting 2560 events.
[19:27:47.441] <TB3> INFO: 2560 events read in total (292ms).
[19:27:47.442] <TB3> INFO: Test took 1192ms.
[19:27:47.445] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:47.753] <TB3> INFO: Expecting 2560 events.
[19:27:48.638] <TB3> INFO: 2560 events read in total (293ms).
[19:27:48.648] <TB3> INFO: Test took 1204ms.
[19:27:48.650] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:48.948] <TB3> INFO: Expecting 2560 events.
[19:27:49.837] <TB3> INFO: 2560 events read in total (297ms).
[19:27:49.837] <TB3> INFO: Test took 1187ms.
[19:27:49.839] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:50.146] <TB3> INFO: Expecting 2560 events.
[19:27:51.047] <TB3> INFO: 2560 events read in total (305ms).
[19:27:51.047] <TB3> INFO: Test took 1208ms.
[19:27:51.049] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:51.362] <TB3> INFO: Expecting 2560 events.
[19:27:52.248] <TB3> INFO: 2560 events read in total (294ms).
[19:27:52.248] <TB3> INFO: Test took 1199ms.
[19:27:52.251] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:52.557] <TB3> INFO: Expecting 2560 events.
[19:27:53.445] <TB3> INFO: 2560 events read in total (295ms).
[19:27:53.445] <TB3> INFO: Test took 1194ms.
[19:27:53.447] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:53.766] <TB3> INFO: Expecting 2560 events.
[19:27:54.677] <TB3> INFO: 2560 events read in total (291ms).
[19:27:54.677] <TB3> INFO: Test took 1230ms.
[19:27:54.679] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:54.986] <TB3> INFO: Expecting 2560 events.
[19:27:55.874] <TB3> INFO: 2560 events read in total (296ms).
[19:27:55.875] <TB3> INFO: Test took 1196ms.
[19:27:55.877] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:56.184] <TB3> INFO: Expecting 2560 events.
[19:27:57.079] <TB3> INFO: 2560 events read in total (303ms).
[19:27:57.080] <TB3> INFO: Test took 1203ms.
[19:27:57.083] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:57.389] <TB3> INFO: Expecting 2560 events.
[19:27:58.271] <TB3> INFO: 2560 events read in total (291ms).
[19:27:58.272] <TB3> INFO: Test took 1189ms.
[19:27:58.274] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:58.588] <TB3> INFO: Expecting 2560 events.
[19:27:59.480] <TB3> INFO: 2560 events read in total (290ms).
[19:27:59.481] <TB3> INFO: Test took 1207ms.
[19:27:59.483] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:27:59.791] <TB3> INFO: Expecting 2560 events.
[19:28:00.678] <TB3> INFO: 2560 events read in total (295ms).
[19:28:00.678] <TB3> INFO: Test took 1195ms.
[19:28:00.681] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:00.987] <TB3> INFO: Expecting 2560 events.
[19:28:01.877] <TB3> INFO: 2560 events read in total (298ms).
[19:28:01.877] <TB3> INFO: Test took 1196ms.
[19:28:01.881] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:02.186] <TB3> INFO: Expecting 2560 events.
[19:28:03.075] <TB3> INFO: 2560 events read in total (297ms).
[19:28:03.075] <TB3> INFO: Test took 1195ms.
[19:28:03.079] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:03.383] <TB3> INFO: Expecting 2560 events.
[19:28:04.276] <TB3> INFO: 2560 events read in total (301ms).
[19:28:04.277] <TB3> INFO: Test took 1199ms.
[19:28:04.280] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:04.585] <TB3> INFO: Expecting 2560 events.
[19:28:05.476] <TB3> INFO: 2560 events read in total (299ms).
[19:28:05.477] <TB3> INFO: Test took 1197ms.
[19:28:05.480] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:05.786] <TB3> INFO: Expecting 2560 events.
[19:28:06.681] <TB3> INFO: 2560 events read in total (304ms).
[19:28:06.681] <TB3> INFO: Test took 1201ms.
[19:28:06.684] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:06.989] <TB3> INFO: Expecting 2560 events.
[19:28:07.884] <TB3> INFO: 2560 events read in total (303ms).
[19:28:07.884] <TB3> INFO: Test took 1200ms.
[19:28:07.887] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:08.193] <TB3> INFO: Expecting 2560 events.
[19:28:09.091] <TB3> INFO: 2560 events read in total (306ms).
[19:28:09.091] <TB3> INFO: Test took 1204ms.
[19:28:09.094] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:09.400] <TB3> INFO: Expecting 2560 events.
[19:28:10.302] <TB3> INFO: 2560 events read in total (309ms).
[19:28:10.302] <TB3> INFO: Test took 1208ms.
[19:28:10.304] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:10.612] <TB3> INFO: Expecting 2560 events.
[19:28:11.520] <TB3> INFO: 2560 events read in total (303ms).
[19:28:11.520] <TB3> INFO: Test took 1216ms.
[19:28:11.523] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:28:11.828] <TB3> INFO: Expecting 2560 events.
[19:28:12.724] <TB3> INFO: 2560 events read in total (304ms).
[19:28:12.731] <TB3> INFO: Test took 1208ms.
[19:28:13.206] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 679 seconds
[19:28:13.206] <TB3> INFO: PH scale (per ROC): 59 55 49 53 49 49 50 57 51 55 58 52 44 71 62 55
[19:28:13.206] <TB3> INFO: PH offset (per ROC): 118 132 127 112 111 99 96 126 129 129 122 133 111 126 127 121
[19:28:13.213] <TB3> INFO: Decoding statistics:
[19:28:13.213] <TB3> INFO: General information:
[19:28:13.213] <TB3> INFO: 16bit words read: 127884
[19:28:13.213] <TB3> INFO: valid events total: 20480
[19:28:13.213] <TB3> INFO: empty events: 17978
[19:28:13.213] <TB3> INFO: valid events with pixels: 2502
[19:28:13.213] <TB3> INFO: valid pixel hits: 2502
[19:28:13.213] <TB3> INFO: Event errors: 0
[19:28:13.213] <TB3> INFO: start marker: 0
[19:28:13.213] <TB3> INFO: stop marker: 0
[19:28:13.213] <TB3> INFO: overflow: 0
[19:28:13.213] <TB3> INFO: invalid 5bit words: 0
[19:28:13.213] <TB3> INFO: invalid XOR eye diagram: 0
[19:28:13.213] <TB3> INFO: frame (failed synchr.): 0
[19:28:13.213] <TB3> INFO: idle data (no TBM trl): 0
[19:28:13.213] <TB3> INFO: no data (only TBM hdr): 0
[19:28:13.213] <TB3> INFO: TBM errors: 0
[19:28:13.213] <TB3> INFO: flawed TBM headers: 0
[19:28:13.213] <TB3> INFO: flawed TBM trailers: 0
[19:28:13.213] <TB3> INFO: event ID mismatches: 0
[19:28:13.213] <TB3> INFO: ROC errors: 0
[19:28:13.213] <TB3> INFO: missing ROC header(s): 0
[19:28:13.213] <TB3> INFO: misplaced readback start: 0
[19:28:13.213] <TB3> INFO: Pixel decoding errors: 0
[19:28:13.213] <TB3> INFO: pixel data incomplete: 0
[19:28:13.213] <TB3> INFO: pixel address: 0
[19:28:13.213] <TB3> INFO: pulse height fill bit: 0
[19:28:13.213] <TB3> INFO: buffer corruption: 0
[19:28:13.391] <TB3> INFO: ######################################################################
[19:28:13.392] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[19:28:13.392] <TB3> INFO: ######################################################################
[19:28:13.406] <TB3> INFO: scanning low vcal = 10
[19:28:13.652] <TB3> INFO: Expecting 41600 events.
[19:28:17.298] <TB3> INFO: 41600 events read in total (3053ms).
[19:28:17.298] <TB3> INFO: Test took 3891ms.
[19:28:17.300] <TB3> INFO: scanning low vcal = 20
[19:28:17.597] <TB3> INFO: Expecting 41600 events.
[19:28:21.228] <TB3> INFO: 41600 events read in total (3039ms).
[19:28:21.228] <TB3> INFO: Test took 3928ms.
[19:28:21.230] <TB3> INFO: scanning low vcal = 30
[19:28:21.545] <TB3> INFO: Expecting 41600 events.
[19:28:25.278] <TB3> INFO: 41600 events read in total (3141ms).
[19:28:25.281] <TB3> INFO: Test took 4049ms.
[19:28:25.283] <TB3> INFO: scanning low vcal = 40
[19:28:25.561] <TB3> INFO: Expecting 41600 events.
[19:28:29.604] <TB3> INFO: 41600 events read in total (3451ms).
[19:28:29.606] <TB3> INFO: Test took 4322ms.
[19:28:29.610] <TB3> INFO: scanning low vcal = 50
[19:28:29.897] <TB3> INFO: Expecting 41600 events.
[19:28:33.976] <TB3> INFO: 41600 events read in total (3486ms).
[19:28:33.978] <TB3> INFO: Test took 4367ms.
[19:28:33.982] <TB3> INFO: scanning low vcal = 60
[19:28:34.259] <TB3> INFO: Expecting 41600 events.
[19:28:38.317] <TB3> INFO: 41600 events read in total (3465ms).
[19:28:38.323] <TB3> INFO: Test took 4341ms.
[19:28:38.327] <TB3> INFO: scanning low vcal = 70
[19:28:38.605] <TB3> INFO: Expecting 41600 events.
[19:28:42.646] <TB3> INFO: 41600 events read in total (3446ms).
[19:28:42.647] <TB3> INFO: Test took 4319ms.
[19:28:42.651] <TB3> INFO: scanning low vcal = 80
[19:28:42.927] <TB3> INFO: Expecting 41600 events.
[19:28:47.015] <TB3> INFO: 41600 events read in total (3496ms).
[19:28:47.017] <TB3> INFO: Test took 4366ms.
[19:28:47.023] <TB3> INFO: scanning low vcal = 90
[19:28:47.297] <TB3> INFO: Expecting 41600 events.
[19:28:51.357] <TB3> INFO: 41600 events read in total (3468ms).
[19:28:51.358] <TB3> INFO: Test took 4335ms.
[19:28:51.362] <TB3> INFO: scanning low vcal = 100
[19:28:51.638] <TB3> INFO: Expecting 41600 events.
[19:28:55.647] <TB3> INFO: 41600 events read in total (3417ms).
[19:28:55.648] <TB3> INFO: Test took 4286ms.
[19:28:55.650] <TB3> INFO: scanning low vcal = 110
[19:28:55.928] <TB3> INFO: Expecting 41600 events.
[19:29:00.025] <TB3> INFO: 41600 events read in total (3505ms).
[19:29:00.026] <TB3> INFO: Test took 4375ms.
[19:29:00.029] <TB3> INFO: scanning low vcal = 120
[19:29:00.306] <TB3> INFO: Expecting 41600 events.
[19:29:04.411] <TB3> INFO: 41600 events read in total (3513ms).
[19:29:04.420] <TB3> INFO: Test took 4391ms.
[19:29:04.429] <TB3> INFO: scanning low vcal = 130
[19:29:04.700] <TB3> INFO: Expecting 41600 events.
[19:29:08.750] <TB3> INFO: 41600 events read in total (3459ms).
[19:29:08.751] <TB3> INFO: Test took 4320ms.
[19:29:08.755] <TB3> INFO: scanning low vcal = 140
[19:29:09.033] <TB3> INFO: Expecting 41600 events.
[19:29:13.094] <TB3> INFO: 41600 events read in total (3470ms).
[19:29:13.095] <TB3> INFO: Test took 4340ms.
[19:29:13.098] <TB3> INFO: scanning low vcal = 150
[19:29:13.375] <TB3> INFO: Expecting 41600 events.
[19:29:17.436] <TB3> INFO: 41600 events read in total (3470ms).
[19:29:17.437] <TB3> INFO: Test took 4339ms.
[19:29:17.451] <TB3> INFO: scanning low vcal = 160
[19:29:17.732] <TB3> INFO: Expecting 41600 events.
[19:29:21.768] <TB3> INFO: 41600 events read in total (3444ms).
[19:29:21.769] <TB3> INFO: Test took 4318ms.
[19:29:21.772] <TB3> INFO: scanning low vcal = 170
[19:29:22.052] <TB3> INFO: Expecting 41600 events.
[19:29:26.129] <TB3> INFO: 41600 events read in total (3485ms).
[19:29:26.130] <TB3> INFO: Test took 4358ms.
[19:29:26.137] <TB3> INFO: scanning low vcal = 180
[19:29:26.412] <TB3> INFO: Expecting 41600 events.
[19:29:30.477] <TB3> INFO: 41600 events read in total (3469ms).
[19:29:30.478] <TB3> INFO: Test took 4333ms.
[19:29:30.482] <TB3> INFO: scanning low vcal = 190
[19:29:30.759] <TB3> INFO: Expecting 41600 events.
[19:29:34.843] <TB3> INFO: 41600 events read in total (3493ms).
[19:29:34.845] <TB3> INFO: Test took 4362ms.
[19:29:34.848] <TB3> INFO: scanning low vcal = 200
[19:29:35.132] <TB3> INFO: Expecting 41600 events.
[19:29:39.153] <TB3> INFO: 41600 events read in total (3429ms).
[19:29:39.153] <TB3> INFO: Test took 4305ms.
[19:29:39.156] <TB3> INFO: scanning low vcal = 210
[19:29:39.434] <TB3> INFO: Expecting 41600 events.
[19:29:43.463] <TB3> INFO: 41600 events read in total (3438ms).
[19:29:43.474] <TB3> INFO: Test took 4317ms.
[19:29:43.478] <TB3> INFO: scanning low vcal = 220
[19:29:43.765] <TB3> INFO: Expecting 41600 events.
[19:29:47.819] <TB3> INFO: 41600 events read in total (3462ms).
[19:29:47.820] <TB3> INFO: Test took 4342ms.
[19:29:47.824] <TB3> INFO: scanning low vcal = 230
[19:29:48.105] <TB3> INFO: Expecting 41600 events.
[19:29:52.172] <TB3> INFO: 41600 events read in total (3475ms).
[19:29:52.190] <TB3> INFO: Test took 4366ms.
[19:29:52.194] <TB3> INFO: scanning low vcal = 240
[19:29:52.472] <TB3> INFO: Expecting 41600 events.
[19:29:56.529] <TB3> INFO: 41600 events read in total (3464ms).
[19:29:56.535] <TB3> INFO: Test took 4341ms.
[19:29:56.538] <TB3> INFO: scanning low vcal = 250
[19:29:56.819] <TB3> INFO: Expecting 41600 events.
[19:30:00.888] <TB3> INFO: 41600 events read in total (3478ms).
[19:30:00.890] <TB3> INFO: Test took 4352ms.
[19:30:00.903] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[19:30:01.179] <TB3> INFO: Expecting 41600 events.
[19:30:05.248] <TB3> INFO: 41600 events read in total (3475ms).
[19:30:05.249] <TB3> INFO: Test took 4346ms.
[19:30:05.253] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[19:30:05.529] <TB3> INFO: Expecting 41600 events.
[19:30:09.472] <TB3> INFO: 41600 events read in total (3351ms).
[19:30:09.473] <TB3> INFO: Test took 4220ms.
[19:30:09.476] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[19:30:09.752] <TB3> INFO: Expecting 41600 events.
[19:30:13.716] <TB3> INFO: 41600 events read in total (3372ms).
[19:30:13.717] <TB3> INFO: Test took 4240ms.
[19:30:13.721] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[19:30:14.043] <TB3> INFO: Expecting 41600 events.
[19:30:18.089] <TB3> INFO: 41600 events read in total (3454ms).
[19:30:18.090] <TB3> INFO: Test took 4369ms.
[19:30:18.093] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[19:30:18.370] <TB3> INFO: Expecting 41600 events.
[19:30:22.383] <TB3> INFO: 41600 events read in total (3421ms).
[19:30:22.384] <TB3> INFO: Test took 4291ms.
[19:30:22.800] <TB3> INFO: PixTestGainPedestal::measure() done
[19:31:13.182] <TB3> INFO: PixTestGainPedestal::fit() done
[19:31:13.182] <TB3> INFO: non-linearity mean: 0.984 0.983 0.981 0.967 0.952 0.952 0.918 0.985 0.981 0.982 0.983 0.973 0.932 0.987 0.983 0.980
[19:31:13.182] <TB3> INFO: non-linearity RMS: 0.004 0.003 0.004 0.012 0.068 0.053 0.140 0.004 0.004 0.003 0.003 0.004 0.132 0.003 0.004 0.004
[19:31:13.183] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[19:31:13.204] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[19:31:13.226] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[19:31:13.247] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[19:31:13.269] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[19:31:13.290] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[19:31:13.312] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[19:31:13.334] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[19:31:13.355] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[19:31:13.377] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[19:31:13.398] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[19:31:13.420] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[19:31:13.441] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[19:31:13.463] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[19:31:13.484] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[19:31:13.506] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1063_FullQualification_2016-10-24_16h14m_1477318445//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[19:31:13.527] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 180 seconds
[19:31:13.527] <TB3> INFO: Decoding statistics:
[19:31:13.527] <TB3> INFO: General information:
[19:31:13.527] <TB3> INFO: 16bit words read: 3327910
[19:31:13.527] <TB3> INFO: valid events total: 332800
[19:31:13.527] <TB3> INFO: empty events: 0
[19:31:13.527] <TB3> INFO: valid events with pixels: 332800
[19:31:13.527] <TB3> INFO: valid pixel hits: 665555
[19:31:13.527] <TB3> INFO: Event errors: 0
[19:31:13.527] <TB3> INFO: start marker: 0
[19:31:13.527] <TB3> INFO: stop marker: 0
[19:31:13.527] <TB3> INFO: overflow: 0
[19:31:13.527] <TB3> INFO: invalid 5bit words: 0
[19:31:13.528] <TB3> INFO: invalid XOR eye diagram: 0
[19:31:13.528] <TB3> INFO: frame (failed synchr.): 0
[19:31:13.528] <TB3> INFO: idle data (no TBM trl): 0
[19:31:13.528] <TB3> INFO: no data (only TBM hdr): 0
[19:31:13.528] <TB3> INFO: TBM errors: 0
[19:31:13.528] <TB3> INFO: flawed TBM headers: 0
[19:31:13.528] <TB3> INFO: flawed TBM trailers: 0
[19:31:13.528] <TB3> INFO: event ID mismatches: 0
[19:31:13.528] <TB3> INFO: ROC errors: 0
[19:31:13.528] <TB3> INFO: missing ROC header(s): 0
[19:31:13.528] <TB3> INFO: misplaced readback start: 0
[19:31:13.528] <TB3> INFO: Pixel decoding errors: 0
[19:31:13.528] <TB3> INFO: pixel data incomplete: 0
[19:31:13.528] <TB3> INFO: pixel address: 0
[19:31:13.528] <TB3> INFO: pulse height fill bit: 0
[19:31:13.528] <TB3> INFO: buffer corruption: 0
[19:31:13.549] <TB3> INFO: Decoding statistics:
[19:31:13.549] <TB3> INFO: General information:
[19:31:13.549] <TB3> INFO: 16bit words read: 3457330
[19:31:13.549] <TB3> INFO: valid events total: 353536
[19:31:13.549] <TB3> INFO: empty events: 18234
[19:31:13.549] <TB3> INFO: valid events with pixels: 335302
[19:31:13.549] <TB3> INFO: valid pixel hits: 668057
[19:31:13.549] <TB3> INFO: Event errors: 0
[19:31:13.549] <TB3> INFO: start marker: 0
[19:31:13.549] <TB3> INFO: stop marker: 0
[19:31:13.549] <TB3> INFO: overflow: 0
[19:31:13.549] <TB3> INFO: invalid 5bit words: 0
[19:31:13.549] <TB3> INFO: invalid XOR eye diagram: 0
[19:31:13.549] <TB3> INFO: frame (failed synchr.): 0
[19:31:13.549] <TB3> INFO: idle data (no TBM trl): 0
[19:31:13.549] <TB3> INFO: no data (only TBM hdr): 0
[19:31:13.549] <TB3> INFO: TBM errors: 0
[19:31:13.549] <TB3> INFO: flawed TBM headers: 0
[19:31:13.549] <TB3> INFO: flawed TBM trailers: 0
[19:31:13.549] <TB3> INFO: event ID mismatches: 0
[19:31:13.549] <TB3> INFO: ROC errors: 0
[19:31:13.549] <TB3> INFO: missing ROC header(s): 0
[19:31:13.549] <TB3> INFO: misplaced readback start: 0
[19:31:13.549] <TB3> INFO: Pixel decoding errors: 0
[19:31:13.549] <TB3> INFO: pixel data incomplete: 0
[19:31:13.549] <TB3> INFO: pixel address: 0
[19:31:13.549] <TB3> INFO: pulse height fill bit: 0
[19:31:13.549] <TB3> INFO: buffer corruption: 0
[19:31:13.550] <TB3> INFO: enter test to run
[19:31:13.550] <TB3> INFO: test: exit no parameter change
[19:31:13.687] <TB3> QUIET: Connection to board 126 closed.
[19:31:13.692] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud