Test Date: 2016-11-03 14:08
Analysis date: 2016-11-14 14:33
Logfile
LogfileView
[10:55:06.867] <TB1> INFO: *** Welcome to pxar ***
[10:55:06.867] <TB1> INFO: *** Today: 2016/11/14
[10:55:06.873] <TB1> INFO: *** Version: c8ba-dirty
[10:55:06.873] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C15.dat
[10:55:06.874] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//tbmParameters_C1b.dat
[10:55:06.874] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//defaultMaskFile.dat
[10:55:06.874] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters_C15.dat
[10:55:06.929] <TB1> INFO: clk: 4
[10:55:06.929] <TB1> INFO: ctr: 4
[10:55:06.929] <TB1> INFO: sda: 19
[10:55:06.929] <TB1> INFO: tin: 9
[10:55:06.929] <TB1> INFO: level: 15
[10:55:06.929] <TB1> INFO: triggerdelay: 0
[10:55:06.929] <TB1> QUIET: Instanciating API for pxar v2.1.0+875~gda35c4c
[10:55:06.929] <TB1> INFO: Log level: INFO
[10:55:06.938] <TB1> INFO: Found DTB DTB_WXBYFL
[10:55:06.948] <TB1> QUIET: Connection to board DTB_WXBYFL opened.
[10:55:06.950] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 153
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXBYFL
MAC address: 40D855118099
Hostname: pixelDTB153
Comment:
------------------------------------------------------
[10:55:06.952] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[10:55:08.435] <TB1> INFO: DUT info:
[10:55:08.435] <TB1> INFO: The DUT currently contains the following objects:
[10:55:08.435] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[10:55:08.435] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:55:08.435] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:55:08.435] <TB1> INFO: TBM Core alpha (2): 7 registers set
[10:55:08.435] <TB1> INFO: TBM Core beta (3): 7 registers set
[10:55:08.435] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[10:55:08.435] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.435] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:55:08.836] <TB1> INFO: enter 'restricted' command line mode
[10:55:08.836] <TB1> INFO: enter test to run
[10:55:08.836] <TB1> INFO: test: pretest no parameter change
[10:55:08.836] <TB1> INFO: running: pretest
[10:55:09.389] <TB1> INFO: ######################################################################
[10:55:09.389] <TB1> INFO: PixTestPretest::doTest()
[10:55:09.389] <TB1> INFO: ######################################################################
[10:55:09.391] <TB1> INFO: ----------------------------------------------------------------------
[10:55:09.391] <TB1> INFO: PixTestPretest::programROC()
[10:55:09.391] <TB1> INFO: ----------------------------------------------------------------------
[10:55:27.403] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[10:55:27.403] <TB1> INFO: IA differences per ROC: 18.5 18.5 20.9 18.5 20.1 18.5 19.3 16.9 18.5 19.3 19.3 19.3 22.5 21.7 20.9 20.9
[10:55:27.440] <TB1> INFO: ----------------------------------------------------------------------
[10:55:27.440] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[10:55:27.440] <TB1> INFO: ----------------------------------------------------------------------
[10:55:35.622] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 376.2 mA = 23.5125 mA/ROC
[10:55:35.622] <TB1> INFO: i(loss) [mA/ROC]: 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5 17.7 18.5 18.5 17.7 18.5 18.5
[10:55:35.650] <TB1> INFO: ----------------------------------------------------------------------
[10:55:35.650] <TB1> INFO: PixTestPretest::findTiming()
[10:55:35.650] <TB1> INFO: ----------------------------------------------------------------------
[10:55:35.650] <TB1> INFO: PixTestCmd::init()
[10:55:36.206] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[10:56:06.881] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[10:56:06.881] <TB1> INFO: (success/tries = 100/100), width = 4
[10:56:08.383] <TB1> INFO: ----------------------------------------------------------------------
[10:56:08.383] <TB1> INFO: PixTestPretest::findWorkingPixel()
[10:56:08.383] <TB1> INFO: ----------------------------------------------------------------------
[10:56:08.475] <TB1> INFO: Expecting 231680 events.
[10:56:18.114] <TB1> INFO: 231680 events read in total (9048ms).
[10:56:18.121] <TB1> INFO: Test took 9735ms.
[10:56:18.364] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[10:56:18.394] <TB1> INFO: ----------------------------------------------------------------------
[10:56:18.394] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[10:56:18.394] <TB1> INFO: ----------------------------------------------------------------------
[10:56:18.487] <TB1> INFO: Expecting 231680 events.
[10:56:28.093] <TB1> INFO: 231680 events read in total (9015ms).
[10:56:28.100] <TB1> INFO: Test took 9702ms.
[10:56:28.359] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[10:56:28.359] <TB1> INFO: CalDel: 96 105 117 94 97 87 89 78 107 119 87 93 95 111 97 90
[10:56:28.359] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 52 51 51 51 51 51 51 51 51
[10:56:28.362] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C0.dat
[10:56:28.362] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C1.dat
[10:56:28.362] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C2.dat
[10:56:28.362] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C3.dat
[10:56:28.362] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C4.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C5.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C6.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C7.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C8.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C9.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C10.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C11.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C12.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C13.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C14.dat
[10:56:28.363] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters_C15.dat
[10:56:28.363] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//tbmParameters_C0a.dat
[10:56:28.364] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//tbmParameters_C0b.dat
[10:56:28.364] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//tbmParameters_C1a.dat
[10:56:28.364] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//tbmParameters_C1b.dat
[10:56:28.364] <TB1> INFO: PixTestPretest::doTest() done, duration: 79 seconds
[10:56:28.461] <TB1> INFO: enter test to run
[10:56:28.461] <TB1> INFO: test: FullTest no parameter change
[10:56:28.461] <TB1> INFO: running: fulltest
[10:56:28.461] <TB1> INFO: ######################################################################
[10:56:28.461] <TB1> INFO: PixTestFullTest::doTest()
[10:56:28.461] <TB1> INFO: ######################################################################
[10:56:28.462] <TB1> INFO: ######################################################################
[10:56:28.462] <TB1> INFO: PixTestAlive::doTest()
[10:56:28.463] <TB1> INFO: ######################################################################
[10:56:28.464] <TB1> INFO: ----------------------------------------------------------------------
[10:56:28.464] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:56:28.464] <TB1> INFO: ----------------------------------------------------------------------
[10:56:28.740] <TB1> INFO: Expecting 41600 events.
[10:56:32.164] <TB1> INFO: 41600 events read in total (2833ms).
[10:56:32.165] <TB1> INFO: Test took 3700ms.
[10:56:32.392] <TB1> INFO: PixTestAlive::aliveTest() done
[10:56:32.392] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:56:32.393] <TB1> INFO: ----------------------------------------------------------------------
[10:56:32.393] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:56:32.393] <TB1> INFO: ----------------------------------------------------------------------
[10:56:32.630] <TB1> INFO: Expecting 41600 events.
[10:56:35.650] <TB1> INFO: 41600 events read in total (2428ms).
[10:56:35.650] <TB1> INFO: Test took 3254ms.
[10:56:35.650] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:56:35.887] <TB1> INFO: PixTestAlive::maskTest() done
[10:56:35.887] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:56:35.888] <TB1> INFO: ----------------------------------------------------------------------
[10:56:35.888] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:56:35.888] <TB1> INFO: ----------------------------------------------------------------------
[10:56:36.137] <TB1> INFO: Expecting 41600 events.
[10:56:39.824] <TB1> INFO: 41600 events read in total (3095ms).
[10:56:39.825] <TB1> INFO: Test took 3936ms.
[10:56:40.070] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[10:56:40.070] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:56:40.070] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[10:56:40.070] <TB1> INFO: Decoding statistics:
[10:56:40.070] <TB1> INFO: General information:
[10:56:40.070] <TB1> INFO: 16bit words read: 0
[10:56:40.070] <TB1> INFO: valid events total: 0
[10:56:40.070] <TB1> INFO: empty events: 0
[10:56:40.070] <TB1> INFO: valid events with pixels: 0
[10:56:40.070] <TB1> INFO: valid pixel hits: 0
[10:56:40.070] <TB1> INFO: Event errors: 0
[10:56:40.070] <TB1> INFO: start marker: 0
[10:56:40.070] <TB1> INFO: stop marker: 0
[10:56:40.070] <TB1> INFO: overflow: 0
[10:56:40.070] <TB1> INFO: invalid 5bit words: 0
[10:56:40.070] <TB1> INFO: invalid XOR eye diagram: 0
[10:56:40.070] <TB1> INFO: frame (failed synchr.): 0
[10:56:40.070] <TB1> INFO: idle data (no TBM trl): 0
[10:56:40.070] <TB1> INFO: no data (only TBM hdr): 0
[10:56:40.070] <TB1> INFO: TBM errors: 0
[10:56:40.070] <TB1> INFO: flawed TBM headers: 0
[10:56:40.070] <TB1> INFO: flawed TBM trailers: 0
[10:56:40.070] <TB1> INFO: event ID mismatches: 0
[10:56:40.070] <TB1> INFO: ROC errors: 0
[10:56:40.070] <TB1> INFO: missing ROC header(s): 0
[10:56:40.070] <TB1> INFO: misplaced readback start: 0
[10:56:40.070] <TB1> INFO: Pixel decoding errors: 0
[10:56:40.070] <TB1> INFO: pixel data incomplete: 0
[10:56:40.070] <TB1> INFO: pixel address: 0
[10:56:40.070] <TB1> INFO: pulse height fill bit: 0
[10:56:40.070] <TB1> INFO: buffer corruption: 0
[10:56:40.079] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C15.dat
[10:56:40.080] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr_C15.dat
[10:56:40.080] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[10:56:40.080] <TB1> INFO: ######################################################################
[10:56:40.080] <TB1> INFO: PixTestReadback::doTest()
[10:56:40.080] <TB1> INFO: ######################################################################
[10:56:40.080] <TB1> INFO: ----------------------------------------------------------------------
[10:56:40.080] <TB1> INFO: PixTestReadback::CalibrateVd()
[10:56:40.080] <TB1> INFO: ----------------------------------------------------------------------
[10:56:50.137] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C0.dat
[10:56:50.137] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C1.dat
[10:56:50.137] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C2.dat
[10:56:50.137] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C3.dat
[10:56:50.137] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C4.dat
[10:56:50.137] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C5.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C6.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C7.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C8.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C9.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C10.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C11.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C12.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C13.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C14.dat
[10:56:50.138] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C15.dat
[10:56:50.166] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[10:56:50.166] <TB1> INFO: ----------------------------------------------------------------------
[10:56:50.166] <TB1> INFO: PixTestReadback::CalibrateVa()
[10:56:50.166] <TB1> INFO: ----------------------------------------------------------------------
[10:57:00.174] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C0.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C1.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C2.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C3.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C4.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C5.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C6.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C7.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C8.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C9.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C10.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C11.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C12.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C13.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C14.dat
[10:57:00.175] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C15.dat
[10:57:00.204] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[10:57:00.204] <TB1> INFO: ----------------------------------------------------------------------
[10:57:00.204] <TB1> INFO: PixTestReadback::readbackVbg()
[10:57:00.204] <TB1> INFO: ----------------------------------------------------------------------
[10:57:07.885] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[10:57:07.891] <TB1> INFO: ----------------------------------------------------------------------
[10:57:07.891] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[10:57:07.891] <TB1> INFO: ----------------------------------------------------------------------
[10:57:07.891] <TB1> INFO: Vbg will be calibrated using Vd calibration
[10:57:07.891] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 159.2calibrated Vbg = 1.16022 :::*/*/*/*/
[10:57:07.891] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 155.9calibrated Vbg = 1.15567 :::*/*/*/*/
[10:57:07.891] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 161.4calibrated Vbg = 1.1591 :::*/*/*/*/
[10:57:07.891] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 149.7calibrated Vbg = 1.14832 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 152.2calibrated Vbg = 1.15337 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 158.7calibrated Vbg = 1.16947 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 151.3calibrated Vbg = 1.15622 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 148.5calibrated Vbg = 1.15729 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 155.2calibrated Vbg = 1.1562 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 156calibrated Vbg = 1.15799 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 153.7calibrated Vbg = 1.14564 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 155.2calibrated Vbg = 1.14858 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 160calibrated Vbg = 1.15175 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 149.4calibrated Vbg = 1.15511 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 153.6calibrated Vbg = 1.1549 :::*/*/*/*/
[10:57:07.892] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 151.8calibrated Vbg = 1.15709 :::*/*/*/*/
[10:57:07.893] <TB1> INFO: ----------------------------------------------------------------------
[10:57:07.893] <TB1> INFO: PixTestReadback::CalibrateIa()
[10:57:07.893] <TB1> INFO: ----------------------------------------------------------------------
[10:59:48.270] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C0.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C1.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C2.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C3.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C4.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C5.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C6.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C7.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C8.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C9.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C10.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C11.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C12.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C13.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C14.dat
[10:59:48.271] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//readbackCal_C15.dat
[10:59:48.299] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[10:59:48.300] <TB1> INFO: PixTestReadback::doTest() done
[10:59:48.300] <TB1> INFO: Decoding statistics:
[10:59:48.300] <TB1> INFO: General information:
[10:59:48.300] <TB1> INFO: 16bit words read: 1536
[10:59:48.300] <TB1> INFO: valid events total: 256
[10:59:48.300] <TB1> INFO: empty events: 256
[10:59:48.300] <TB1> INFO: valid events with pixels: 0
[10:59:48.300] <TB1> INFO: valid pixel hits: 0
[10:59:48.300] <TB1> INFO: Event errors: 0
[10:59:48.300] <TB1> INFO: start marker: 0
[10:59:48.300] <TB1> INFO: stop marker: 0
[10:59:48.300] <TB1> INFO: overflow: 0
[10:59:48.300] <TB1> INFO: invalid 5bit words: 0
[10:59:48.300] <TB1> INFO: invalid XOR eye diagram: 0
[10:59:48.300] <TB1> INFO: frame (failed synchr.): 0
[10:59:48.300] <TB1> INFO: idle data (no TBM trl): 0
[10:59:48.300] <TB1> INFO: no data (only TBM hdr): 0
[10:59:48.300] <TB1> INFO: TBM errors: 0
[10:59:48.300] <TB1> INFO: flawed TBM headers: 0
[10:59:48.300] <TB1> INFO: flawed TBM trailers: 0
[10:59:48.300] <TB1> INFO: event ID mismatches: 0
[10:59:48.300] <TB1> INFO: ROC errors: 0
[10:59:48.300] <TB1> INFO: missing ROC header(s): 0
[10:59:48.300] <TB1> INFO: misplaced readback start: 0
[10:59:48.300] <TB1> INFO: Pixel decoding errors: 0
[10:59:48.300] <TB1> INFO: pixel data incomplete: 0
[10:59:48.300] <TB1> INFO: pixel address: 0
[10:59:48.300] <TB1> INFO: pulse height fill bit: 0
[10:59:48.300] <TB1> INFO: buffer corruption: 0
[10:59:48.337] <TB1> INFO: ######################################################################
[10:59:48.337] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[10:59:48.337] <TB1> INFO: ######################################################################
[10:59:48.340] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[10:59:48.353] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[10:59:48.353] <TB1> INFO: run 1 of 1
[10:59:48.589] <TB1> INFO: Expecting 3120000 events.
[11:00:19.454] <TB1> INFO: 678385 events read in total (30274ms).
[11:00:31.876] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (114) != TBM ID (129)

[11:00:32.014] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 114 114 129 114 114 114 114 114

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

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

[11:00:32.014] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a076 8000 40e0 40e0 e022 c000

[11:00:32.014] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a070 80b1 4060 40e0 e022 c000

[11:00:32.014] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a071 80c0 4061 4061 e022 c000

[11:00:32.014] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4061 4061 e022 c000

[11:00:32.014] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a073 8040 40e0 40e1 266 21ef e022 c000

[11:00:32.014] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a074 80b1 40e0 40e0 e022 c000

[11:00:32.014] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a075 80c0 40c0 40c0 e022 c000

[11:00:51.996] <TB1> INFO: 1354420 events read in total (62816ms).
[11:01:04.384] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (53) != TBM ID (129)

[11:01:04.570] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 53 53 129 53 53 53 53 53

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

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

[11:01:04.572] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a039 80c0 40e0 4ca 2bef 40e0 4ca 2bef e022 c000

[11:01:04.572] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a033 8040 40c0 4ca 2bef 40c1 4ca 2bef e022 c000

[11:01:04.572] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a034 80b1 40e0 4ca 2bef 40e0 4ca 2bef e022 c000

[11:01:04.572] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4061 4061 2bef 40e0 4ca 2bef e022 c000

[11:01:04.572] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a036 8000 40c0 4ca 2bef 40e0 4ca 2bef e022 c000

[11:01:04.572] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a037 8040 40c0 4ca 2bef 40c0 4ca 2bef e022 c000

[11:01:04.572] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a038 80b1 40e1 4ca 2bef 40e1 4ca 2bef e022 c000

[11:01:23.079] <TB1> INFO: 2027190 events read in total (93899ms).
[11:01:35.481] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (55) != TBM ID (129)

[11:01:35.631] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 55 55 129 55 55 55 55 55

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

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

[11:01:35.640] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03b 8040 40e0 82e 2def 40e0 82e 2def e022 c000

[11:01:35.640] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a035 80c0 40c0 82e 2def 40c0 82e 2def e022 c000

[11:01:35.640] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a036 8000 40c0 82e 2def 40c0 82e 2def e022 c000

[11:01:35.640] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4061 4061 2def 40c0 82e 2def e022 c000

[11:01:35.640] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a038 80b1 40e1 82e 2def 40e1 82e 2def e022 c000

[11:01:35.640] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a039 80c0 40c0 82e 2def 40c0 82e 2def e022 c000

[11:01:35.640] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03a 8000 4060 82e 2def 40e0 82e 2def e022 c000

[11:01:55.781] <TB1> INFO: 2701205 events read in total (126601ms).
[11:02:03.583] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (22) != TBM ID (129)

[11:02:03.727] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 22 22 129 22 22 22 22 22

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

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

[11:02:03.728] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01a 8000 40c0 aa0 23ef 40c0 aa0 23ef e022 c000

[11:02:03.728] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a014 80b1 40c0 aa0 23ef 40c0 aa0 23ef e022 c000

[11:02:03.728] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a015 80c0 40c0 aa0 23ef 40e0 aa0 23ef e022 c000

[11:02:03.728] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4061 4061 23ef 40c0 aa0 23ef e022 c000

[11:02:03.728] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a017 8040 40c0 aa0 23ef 40c0 aa0 23ef e022 c000

[11:02:03.728] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a018 80b1 40c0 aa0 23ef 40c0 aa0 23ef e022 c000

[11:02:03.728] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a019 80c0 40c1 aa0 23ef 40c1 aa0 23ef e022 c000

[11:02:15.323] <TB1> INFO: 3120000 events read in total (146143ms).
[11:02:15.399] <TB1> INFO: Test took 147046ms.
[11:02:36.583] <TB1> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 168 seconds
[11:02:36.583] <TB1> INFO: number of dead bumps (per ROC): 0 2 1 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:02:36.583] <TB1> INFO: separation cut (per ROC): 105 105 105 108 107 108 106 115 101 104 103 104 111 100 107 113
[11:02:36.583] <TB1> INFO: Decoding statistics:
[11:02:36.583] <TB1> INFO: General information:
[11:02:36.583] <TB1> INFO: 16bit words read: 0
[11:02:36.583] <TB1> INFO: valid events total: 0
[11:02:36.583] <TB1> INFO: empty events: 0
[11:02:36.583] <TB1> INFO: valid events with pixels: 0
[11:02:36.583] <TB1> INFO: valid pixel hits: 0
[11:02:36.583] <TB1> INFO: Event errors: 0
[11:02:36.583] <TB1> INFO: start marker: 0
[11:02:36.583] <TB1> INFO: stop marker: 0
[11:02:36.584] <TB1> INFO: overflow: 0
[11:02:36.584] <TB1> INFO: invalid 5bit words: 0
[11:02:36.584] <TB1> INFO: invalid XOR eye diagram: 0
[11:02:36.584] <TB1> INFO: frame (failed synchr.): 0
[11:02:36.584] <TB1> INFO: idle data (no TBM trl): 0
[11:02:36.584] <TB1> INFO: no data (only TBM hdr): 0
[11:02:36.584] <TB1> INFO: TBM errors: 0
[11:02:36.584] <TB1> INFO: flawed TBM headers: 0
[11:02:36.584] <TB1> INFO: flawed TBM trailers: 0
[11:02:36.584] <TB1> INFO: event ID mismatches: 0
[11:02:36.584] <TB1> INFO: ROC errors: 0
[11:02:36.584] <TB1> INFO: missing ROC header(s): 0
[11:02:36.584] <TB1> INFO: misplaced readback start: 0
[11:02:36.584] <TB1> INFO: Pixel decoding errors: 0
[11:02:36.584] <TB1> INFO: pixel data incomplete: 0
[11:02:36.584] <TB1> INFO: pixel address: 0
[11:02:36.584] <TB1> INFO: pulse height fill bit: 0
[11:02:36.584] <TB1> INFO: buffer corruption: 0
[11:02:36.628] <TB1> INFO: ######################################################################
[11:02:36.628] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:02:36.628] <TB1> INFO: ######################################################################
[11:02:36.628] <TB1> INFO: ----------------------------------------------------------------------
[11:02:36.628] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:02:36.628] <TB1> INFO: ----------------------------------------------------------------------
[11:02:36.628] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[11:02:36.637] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[11:02:36.637] <TB1> INFO: run 1 of 1
[11:02:36.869] <TB1> INFO: Expecting 36608000 events.
[11:03:00.333] <TB1> INFO: 685850 events read in total (22873ms).
[11:03:23.578] <TB1> INFO: 1358000 events read in total (46118ms).
[11:03:47.417] <TB1> INFO: 2031550 events read in total (69957ms).
[11:04:10.727] <TB1> INFO: 2706150 events read in total (93267ms).
[11:04:33.807] <TB1> INFO: 3377600 events read in total (116347ms).
[11:04:57.142] <TB1> INFO: 4047700 events read in total (139682ms).
[11:05:20.688] <TB1> INFO: 4718350 events read in total (163228ms).
[11:05:43.942] <TB1> INFO: 5387600 events read in total (186482ms).
[11:06:07.412] <TB1> INFO: 6058150 events read in total (209952ms).
[11:06:30.664] <TB1> INFO: 6727600 events read in total (233204ms).
[11:06:54.078] <TB1> INFO: 7396900 events read in total (256618ms).
[11:07:17.057] <TB1> INFO: 8065400 events read in total (279597ms).
[11:07:40.543] <TB1> INFO: 8735050 events read in total (303083ms).
[11:08:03.722] <TB1> INFO: 9404350 events read in total (326262ms).
[11:08:26.952] <TB1> INFO: 10073850 events read in total (349492ms).
[11:08:50.301] <TB1> INFO: 10742200 events read in total (372841ms).
[11:09:13.285] <TB1> INFO: 11411150 events read in total (395825ms).
[11:09:36.688] <TB1> INFO: 12078000 events read in total (419228ms).
[11:09:59.312] <TB1> INFO: 12742400 events read in total (441852ms).
[11:10:22.448] <TB1> INFO: 13408700 events read in total (464988ms).
[11:10:45.768] <TB1> INFO: 14075200 events read in total (488308ms).
[11:11:08.576] <TB1> INFO: 14737800 events read in total (511116ms).
[11:11:31.467] <TB1> INFO: 15400500 events read in total (534007ms).
[11:11:54.428] <TB1> INFO: 16065200 events read in total (556968ms).
[11:12:17.613] <TB1> INFO: 16728700 events read in total (580153ms).
[11:12:40.879] <TB1> INFO: 17393500 events read in total (603419ms).
[11:13:04.178] <TB1> INFO: 18055300 events read in total (626718ms).
[11:13:27.806] <TB1> INFO: 18716850 events read in total (650346ms).
[11:13:50.882] <TB1> INFO: 19379200 events read in total (673422ms).
[11:14:14.590] <TB1> INFO: 20041550 events read in total (697130ms).
[11:14:37.827] <TB1> INFO: 20703350 events read in total (720367ms).
[11:15:00.775] <TB1> INFO: 21364050 events read in total (743315ms).
[11:15:23.907] <TB1> INFO: 22023550 events read in total (766447ms).
[11:15:47.279] <TB1> INFO: 22682300 events read in total (789819ms).
[11:16:10.465] <TB1> INFO: 23342450 events read in total (813005ms).
[11:16:33.780] <TB1> INFO: 24000000 events read in total (836320ms).
[11:16:57.113] <TB1> INFO: 24658000 events read in total (859653ms).
[11:17:19.985] <TB1> INFO: 25316050 events read in total (882525ms).
[11:17:43.037] <TB1> INFO: 25975350 events read in total (905577ms).
[11:18:06.191] <TB1> INFO: 26634500 events read in total (928731ms).
[11:18:29.375] <TB1> INFO: 27293950 events read in total (951915ms).
[11:18:52.571] <TB1> INFO: 27952850 events read in total (975111ms).
[11:19:14.961] <TB1> INFO: 28609050 events read in total (997501ms).
[11:19:38.085] <TB1> INFO: 29266500 events read in total (1020625ms).
[11:20:01.427] <TB1> INFO: 29923250 events read in total (1043967ms).
[11:20:24.478] <TB1> INFO: 30578550 events read in total (1067018ms).
[11:20:47.200] <TB1> INFO: 31235600 events read in total (1089740ms).
[11:21:09.974] <TB1> INFO: 31892000 events read in total (1112514ms).
[11:21:32.785] <TB1> INFO: 32549250 events read in total (1135325ms).
[11:21:55.695] <TB1> INFO: 33208900 events read in total (1158235ms).
[11:22:18.301] <TB1> INFO: 33868200 events read in total (1180841ms).
[11:22:41.370] <TB1> INFO: 34528850 events read in total (1203910ms).
[11:23:04.640] <TB1> INFO: 35186800 events read in total (1227180ms).
[11:23:27.778] <TB1> INFO: 35843800 events read in total (1250318ms).
[11:23:51.038] <TB1> INFO: 36512400 events read in total (1273578ms).
[11:23:54.534] <TB1> INFO: 36608000 events read in total (1277074ms).
[11:23:54.594] <TB1> INFO: Test took 1277956ms.
[11:23:54.992] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:23:56.651] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:23:58.120] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:23:59.636] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:01.075] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:02.601] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:04.037] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:05.488] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:06.949] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:08.392] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:09.858] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:11.913] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:13.831] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:15.704] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:17.245] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:18.748] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:24:20.433] <TB1> INFO: PixTestScurves::scurves() done
[11:24:20.434] <TB1> INFO: Vcal mean: 120.65 121.07 121.30 123.86 118.94 124.00 114.92 126.63 116.37 118.27 114.87 108.91 122.16 112.80 126.69 116.08
[11:24:20.434] <TB1> INFO: Vcal RMS: 5.85 5.44 6.20 6.22 5.74 6.14 5.03 6.03 5.29 7.23 5.22 5.31 6.21 5.71 6.11 5.53
[11:24:20.434] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1303 seconds
[11:24:20.434] <TB1> INFO: Decoding statistics:
[11:24:20.434] <TB1> INFO: General information:
[11:24:20.434] <TB1> INFO: 16bit words read: 0
[11:24:20.434] <TB1> INFO: valid events total: 0
[11:24:20.434] <TB1> INFO: empty events: 0
[11:24:20.434] <TB1> INFO: valid events with pixels: 0
[11:24:20.434] <TB1> INFO: valid pixel hits: 0
[11:24:20.434] <TB1> INFO: Event errors: 0
[11:24:20.434] <TB1> INFO: start marker: 0
[11:24:20.434] <TB1> INFO: stop marker: 0
[11:24:20.434] <TB1> INFO: overflow: 0
[11:24:20.434] <TB1> INFO: invalid 5bit words: 0
[11:24:20.434] <TB1> INFO: invalid XOR eye diagram: 0
[11:24:20.434] <TB1> INFO: frame (failed synchr.): 0
[11:24:20.434] <TB1> INFO: idle data (no TBM trl): 0
[11:24:20.434] <TB1> INFO: no data (only TBM hdr): 0
[11:24:20.434] <TB1> INFO: TBM errors: 0
[11:24:20.434] <TB1> INFO: flawed TBM headers: 0
[11:24:20.434] <TB1> INFO: flawed TBM trailers: 0
[11:24:20.434] <TB1> INFO: event ID mismatches: 0
[11:24:20.434] <TB1> INFO: ROC errors: 0
[11:24:20.434] <TB1> INFO: missing ROC header(s): 0
[11:24:20.434] <TB1> INFO: misplaced readback start: 0
[11:24:20.434] <TB1> INFO: Pixel decoding errors: 0
[11:24:20.434] <TB1> INFO: pixel data incomplete: 0
[11:24:20.434] <TB1> INFO: pixel address: 0
[11:24:20.434] <TB1> INFO: pulse height fill bit: 0
[11:24:20.434] <TB1> INFO: buffer corruption: 0
[11:24:20.521] <TB1> INFO: ######################################################################
[11:24:20.521] <TB1> INFO: PixTestTrim::doTest()
[11:24:20.521] <TB1> INFO: ######################################################################
[11:24:20.522] <TB1> INFO: ----------------------------------------------------------------------
[11:24:20.522] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[11:24:20.522] <TB1> INFO: ----------------------------------------------------------------------
[11:24:20.561] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[11:24:20.561] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:24:20.572] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:24:20.572] <TB1> INFO: run 1 of 1
[11:24:20.803] <TB1> INFO: Expecting 5025280 events.
[11:24:52.015] <TB1> INFO: 830656 events read in total (30617ms).
[11:25:22.463] <TB1> INFO: 1659160 events read in total (61066ms).
[11:25:53.240] <TB1> INFO: 2484216 events read in total (91842ms).
[11:26:23.888] <TB1> INFO: 3306944 events read in total (122490ms).
[11:26:54.041] <TB1> INFO: 4125168 events read in total (152643ms).
[11:27:24.371] <TB1> INFO: 4940704 events read in total (182973ms).
[11:27:27.948] <TB1> INFO: 5025280 events read in total (186550ms).
[11:27:27.988] <TB1> INFO: Test took 187416ms.
[11:27:45.403] <TB1> INFO: ROC 0 VthrComp = 118
[11:27:45.403] <TB1> INFO: ROC 1 VthrComp = 117
[11:27:45.403] <TB1> INFO: ROC 2 VthrComp = 114
[11:27:45.403] <TB1> INFO: ROC 3 VthrComp = 122
[11:27:45.403] <TB1> INFO: ROC 4 VthrComp = 121
[11:27:45.403] <TB1> INFO: ROC 5 VthrComp = 120
[11:27:45.404] <TB1> INFO: ROC 6 VthrComp = 112
[11:27:45.404] <TB1> INFO: ROC 7 VthrComp = 129
[11:27:45.404] <TB1> INFO: ROC 8 VthrComp = 112
[11:27:45.404] <TB1> INFO: ROC 9 VthrComp = 107
[11:27:45.406] <TB1> INFO: ROC 10 VthrComp = 112
[11:27:45.406] <TB1> INFO: ROC 11 VthrComp = 108
[11:27:45.407] <TB1> INFO: ROC 12 VthrComp = 128
[11:27:45.407] <TB1> INFO: ROC 13 VthrComp = 109
[11:27:45.407] <TB1> INFO: ROC 14 VthrComp = 125
[11:27:45.407] <TB1> INFO: ROC 15 VthrComp = 121
[11:27:45.651] <TB1> INFO: Expecting 41600 events.
[11:27:49.260] <TB1> INFO: 41600 events read in total (3018ms).
[11:27:49.261] <TB1> INFO: Test took 3852ms.
[11:27:49.273] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:27:49.273] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:27:49.285] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:27:49.285] <TB1> INFO: run 1 of 1
[11:27:49.563] <TB1> INFO: Expecting 5025280 events.
[11:28:16.307] <TB1> INFO: 591208 events read in total (26152ms).
[11:28:42.696] <TB1> INFO: 1181984 events read in total (52541ms).
[11:29:08.971] <TB1> INFO: 1772768 events read in total (78816ms).
[11:29:34.987] <TB1> INFO: 2363728 events read in total (104832ms).
[11:30:01.220] <TB1> INFO: 2952808 events read in total (131065ms).
[11:30:27.578] <TB1> INFO: 3540216 events read in total (157423ms).
[11:30:53.380] <TB1> INFO: 4126120 events read in total (183225ms).
[11:31:19.193] <TB1> INFO: 4711376 events read in total (209038ms).
[11:31:33.239] <TB1> INFO: 5025280 events read in total (223084ms).
[11:31:33.318] <TB1> INFO: Test took 224033ms.
[11:31:55.129] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 60.8434 for pixel 10/66 mean/min/max = 46.4603/31.9169/61.0038
[11:31:55.129] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 62.5163 for pixel 38/2 mean/min/max = 47.8345/33.1081/62.5609
[11:31:55.129] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 67.63 for pixel 4/18 mean/min/max = 49.5694/31.3896/67.7492
[11:31:55.130] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 61.8585 for pixel 16/67 mean/min/max = 46.9884/32.095/61.8818
[11:31:55.130] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 61.7547 for pixel 0/16 mean/min/max = 47.1439/32.4373/61.8505
[11:31:55.130] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 62.0234 for pixel 15/2 mean/min/max = 47.8771/33.6957/62.0586
[11:31:55.131] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 61.3204 for pixel 22/5 mean/min/max = 47.1505/32.6084/61.6926
[11:31:55.131] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 59.9329 for pixel 5/1 mean/min/max = 46.0996/32.2572/59.9421
[11:31:55.132] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 60.7273 for pixel 14/12 mean/min/max = 47.1199/33.434/60.8057
[11:31:55.132] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 70.4163 for pixel 0/77 mean/min/max = 52.066/33.6087/70.5232
[11:31:55.132] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 61.1823 for pixel 2/19 mean/min/max = 47.1934/33.197/61.1898
[11:31:55.133] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 61.7319 for pixel 3/74 mean/min/max = 48.3114/34.8004/61.8224
[11:31:55.133] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 58.9019 for pixel 23/4 mean/min/max = 44.991/31.0357/58.9462
[11:31:55.133] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 64.4453 for pixel 12/0 mean/min/max = 49.2005/33.6691/64.7318
[11:31:55.134] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 59.6472 for pixel 0/13 mean/min/max = 46.0332/32.3666/59.6997
[11:31:55.134] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 58.4397 for pixel 5/72 mean/min/max = 46.0202/33.6004/58.44
[11:31:55.134] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:31:55.223] <TB1> INFO: Expecting 411648 events.
[11:32:04.597] <TB1> INFO: 411648 events read in total (8782ms).
[11:32:04.603] <TB1> INFO: Expecting 411648 events.
[11:32:13.985] <TB1> INFO: 411648 events read in total (8979ms).
[11:32:13.994] <TB1> INFO: Expecting 411648 events.
[11:32:23.417] <TB1> INFO: 411648 events read in total (9020ms).
[11:32:23.429] <TB1> INFO: Expecting 411648 events.
[11:32:32.826] <TB1> INFO: 411648 events read in total (8994ms).
[11:32:32.847] <TB1> INFO: Expecting 411648 events.
[11:32:42.126] <TB1> INFO: 411648 events read in total (8876ms).
[11:32:42.146] <TB1> INFO: Expecting 411648 events.
[11:32:51.562] <TB1> INFO: 411648 events read in total (9013ms).
[11:32:51.582] <TB1> INFO: Expecting 411648 events.
[11:33:00.945] <TB1> INFO: 411648 events read in total (8961ms).
[11:33:00.978] <TB1> INFO: Expecting 411648 events.
[11:33:10.369] <TB1> INFO: 411648 events read in total (8988ms).
[11:33:10.394] <TB1> INFO: Expecting 411648 events.
[11:33:19.714] <TB1> INFO: 411648 events read in total (8917ms).
[11:33:19.740] <TB1> INFO: Expecting 411648 events.
[11:33:28.984] <TB1> INFO: 411648 events read in total (8841ms).
[11:33:29.028] <TB1> INFO: Expecting 411648 events.
[11:33:38.420] <TB1> INFO: 411648 events read in total (8989ms).
[11:33:38.470] <TB1> INFO: Expecting 411648 events.
[11:33:47.748] <TB1> INFO: 411648 events read in total (8875ms).
[11:33:47.799] <TB1> INFO: Expecting 411648 events.
[11:33:57.221] <TB1> INFO: 411648 events read in total (9019ms).
[11:33:57.277] <TB1> INFO: Expecting 411648 events.
[11:34:06.621] <TB1> INFO: 411648 events read in total (8941ms).
[11:34:06.661] <TB1> INFO: Expecting 411648 events.
[11:34:15.988] <TB1> INFO: 411648 events read in total (8924ms).
[11:34:16.054] <TB1> INFO: Expecting 411648 events.
[11:34:25.282] <TB1> INFO: 411648 events read in total (8825ms).
[11:34:25.347] <TB1> INFO: Test took 150213ms.
[11:34:25.996] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[11:34:26.008] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:34:26.008] <TB1> INFO: run 1 of 1
[11:34:26.266] <TB1> INFO: Expecting 5025280 events.
[11:34:52.937] <TB1> INFO: 590704 events read in total (26080ms).
[11:35:19.424] <TB1> INFO: 1180144 events read in total (52567ms).
[11:35:45.452] <TB1> INFO: 1769040 events read in total (78595ms).
[11:36:11.755] <TB1> INFO: 2356264 events read in total (104898ms).
[11:36:37.810] <TB1> INFO: 2946120 events read in total (130953ms).
[11:37:04.023] <TB1> INFO: 3536304 events read in total (157166ms).
[11:37:30.813] <TB1> INFO: 4131296 events read in total (183956ms).
[11:37:57.659] <TB1> INFO: 4726128 events read in total (210802ms).
[11:38:11.308] <TB1> INFO: 5025280 events read in total (224451ms).
[11:38:11.418] <TB1> INFO: Test took 225411ms.
[11:38:32.151] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 2.827454 .. 147.977227
[11:38:32.385] <TB1> INFO: Expecting 208000 events.
[11:38:42.246] <TB1> INFO: 208000 events read in total (9270ms).
[11:38:42.247] <TB1> INFO: Test took 10093ms.
[11:38:42.324] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 2 .. 157 (-1/-1) hits flags = 528 (plus default)
[11:38:42.336] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:38:42.336] <TB1> INFO: run 1 of 1
[11:38:42.577] <TB1> INFO: Expecting 5191680 events.
[11:39:08.002] <TB1> INFO: 583464 events read in total (25833ms).
[11:39:34.943] <TB1> INFO: 1166568 events read in total (51774ms).
[11:40:00.503] <TB1> INFO: 1749352 events read in total (77334ms).
[11:40:26.079] <TB1> INFO: 2331560 events read in total (102910ms).
[11:40:52.794] <TB1> INFO: 2914352 events read in total (129625ms).
[11:41:19.218] <TB1> INFO: 3496400 events read in total (156049ms).
[11:41:45.222] <TB1> INFO: 4078696 events read in total (182053ms).
[11:42:11.528] <TB1> INFO: 4660296 events read in total (208359ms).
[11:42:35.052] <TB1> INFO: 5191680 events read in total (231883ms).
[11:42:35.122] <TB1> INFO: Test took 232787ms.
[11:43:00.283] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 26.442985 .. 48.190993
[11:43:00.518] <TB1> INFO: Expecting 208000 events.
[11:43:10.556] <TB1> INFO: 208000 events read in total (9446ms).
[11:43:10.557] <TB1> INFO: Test took 10271ms.
[11:43:10.636] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 58 (-1/-1) hits flags = 528 (plus default)
[11:43:10.648] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:43:10.648] <TB1> INFO: run 1 of 1
[11:43:10.915] <TB1> INFO: Expecting 1431040 events.
[11:43:39.783] <TB1> INFO: 651224 events read in total (28277ms).
[11:44:07.340] <TB1> INFO: 1301664 events read in total (55834ms).
[11:44:13.042] <TB1> INFO: 1431040 events read in total (61537ms).
[11:44:13.081] <TB1> INFO: Test took 62434ms.
[11:44:28.591] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 23.041169 .. 47.097962
[11:44:28.913] <TB1> INFO: Expecting 208000 events.
[11:44:38.778] <TB1> INFO: 208000 events read in total (9273ms).
[11:44:38.779] <TB1> INFO: Test took 10185ms.
[11:44:38.843] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 13 .. 57 (-1/-1) hits flags = 528 (plus default)
[11:44:38.855] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:44:38.855] <TB1> INFO: run 1 of 1
[11:44:39.139] <TB1> INFO: Expecting 1497600 events.
[11:45:07.596] <TB1> INFO: 667464 events read in total (27865ms).
[11:45:36.154] <TB1> INFO: 1334024 events read in total (56423ms).
[11:45:43.343] <TB1> INFO: 1497600 events read in total (63612ms).
[11:45:43.373] <TB1> INFO: Test took 64518ms.
[11:45:55.811] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 22.606094 .. 44.408766
[11:45:56.046] <TB1> INFO: Expecting 208000 events.
[11:46:06.133] <TB1> INFO: 208000 events read in total (9495ms).
[11:46:06.133] <TB1> INFO: Test took 10319ms.
[11:46:06.182] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 12 .. 54 (-1/-1) hits flags = 528 (plus default)
[11:46:06.193] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:46:06.193] <TB1> INFO: run 1 of 1
[11:46:06.426] <TB1> INFO: Expecting 1431040 events.
[11:46:35.467] <TB1> INFO: 682864 events read in total (28449ms).
[11:47:03.981] <TB1> INFO: 1365464 events read in total (56963ms).
[11:47:07.166] <TB1> INFO: 1431040 events read in total (60148ms).
[11:47:07.200] <TB1> INFO: Test took 61006ms.
[11:47:18.675] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[11:47:18.676] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:47:18.687] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:47:18.687] <TB1> INFO: run 1 of 1
[11:47:18.919] <TB1> INFO: Expecting 1364480 events.
[11:47:47.815] <TB1> INFO: 667832 events read in total (28304ms).
[11:48:15.466] <TB1> INFO: 1335520 events read in total (55956ms).
[11:48:17.129] <TB1> INFO: 1364480 events read in total (57619ms).
[11:48:17.153] <TB1> INFO: Test took 58466ms.
[11:48:28.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C0.dat
[11:48:28.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C1.dat
[11:48:28.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C2.dat
[11:48:28.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C3.dat
[11:48:28.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C4.dat
[11:48:28.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C5.dat
[11:48:28.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C6.dat
[11:48:28.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C7.dat
[11:48:28.507] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C8.dat
[11:48:28.507] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C9.dat
[11:48:28.507] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C10.dat
[11:48:28.507] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C11.dat
[11:48:28.507] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C12.dat
[11:48:28.507] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C13.dat
[11:48:28.507] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C14.dat
[11:48:28.507] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C15.dat
[11:48:28.507] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C0.dat
[11:48:28.515] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C1.dat
[11:48:28.523] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C2.dat
[11:48:28.531] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C3.dat
[11:48:28.538] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C4.dat
[11:48:28.546] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C5.dat
[11:48:28.554] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C6.dat
[11:48:28.562] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C7.dat
[11:48:28.570] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C8.dat
[11:48:28.578] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C9.dat
[11:48:28.586] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C10.dat
[11:48:28.594] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C11.dat
[11:48:28.602] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C12.dat
[11:48:28.609] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C13.dat
[11:48:28.617] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C14.dat
[11:48:28.625] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//trimParameters35_C15.dat
[11:48:28.632] <TB1> INFO: PixTestTrim::trimTest() done
[11:48:28.632] <TB1> INFO: vtrim: 134 147 170 143 150 154 128 133 138 129 131 126 137 149 136 112
[11:48:28.632] <TB1> INFO: vthrcomp: 118 117 114 122 121 120 112 129 112 107 112 108 128 109 125 121
[11:48:28.632] <TB1> INFO: vcal mean: 34.97 35.03 34.97 35.00 34.99 35.00 35.05 35.01 34.97 35.01 34.95 35.03 35.00 35.05 34.95 34.98
[11:48:28.632] <TB1> INFO: vcal RMS: 1.15 1.32 1.27 1.18 1.18 1.17 1.10 1.05 1.22 1.22 1.16 1.04 1.08 1.12 1.17 1.01
[11:48:28.632] <TB1> INFO: bits mean: 10.11 9.82 9.71 9.99 9.79 9.88 9.34 9.59 10.00 8.53 9.56 9.08 10.56 9.52 9.83 9.17
[11:48:28.632] <TB1> INFO: bits RMS: 2.41 2.38 2.50 2.39 2.48 2.24 2.65 2.63 2.30 2.52 2.50 2.33 2.34 2.25 2.52 2.67
[11:48:28.640] <TB1> INFO: ----------------------------------------------------------------------
[11:48:28.640] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[11:48:28.640] <TB1> INFO: ----------------------------------------------------------------------
[11:48:28.643] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[11:48:28.657] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:48:28.657] <TB1> INFO: run 1 of 1
[11:48:28.889] <TB1> INFO: Expecting 4160000 events.
[11:49:02.398] <TB1> INFO: 761335 events read in total (32917ms).
[11:49:34.953] <TB1> INFO: 1515790 events read in total (65472ms).
[11:50:07.359] <TB1> INFO: 2262940 events read in total (97878ms).
[11:50:39.289] <TB1> INFO: 3004940 events read in total (129808ms).
[11:51:11.388] <TB1> INFO: 3743460 events read in total (161907ms).
[11:51:29.709] <TB1> INFO: 4160000 events read in total (180228ms).
[11:51:29.756] <TB1> INFO: Test took 181099ms.
[11:51:53.764] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 206 (-1/-1) hits flags = 528 (plus default)
[11:51:53.776] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:51:53.776] <TB1> INFO: run 1 of 1
[11:51:54.066] <TB1> INFO: Expecting 4305600 events.
[11:52:26.136] <TB1> INFO: 726140 events read in total (31479ms).
[11:52:57.590] <TB1> INFO: 1446885 events read in total (62933ms).
[11:53:28.785] <TB1> INFO: 2162150 events read in total (94128ms).
[11:53:59.846] <TB1> INFO: 2872540 events read in total (125189ms).
[11:54:31.115] <TB1> INFO: 3580125 events read in total (156458ms).
[11:55:02.728] <TB1> INFO: 4288680 events read in total (188071ms).
[11:55:03.854] <TB1> INFO: 4305600 events read in total (189197ms).
[11:55:03.925] <TB1> INFO: Test took 190149ms.
[11:55:29.265] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 188 (-1/-1) hits flags = 528 (plus default)
[11:55:29.274] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:55:29.274] <TB1> INFO: run 1 of 1
[11:55:29.507] <TB1> INFO: Expecting 3931200 events.
[11:56:02.507] <TB1> INFO: 752330 events read in total (32409ms).
[11:56:34.340] <TB1> INFO: 1497830 events read in total (64242ms).
[11:57:06.206] <TB1> INFO: 2235950 events read in total (96108ms).
[11:57:38.405] <TB1> INFO: 2968835 events read in total (128307ms).
[11:58:10.378] <TB1> INFO: 3698835 events read in total (160280ms).
[11:58:20.357] <TB1> INFO: 3931200 events read in total (170259ms).
[11:58:20.402] <TB1> INFO: Test took 171129ms.
[11:58:42.938] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 190 (-1/-1) hits flags = 528 (plus default)
[11:58:42.947] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:58:42.947] <TB1> INFO: run 1 of 1
[11:58:43.179] <TB1> INFO: Expecting 3972800 events.
[11:59:15.977] <TB1> INFO: 749250 events read in total (32207ms).
[11:59:47.900] <TB1> INFO: 1491805 events read in total (64130ms).
[12:00:19.286] <TB1> INFO: 2227365 events read in total (95516ms).
[12:00:50.831] <TB1> INFO: 2957375 events read in total (127061ms).
[12:01:22.434] <TB1> INFO: 3684640 events read in total (158664ms).
[12:01:35.241] <TB1> INFO: 3972800 events read in total (171471ms).
[12:01:35.289] <TB1> INFO: Test took 172341ms.
[12:01:59.827] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 190 (-1/-1) hits flags = 528 (plus default)
[12:01:59.837] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:01:59.837] <TB1> INFO: run 1 of 1
[12:02:00.075] <TB1> INFO: Expecting 3972800 events.
[12:02:32.000] <TB1> INFO: 749285 events read in total (32334ms).
[12:03:04.700] <TB1> INFO: 1491930 events read in total (64034ms).
[12:03:37.031] <TB1> INFO: 2227645 events read in total (96365ms).
[12:04:08.724] <TB1> INFO: 2957630 events read in total (128058ms).
[12:04:41.100] <TB1> INFO: 3685130 events read in total (160434ms).
[12:04:54.068] <TB1> INFO: 3972800 events read in total (173402ms).
[12:04:54.133] <TB1> INFO: Test took 174296ms.
[12:05:21.440] <TB1> INFO: PixTestTrim::trimBitTest() done
[12:05:21.441] <TB1> INFO: PixTestTrim::doTest() done, duration: 2460 seconds
[12:05:21.441] <TB1> INFO: Decoding statistics:
[12:05:21.441] <TB1> INFO: General information:
[12:05:21.441] <TB1> INFO: 16bit words read: 0
[12:05:21.441] <TB1> INFO: valid events total: 0
[12:05:21.441] <TB1> INFO: empty events: 0
[12:05:21.441] <TB1> INFO: valid events with pixels: 0
[12:05:21.441] <TB1> INFO: valid pixel hits: 0
[12:05:21.441] <TB1> INFO: Event errors: 0
[12:05:21.441] <TB1> INFO: start marker: 0
[12:05:21.441] <TB1> INFO: stop marker: 0
[12:05:21.441] <TB1> INFO: overflow: 0
[12:05:21.441] <TB1> INFO: invalid 5bit words: 0
[12:05:21.441] <TB1> INFO: invalid XOR eye diagram: 0
[12:05:21.441] <TB1> INFO: frame (failed synchr.): 0
[12:05:21.441] <TB1> INFO: idle data (no TBM trl): 0
[12:05:21.442] <TB1> INFO: no data (only TBM hdr): 0
[12:05:21.442] <TB1> INFO: TBM errors: 0
[12:05:21.442] <TB1> INFO: flawed TBM headers: 0
[12:05:21.442] <TB1> INFO: flawed TBM trailers: 0
[12:05:21.442] <TB1> INFO: event ID mismatches: 0
[12:05:21.442] <TB1> INFO: ROC errors: 0
[12:05:21.442] <TB1> INFO: missing ROC header(s): 0
[12:05:21.442] <TB1> INFO: misplaced readback start: 0
[12:05:21.442] <TB1> INFO: Pixel decoding errors: 0
[12:05:21.442] <TB1> INFO: pixel data incomplete: 0
[12:05:21.442] <TB1> INFO: pixel address: 0
[12:05:21.442] <TB1> INFO: pulse height fill bit: 0
[12:05:21.442] <TB1> INFO: buffer corruption: 0
[12:05:22.301] <TB1> INFO: ######################################################################
[12:05:22.302] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:05:22.302] <TB1> INFO: ######################################################################
[12:05:22.594] <TB1> INFO: Expecting 41600 events.
[12:05:26.113] <TB1> INFO: 41600 events read in total (2928ms).
[12:05:26.114] <TB1> INFO: Test took 3811ms.
[12:05:26.555] <TB1> INFO: Expecting 41600 events.
[12:05:30.045] <TB1> INFO: 41600 events read in total (2899ms).
[12:05:30.046] <TB1> INFO: Test took 3726ms.
[12:05:30.055] <TB1> INFO: Max pixel from chip 0 is [18 ,6] phvalue 114
[12:05:30.055] <TB1> INFO: Max pixel from chip 1 is [4 ,11] phvalue 54
[12:05:30.055] <TB1> INFO: Max pixel from chip 2 is [7 ,59] phvalue 189
[12:05:30.056] <TB1> INFO: Max pixel from chip 3 is [4 ,34] phvalue 161
[12:05:30.056] <TB1> INFO: Max pixel from chip 4 is [14 ,5] phvalue 144
[12:05:30.056] <TB1> INFO: Max pixel from chip 5 is [16 ,39] phvalue 191
[12:05:30.056] <TB1> INFO: Max pixel from chip 6 is [4 ,29] phvalue 80
[12:05:30.056] <TB1> INFO: Max pixel from chip 7 is [34 ,9] phvalue 174
[12:05:30.056] <TB1> INFO: Max pixel from chip 8 is [9 ,45] phvalue 57
[12:05:30.056] <TB1> INFO: Max pixel from chip 9 is [14 ,5] phvalue 94
[12:05:30.056] <TB1> INFO: Max pixel from chip 10 is [12 ,14] phvalue 89
[12:05:30.056] <TB1> INFO: Max pixel from chip 11 is [14 ,8] phvalue 166
[12:05:30.057] <TB1> INFO: Max pixel from chip 12 is [20 ,23] phvalue 68
[12:05:30.057] <TB1> INFO: Max pixel from chip 13 is [6 ,9] phvalue 67
[12:05:30.057] <TB1> INFO: Max pixel from chip 14 is [8 ,21] phvalue 149
[12:05:30.057] <TB1> INFO: Max pixel from chip 15 is [5 ,5] phvalue 108
[12:05:30.336] <TB1> INFO: Expecting 41600 events.
[12:05:33.827] <TB1> INFO: 41600 events read in total (2899ms).
[12:05:33.828] <TB1> INFO: Test took 3753ms.
[12:05:33.840] <TB1> INFO: Min pixel from chip 0 is [3 ,5] phvalue 255
[12:05:33.840] <TB1> INFO: Min pixel from chip 1 is [25 ,52] phvalue 252
[12:05:33.841] <TB1> INFO: Min pixel from chip 2 is [3 ,5] phvalue 255
[12:05:33.841] <TB1> INFO: Min pixel from chip 3 is [3 ,5] phvalue 255
[12:05:33.841] <TB1> INFO: Min pixel from chip 4 is [3 ,5] phvalue 255
[12:05:33.841] <TB1> INFO: Min pixel from chip 5 is [3 ,5] phvalue 255
[12:05:33.841] <TB1> INFO: Search for minph pixel failed in the fiducial region for chip 6, looking at the edges
[12:05:33.841] <TB1> INFO: min ph pixel determination failed on roc 6, setting pixel 0,0
[12:05:33.842] <TB1> INFO: Min pixel from chip 7 is [3 ,5] phvalue 255
[12:05:33.842] <TB1> INFO: Min pixel from chip 8 is [17 ,12] phvalue 235
[12:05:33.842] <TB1> INFO: Min pixel from chip 9 is [3 ,5] phvalue 255
[12:05:33.842] <TB1> INFO: Min pixel from chip 10 is [3 ,5] phvalue 255
[12:05:33.842] <TB1> INFO: Min pixel from chip 11 is [3 ,5] phvalue 255
[12:05:33.842] <TB1> INFO: Min pixel from chip 12 is [3 ,5] phvalue 255
[12:05:33.842] <TB1> INFO: Min pixel from chip 13 is [3 ,5] phvalue 255
[12:05:33.843] <TB1> INFO: Min pixel from chip 14 is [3 ,5] phvalue 255
[12:05:33.843] <TB1> INFO: Min pixel from chip 15 is [3 ,5] phvalue 255
[12:05:34.121] <TB1> INFO: Expecting 2560 events.
[12:05:35.009] <TB1> INFO: 2560 events read in total (296ms).
[12:05:35.009] <TB1> INFO: Test took 1164ms.
[12:05:35.317] <TB1> INFO: Expecting 2560 events.
[12:05:36.204] <TB1> INFO: 2560 events read in total (295ms).
[12:05:36.204] <TB1> INFO: Test took 1194ms.
[12:05:36.512] <TB1> INFO: Expecting 2560 events.
[12:05:37.399] <TB1> INFO: 2560 events read in total (295ms).
[12:05:37.400] <TB1> INFO: Test took 1195ms.
[12:05:37.707] <TB1> INFO: Expecting 2560 events.
[12:05:38.595] <TB1> INFO: 2560 events read in total (296ms).
[12:05:38.596] <TB1> INFO: Test took 1195ms.
[12:05:38.903] <TB1> INFO: Expecting 2560 events.
[12:05:39.787] <TB1> INFO: 2560 events read in total (292ms).
[12:05:39.787] <TB1> INFO: Test took 1191ms.
[12:05:40.094] <TB1> INFO: Expecting 2560 events.
[12:05:40.978] <TB1> INFO: 2560 events read in total (292ms).
[12:05:40.978] <TB1> INFO: Test took 1191ms.
[12:05:41.286] <TB1> INFO: Expecting 2560 events.
[12:05:42.167] <TB1> INFO: 2560 events read in total (290ms).
[12:05:42.167] <TB1> INFO: Test took 1189ms.
[12:05:42.475] <TB1> INFO: Expecting 2560 events.
[12:05:43.358] <TB1> INFO: 2560 events read in total (292ms).
[12:05:43.358] <TB1> INFO: Test took 1190ms.
[12:05:43.666] <TB1> INFO: Expecting 2560 events.
[12:05:44.549] <TB1> INFO: 2560 events read in total (292ms).
[12:05:44.549] <TB1> INFO: Test took 1190ms.
[12:05:44.857] <TB1> INFO: Expecting 2560 events.
[12:05:45.740] <TB1> INFO: 2560 events read in total (292ms).
[12:05:45.741] <TB1> INFO: Test took 1191ms.
[12:05:46.048] <TB1> INFO: Expecting 2560 events.
[12:05:46.931] <TB1> INFO: 2560 events read in total (291ms).
[12:05:46.931] <TB1> INFO: Test took 1190ms.
[12:05:47.240] <TB1> INFO: Expecting 2560 events.
[12:05:48.123] <TB1> INFO: 2560 events read in total (292ms).
[12:05:48.123] <TB1> INFO: Test took 1191ms.
[12:05:48.431] <TB1> INFO: Expecting 2560 events.
[12:05:49.315] <TB1> INFO: 2560 events read in total (293ms).
[12:05:49.315] <TB1> INFO: Test took 1192ms.
[12:05:49.622] <TB1> INFO: Expecting 2560 events.
[12:05:50.510] <TB1> INFO: 2560 events read in total (296ms).
[12:05:50.510] <TB1> INFO: Test took 1194ms.
[12:05:50.818] <TB1> INFO: Expecting 2560 events.
[12:05:51.706] <TB1> INFO: 2560 events read in total (297ms).
[12:05:51.706] <TB1> INFO: Test took 1195ms.
[12:05:52.013] <TB1> INFO: Expecting 2560 events.
[12:05:52.902] <TB1> INFO: 2560 events read in total (297ms).
[12:05:52.902] <TB1> INFO: Test took 1195ms.
[12:05:52.906] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:05:53.210] <TB1> INFO: Expecting 655360 events.
[12:06:08.090] <TB1> INFO: 655360 events read in total (14288ms).
[12:06:08.106] <TB1> INFO: Expecting 655360 events.
[12:06:22.871] <TB1> INFO: 655360 events read in total (14362ms).
[12:06:22.886] <TB1> INFO: Expecting 655360 events.
[12:06:37.337] <TB1> INFO: 655360 events read in total (14048ms).
[12:06:37.356] <TB1> INFO: Expecting 655360 events.
[12:06:51.824] <TB1> INFO: 655360 events read in total (14065ms).
[12:06:51.847] <TB1> INFO: Expecting 655360 events.
[12:07:06.466] <TB1> INFO: 655360 events read in total (14216ms).
[12:07:06.501] <TB1> INFO: Expecting 655360 events.
[12:07:21.015] <TB1> INFO: 655360 events read in total (14111ms).
[12:07:21.047] <TB1> INFO: Expecting 655360 events.
[12:07:35.631] <TB1> INFO: 655360 events read in total (14181ms).
[12:07:35.686] <TB1> INFO: Expecting 655360 events.
[12:07:50.264] <TB1> INFO: 655360 events read in total (14175ms).
[12:07:50.325] <TB1> INFO: Expecting 655360 events.
[12:08:04.762] <TB1> INFO: 655360 events read in total (14034ms).
[12:08:04.807] <TB1> INFO: Expecting 655360 events.
[12:08:19.223] <TB1> INFO: 655360 events read in total (14013ms).
[12:08:19.297] <TB1> INFO: Expecting 655360 events.
[12:08:33.905] <TB1> INFO: 655360 events read in total (14205ms).
[12:08:33.982] <TB1> INFO: Expecting 655360 events.
[12:08:48.365] <TB1> INFO: 655360 events read in total (13980ms).
[12:08:48.424] <TB1> INFO: Expecting 655360 events.
[12:09:02.859] <TB1> INFO: 655360 events read in total (14032ms).
[12:09:02.949] <TB1> INFO: Expecting 655360 events.
[12:09:17.530] <TB1> INFO: 655360 events read in total (14178ms).
[12:09:17.629] <TB1> INFO: Expecting 655360 events.
[12:09:32.285] <TB1> INFO: 655360 events read in total (14253ms).
[12:09:32.390] <TB1> INFO: Expecting 655360 events.
[12:09:46.879] <TB1> INFO: 655360 events read in total (14086ms).
[12:09:46.953] <TB1> INFO: Test took 234047ms.
[12:09:47.032] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:09:47.297] <TB1> INFO: Expecting 655360 events.
[12:10:01.539] <TB1> INFO: 655360 events read in total (13650ms).
[12:10:01.553] <TB1> INFO: Expecting 655360 events.
[12:10:15.956] <TB1> INFO: 655360 events read in total (14000ms).
[12:10:15.976] <TB1> INFO: Expecting 655360 events.
[12:10:30.302] <TB1> INFO: 655360 events read in total (13923ms).
[12:10:30.320] <TB1> INFO: Expecting 655360 events.
[12:10:44.798] <TB1> INFO: 655360 events read in total (14075ms).
[12:10:44.829] <TB1> INFO: Expecting 655360 events.
[12:10:59.143] <TB1> INFO: 655360 events read in total (13911ms).
[12:10:59.182] <TB1> INFO: Expecting 655360 events.
[12:11:13.647] <TB1> INFO: 655360 events read in total (14062ms).
[12:11:13.677] <TB1> INFO: Expecting 655360 events.
[12:11:27.770] <TB1> INFO: 655360 events read in total (13690ms).
[12:11:27.808] <TB1> INFO: Expecting 655360 events.
[12:11:41.824] <TB1> INFO: 655360 events read in total (13613ms).
[12:11:41.865] <TB1> INFO: Expecting 655360 events.
[12:11:56.328] <TB1> INFO: 655360 events read in total (14060ms).
[12:11:56.373] <TB1> INFO: Expecting 655360 events.
[12:12:10.699] <TB1> INFO: 655360 events read in total (13922ms).
[12:12:10.747] <TB1> INFO: Expecting 655360 events.
[12:12:25.031] <TB1> INFO: 655360 events read in total (13881ms).
[12:12:25.082] <TB1> INFO: Expecting 655360 events.
[12:12:39.369] <TB1> INFO: 655360 events read in total (13884ms).
[12:12:39.425] <TB1> INFO: Expecting 655360 events.
[12:12:53.799] <TB1> INFO: 655360 events read in total (13971ms).
[12:12:53.858] <TB1> INFO: Expecting 655360 events.
[12:13:08.184] <TB1> INFO: 655360 events read in total (13923ms).
[12:13:08.251] <TB1> INFO: Expecting 655360 events.
[12:13:22.386] <TB1> INFO: 655360 events read in total (13732ms).
[12:13:22.486] <TB1> INFO: Expecting 655360 events.
[12:13:37.082] <TB1> INFO: 655360 events read in total (14193ms).
[12:13:37.192] <TB1> INFO: Test took 230160ms.
[12:13:37.437] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.444] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:13:37.451] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:13:37.458] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:13:37.466] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.473] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.481] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.488] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:13:37.496] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.503] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.511] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:13:37.519] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.526] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:13:37.533] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:13:37.540] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:13:37.548] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[12:13:37.555] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.561] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:13:37.568] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:13:37.576] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:13:37.584] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[12:13:37.591] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[12:13:37.598] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[12:13:37.605] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[12:13:37.613] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[12:13:37.620] <TB1> INFO: safety margin for low PH: adding 9, margin is now 29
[12:13:37.627] <TB1> INFO: safety margin for low PH: adding 10, margin is now 30
[12:13:37.635] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.642] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:13:37.650] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.657] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.664] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.671] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.678] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:13:37.686] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.693] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:13:37.700] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:13:37.707] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:13:37.715] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.722] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:13:37.760] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C0.dat
[12:13:37.761] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C1.dat
[12:13:37.761] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C2.dat
[12:13:37.761] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C3.dat
[12:13:37.761] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C4.dat
[12:13:37.761] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C5.dat
[12:13:37.761] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C6.dat
[12:13:37.761] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C7.dat
[12:13:37.761] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C8.dat
[12:13:37.761] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C9.dat
[12:13:37.762] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C10.dat
[12:13:37.762] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C11.dat
[12:13:37.762] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C12.dat
[12:13:37.762] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C13.dat
[12:13:37.762] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C14.dat
[12:13:37.762] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//dacParameters35_C15.dat
[12:13:37.998] <TB1> INFO: Expecting 41600 events.
[12:13:41.194] <TB1> INFO: 41600 events read in total (2605ms).
[12:13:41.195] <TB1> INFO: Test took 3430ms.
[12:13:41.640] <TB1> INFO: Expecting 41600 events.
[12:13:44.643] <TB1> INFO: 41600 events read in total (2411ms).
[12:13:44.643] <TB1> INFO: Test took 3234ms.
[12:13:45.092] <TB1> INFO: Expecting 41600 events.
[12:13:48.200] <TB1> INFO: 41600 events read in total (2516ms).
[12:13:48.201] <TB1> INFO: Test took 3344ms.
[12:13:48.415] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:48.504] <TB1> INFO: Expecting 2560 events.
[12:13:49.391] <TB1> INFO: 2560 events read in total (296ms).
[12:13:49.391] <TB1> INFO: Test took 976ms.
[12:13:49.393] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:49.699] <TB1> INFO: Expecting 2560 events.
[12:13:50.583] <TB1> INFO: 2560 events read in total (292ms).
[12:13:50.584] <TB1> INFO: Test took 1191ms.
[12:13:50.585] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:50.892] <TB1> INFO: Expecting 2560 events.
[12:13:51.779] <TB1> INFO: 2560 events read in total (295ms).
[12:13:51.780] <TB1> INFO: Test took 1195ms.
[12:13:51.781] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:52.088] <TB1> INFO: Expecting 2560 events.
[12:13:52.970] <TB1> INFO: 2560 events read in total (290ms).
[12:13:52.971] <TB1> INFO: Test took 1190ms.
[12:13:52.973] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:53.279] <TB1> INFO: Expecting 2560 events.
[12:13:54.167] <TB1> INFO: 2560 events read in total (296ms).
[12:13:54.167] <TB1> INFO: Test took 1194ms.
[12:13:54.169] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:54.476] <TB1> INFO: Expecting 2560 events.
[12:13:55.363] <TB1> INFO: 2560 events read in total (296ms).
[12:13:55.363] <TB1> INFO: Test took 1194ms.
[12:13:55.365] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:55.671] <TB1> INFO: Expecting 2560 events.
[12:13:56.554] <TB1> INFO: 2560 events read in total (291ms).
[12:13:56.555] <TB1> INFO: Test took 1190ms.
[12:13:56.557] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:56.863] <TB1> INFO: Expecting 2560 events.
[12:13:57.747] <TB1> INFO: 2560 events read in total (292ms).
[12:13:57.747] <TB1> INFO: Test took 1190ms.
[12:13:57.749] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:58.055] <TB1> INFO: Expecting 2560 events.
[12:13:58.937] <TB1> INFO: 2560 events read in total (290ms).
[12:13:58.938] <TB1> INFO: Test took 1189ms.
[12:13:58.940] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:13:59.246] <TB1> INFO: Expecting 2560 events.
[12:14:00.126] <TB1> INFO: 2560 events read in total (288ms).
[12:14:00.126] <TB1> INFO: Test took 1186ms.
[12:14:00.128] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:00.435] <TB1> INFO: Expecting 2560 events.
[12:14:01.314] <TB1> INFO: 2560 events read in total (288ms).
[12:14:01.314] <TB1> INFO: Test took 1186ms.
[12:14:01.316] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:01.623] <TB1> INFO: Expecting 2560 events.
[12:14:02.502] <TB1> INFO: 2560 events read in total (288ms).
[12:14:02.502] <TB1> INFO: Test took 1186ms.
[12:14:02.504] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:02.810] <TB1> INFO: Expecting 2560 events.
[12:14:03.694] <TB1> INFO: 2560 events read in total (292ms).
[12:14:03.694] <TB1> INFO: Test took 1190ms.
[12:14:03.695] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:03.002] <TB1> INFO: Expecting 2560 events.
[12:14:04.882] <TB1> INFO: 2560 events read in total (289ms).
[12:14:04.882] <TB1> INFO: Test took 1187ms.
[12:14:04.884] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:05.190] <TB1> INFO: Expecting 2560 events.
[12:14:06.070] <TB1> INFO: 2560 events read in total (288ms).
[12:14:06.070] <TB1> INFO: Test took 1186ms.
[12:14:06.072] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:06.378] <TB1> INFO: Expecting 2560 events.
[12:14:07.255] <TB1> INFO: 2560 events read in total (285ms).
[12:14:07.255] <TB1> INFO: Test took 1183ms.
[12:14:07.257] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:07.564] <TB1> INFO: Expecting 2560 events.
[12:14:08.444] <TB1> INFO: 2560 events read in total (289ms).
[12:14:08.445] <TB1> INFO: Test took 1188ms.
[12:14:08.447] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:08.752] <TB1> INFO: Expecting 2560 events.
[12:14:09.636] <TB1> INFO: 2560 events read in total (292ms).
[12:14:09.636] <TB1> INFO: Test took 1189ms.
[12:14:09.638] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:09.945] <TB1> INFO: Expecting 2560 events.
[12:14:10.828] <TB1> INFO: 2560 events read in total (292ms).
[12:14:10.828] <TB1> INFO: Test took 1190ms.
[12:14:10.830] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:11.136] <TB1> INFO: Expecting 2560 events.
[12:14:12.019] <TB1> INFO: 2560 events read in total (291ms).
[12:14:12.019] <TB1> INFO: Test took 1189ms.
[12:14:12.021] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:12.328] <TB1> INFO: Expecting 2560 events.
[12:14:13.207] <TB1> INFO: 2560 events read in total (288ms).
[12:14:13.208] <TB1> INFO: Test took 1187ms.
[12:14:13.210] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:13.516] <TB1> INFO: Expecting 2560 events.
[12:14:14.395] <TB1> INFO: 2560 events read in total (287ms).
[12:14:14.395] <TB1> INFO: Test took 1185ms.
[12:14:14.397] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:14.703] <TB1> INFO: Expecting 2560 events.
[12:14:15.583] <TB1> INFO: 2560 events read in total (288ms).
[12:14:15.583] <TB1> INFO: Test took 1186ms.
[12:14:15.585] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:15.891] <TB1> INFO: Expecting 2560 events.
[12:14:16.772] <TB1> INFO: 2560 events read in total (289ms).
[12:14:16.772] <TB1> INFO: Test took 1188ms.
[12:14:16.774] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:17.080] <TB1> INFO: Expecting 2560 events.
[12:14:17.964] <TB1> INFO: 2560 events read in total (292ms).
[12:14:17.964] <TB1> INFO: Test took 1190ms.
[12:14:17.966] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:18.272] <TB1> INFO: Expecting 2560 events.
[12:14:19.157] <TB1> INFO: 2560 events read in total (293ms).
[12:14:19.157] <TB1> INFO: Test took 1191ms.
[12:14:19.159] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:19.465] <TB1> INFO: Expecting 2560 events.
[12:14:20.350] <TB1> INFO: 2560 events read in total (293ms).
[12:14:20.350] <TB1> INFO: Test took 1191ms.
[12:14:20.352] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:20.658] <TB1> INFO: Expecting 2560 events.
[12:14:21.542] <TB1> INFO: 2560 events read in total (292ms).
[12:14:21.542] <TB1> INFO: Test took 1190ms.
[12:14:21.544] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:21.851] <TB1> INFO: Expecting 2560 events.
[12:14:22.735] <TB1> INFO: 2560 events read in total (293ms).
[12:14:22.735] <TB1> INFO: Test took 1191ms.
[12:14:22.736] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:23.043] <TB1> INFO: Expecting 2560 events.
[12:14:23.931] <TB1> INFO: 2560 events read in total (296ms).
[12:14:23.932] <TB1> INFO: Test took 1196ms.
[12:14:23.933] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:24.240] <TB1> INFO: Expecting 2560 events.
[12:14:25.123] <TB1> INFO: 2560 events read in total (292ms).
[12:14:25.124] <TB1> INFO: Test took 1191ms.
[12:14:25.126] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:14:25.432] <TB1> INFO: Expecting 2560 events.
[12:14:26.316] <TB1> INFO: 2560 events read in total (293ms).
[12:14:26.316] <TB1> INFO: Test took 1190ms.
[12:14:26.775] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 544 seconds
[12:14:26.775] <TB1> INFO: PH scale (per ROC): 50 49 47 44 37 33 43 37 48 34 36 39 47 47 43 42
[12:14:26.775] <TB1> INFO: PH offset (per ROC): 109 127 90 90 95 81 114 85 129 107 108 90 117 119 95 107
[12:14:26.781] <TB1> INFO: Decoding statistics:
[12:14:26.781] <TB1> INFO: General information:
[12:14:26.781] <TB1> INFO: 16bit words read: 127890
[12:14:26.781] <TB1> INFO: valid events total: 20480
[12:14:26.781] <TB1> INFO: empty events: 17975
[12:14:26.781] <TB1> INFO: valid events with pixels: 2505
[12:14:26.781] <TB1> INFO: valid pixel hits: 2505
[12:14:26.781] <TB1> INFO: Event errors: 0
[12:14:26.781] <TB1> INFO: start marker: 0
[12:14:26.781] <TB1> INFO: stop marker: 0
[12:14:26.781] <TB1> INFO: overflow: 0
[12:14:26.781] <TB1> INFO: invalid 5bit words: 0
[12:14:26.781] <TB1> INFO: invalid XOR eye diagram: 0
[12:14:26.781] <TB1> INFO: frame (failed synchr.): 0
[12:14:26.781] <TB1> INFO: idle data (no TBM trl): 0
[12:14:26.781] <TB1> INFO: no data (only TBM hdr): 0
[12:14:26.781] <TB1> INFO: TBM errors: 0
[12:14:26.781] <TB1> INFO: flawed TBM headers: 0
[12:14:26.781] <TB1> INFO: flawed TBM trailers: 0
[12:14:26.781] <TB1> INFO: event ID mismatches: 0
[12:14:26.781] <TB1> INFO: ROC errors: 0
[12:14:26.781] <TB1> INFO: missing ROC header(s): 0
[12:14:26.781] <TB1> INFO: misplaced readback start: 0
[12:14:26.781] <TB1> INFO: Pixel decoding errors: 0
[12:14:26.781] <TB1> INFO: pixel data incomplete: 0
[12:14:26.781] <TB1> INFO: pixel address: 0
[12:14:26.781] <TB1> INFO: pulse height fill bit: 0
[12:14:26.781] <TB1> INFO: buffer corruption: 0
[12:14:27.049] <TB1> INFO: ######################################################################
[12:14:27.049] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:14:27.049] <TB1> INFO: ######################################################################
[12:14:27.062] <TB1> INFO: scanning low vcal = 10
[12:14:27.293] <TB1> INFO: Expecting 41600 events.
[12:14:30.863] <TB1> INFO: 41600 events read in total (2978ms).
[12:14:30.863] <TB1> INFO: Test took 3801ms.
[12:14:30.864] <TB1> INFO: scanning low vcal = 20
[12:14:31.164] <TB1> INFO: Expecting 41600 events.
[12:14:34.769] <TB1> INFO: 41600 events read in total (3013ms).
[12:14:34.770] <TB1> INFO: Test took 3906ms.
[12:14:34.773] <TB1> INFO: scanning low vcal = 30
[12:14:35.066] <TB1> INFO: Expecting 41600 events.
[12:14:38.763] <TB1> INFO: 41600 events read in total (3105ms).
[12:14:38.763] <TB1> INFO: Test took 3990ms.
[12:14:38.766] <TB1> INFO: scanning low vcal = 40
[12:14:39.044] <TB1> INFO: Expecting 41600 events.
[12:14:43.034] <TB1> INFO: 41600 events read in total (3399ms).
[12:14:43.035] <TB1> INFO: Test took 4269ms.
[12:14:43.038] <TB1> INFO: scanning low vcal = 50
[12:14:43.315] <TB1> INFO: Expecting 41600 events.
[12:14:47.293] <TB1> INFO: 41600 events read in total (3386ms).
[12:14:47.294] <TB1> INFO: Test took 4256ms.
[12:14:47.297] <TB1> INFO: scanning low vcal = 60
[12:14:47.573] <TB1> INFO: Expecting 41600 events.
[12:14:51.591] <TB1> INFO: 41600 events read in total (3426ms).
[12:14:51.592] <TB1> INFO: Test took 4295ms.
[12:14:51.595] <TB1> INFO: scanning low vcal = 70
[12:14:51.871] <TB1> INFO: Expecting 41600 events.
[12:14:55.863] <TB1> INFO: 41600 events read in total (3400ms).
[12:14:55.864] <TB1> INFO: Test took 4269ms.
[12:14:55.866] <TB1> INFO: scanning low vcal = 80
[12:14:56.143] <TB1> INFO: Expecting 41600 events.
[12:15:00.164] <TB1> INFO: 41600 events read in total (3429ms).
[12:15:00.165] <TB1> INFO: Test took 4299ms.
[12:15:00.168] <TB1> INFO: scanning low vcal = 90
[12:15:00.444] <TB1> INFO: Expecting 41600 events.
[12:15:04.418] <TB1> INFO: 41600 events read in total (3382ms).
[12:15:04.419] <TB1> INFO: Test took 4251ms.
[12:15:04.421] <TB1> INFO: scanning low vcal = 100
[12:15:04.698] <TB1> INFO: Expecting 41600 events.
[12:15:08.664] <TB1> INFO: 41600 events read in total (3374ms).
[12:15:08.664] <TB1> INFO: Test took 4242ms.
[12:15:08.667] <TB1> INFO: scanning low vcal = 110
[12:15:08.959] <TB1> INFO: Expecting 41600 events.
[12:15:12.917] <TB1> INFO: 41600 events read in total (3366ms).
[12:15:12.918] <TB1> INFO: Test took 4251ms.
[12:15:12.920] <TB1> INFO: scanning low vcal = 120
[12:15:13.197] <TB1> INFO: Expecting 41600 events.
[12:15:17.213] <TB1> INFO: 41600 events read in total (3425ms).
[12:15:17.214] <TB1> INFO: Test took 4293ms.
[12:15:17.217] <TB1> INFO: scanning low vcal = 130
[12:15:17.510] <TB1> INFO: Expecting 41600 events.
[12:15:21.525] <TB1> INFO: 41600 events read in total (3423ms).
[12:15:21.526] <TB1> INFO: Test took 4309ms.
[12:15:21.528] <TB1> INFO: scanning low vcal = 140
[12:15:21.823] <TB1> INFO: Expecting 41600 events.
[12:15:25.805] <TB1> INFO: 41600 events read in total (3391ms).
[12:15:25.805] <TB1> INFO: Test took 4277ms.
[12:15:25.808] <TB1> INFO: scanning low vcal = 150
[12:15:26.100] <TB1> INFO: Expecting 41600 events.
[12:15:30.116] <TB1> INFO: 41600 events read in total (3424ms).
[12:15:30.117] <TB1> INFO: Test took 4309ms.
[12:15:30.119] <TB1> INFO: scanning low vcal = 160
[12:15:30.396] <TB1> INFO: Expecting 41600 events.
[12:15:34.407] <TB1> INFO: 41600 events read in total (3419ms).
[12:15:34.408] <TB1> INFO: Test took 4288ms.
[12:15:34.410] <TB1> INFO: scanning low vcal = 170
[12:15:34.687] <TB1> INFO: Expecting 41600 events.
[12:15:38.652] <TB1> INFO: 41600 events read in total (3373ms).
[12:15:38.653] <TB1> INFO: Test took 4243ms.
[12:15:38.655] <TB1> INFO: scanning low vcal = 180
[12:15:38.931] <TB1> INFO: Expecting 41600 events.
[12:15:42.909] <TB1> INFO: 41600 events read in total (3386ms).
[12:15:42.910] <TB1> INFO: Test took 4255ms.
[12:15:42.913] <TB1> INFO: scanning low vcal = 190
[12:15:43.206] <TB1> INFO: Expecting 41600 events.
[12:15:47.200] <TB1> INFO: 41600 events read in total (3402ms).
[12:15:47.201] <TB1> INFO: Test took 4288ms.
[12:15:47.203] <TB1> INFO: scanning low vcal = 200
[12:15:47.480] <TB1> INFO: Expecting 41600 events.
[12:15:51.452] <TB1> INFO: 41600 events read in total (3380ms).
[12:15:51.453] <TB1> INFO: Test took 4249ms.
[12:15:51.455] <TB1> INFO: scanning low vcal = 210
[12:15:51.744] <TB1> INFO: Expecting 41600 events.
[12:15:55.767] <TB1> INFO: 41600 events read in total (3431ms).
[12:15:55.768] <TB1> INFO: Test took 4313ms.
[12:15:55.771] <TB1> INFO: scanning low vcal = 220
[12:15:56.048] <TB1> INFO: Expecting 41600 events.
[12:16:00.020] <TB1> INFO: 41600 events read in total (3381ms).
[12:16:00.020] <TB1> INFO: Test took 4249ms.
[12:16:00.023] <TB1> INFO: scanning low vcal = 230
[12:16:00.319] <TB1> INFO: Expecting 41600 events.
[12:16:04.319] <TB1> INFO: 41600 events read in total (3408ms).
[12:16:04.320] <TB1> INFO: Test took 4297ms.
[12:16:04.322] <TB1> INFO: scanning low vcal = 240
[12:16:04.599] <TB1> INFO: Expecting 41600 events.
[12:16:08.583] <TB1> INFO: 41600 events read in total (3393ms).
[12:16:08.584] <TB1> INFO: Test took 4262ms.
[12:16:08.586] <TB1> INFO: scanning low vcal = 250
[12:16:08.863] <TB1> INFO: Expecting 41600 events.
[12:16:12.839] <TB1> INFO: 41600 events read in total (3384ms).
[12:16:12.840] <TB1> INFO: Test took 4254ms.
[12:16:12.843] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[12:16:13.119] <TB1> INFO: Expecting 41600 events.
[12:16:17.144] <TB1> INFO: 41600 events read in total (3433ms).
[12:16:17.144] <TB1> INFO: Test took 4300ms.
[12:16:17.147] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[12:16:17.424] <TB1> INFO: Expecting 41600 events.
[12:16:21.429] <TB1> INFO: 41600 events read in total (3414ms).
[12:16:21.430] <TB1> INFO: Test took 4283ms.
[12:16:21.432] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[12:16:21.723] <TB1> INFO: Expecting 41600 events.
[12:16:25.702] <TB1> INFO: 41600 events read in total (3387ms).
[12:16:25.703] <TB1> INFO: Test took 4270ms.
[12:16:25.706] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[12:16:25.982] <TB1> INFO: Expecting 41600 events.
[12:16:29.989] <TB1> INFO: 41600 events read in total (3415ms).
[12:16:29.989] <TB1> INFO: Test took 4283ms.
[12:16:29.992] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:16:30.286] <TB1> INFO: Expecting 41600 events.
[12:16:34.340] <TB1> INFO: 41600 events read in total (3463ms).
[12:16:34.341] <TB1> INFO: Test took 4349ms.
[12:16:34.940] <TB1> INFO: PixTestGainPedestal::measure() done
[12:17:12.479] <TB1> INFO: PixTestGainPedestal::fit() done
[12:17:12.479] <TB1> INFO: non-linearity mean: 0.962 0.981 0.975 0.930 0.931 0.941 0.946 0.951 0.983 0.952 0.974 0.943 0.952 0.963 0.941 0.917
[12:17:12.479] <TB1> INFO: non-linearity RMS: 0.051 0.004 0.012 0.164 0.119 0.150 0.061 0.145 0.004 0.162 0.179 0.098 0.052 0.023 0.071 0.119
[12:17:12.479] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C0.dat
[12:17:12.493] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C1.dat
[12:17:12.507] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C2.dat
[12:17:12.526] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C3.dat
[12:17:12.547] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C4.dat
[12:17:12.568] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C5.dat
[12:17:12.590] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C6.dat
[12:17:12.605] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C7.dat
[12:17:12.619] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C8.dat
[12:17:12.632] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C9.dat
[12:17:12.645] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C10.dat
[12:17:12.659] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C11.dat
[12:17:12.672] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C12.dat
[12:17:12.685] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C13.dat
[12:17:12.699] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C14.dat
[12:17:12.712] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1068_FullQualification_2016-11-14_10h48m_1479116883//000_Fulltest_p17//phCalibrationFitErr35_C15.dat
[12:17:12.725] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 165 seconds
[12:17:12.725] <TB1> INFO: Decoding statistics:
[12:17:12.725] <TB1> INFO: General information:
[12:17:12.725] <TB1> INFO: 16bit words read: 3316596
[12:17:12.725] <TB1> INFO: valid events total: 332800
[12:17:12.725] <TB1> INFO: empty events: 38
[12:17:12.725] <TB1> INFO: valid events with pixels: 332762
[12:17:12.725] <TB1> INFO: valid pixel hits: 659898
[12:17:12.725] <TB1> INFO: Event errors: 0
[12:17:12.726] <TB1> INFO: start marker: 0
[12:17:12.726] <TB1> INFO: stop marker: 0
[12:17:12.726] <TB1> INFO: overflow: 0
[12:17:12.726] <TB1> INFO: invalid 5bit words: 0
[12:17:12.726] <TB1> INFO: invalid XOR eye diagram: 0
[12:17:12.726] <TB1> INFO: frame (failed synchr.): 0
[12:17:12.726] <TB1> INFO: idle data (no TBM trl): 0
[12:17:12.726] <TB1> INFO: no data (only TBM hdr): 0
[12:17:12.726] <TB1> INFO: TBM errors: 0
[12:17:12.726] <TB1> INFO: flawed TBM headers: 0
[12:17:12.726] <TB1> INFO: flawed TBM trailers: 0
[12:17:12.726] <TB1> INFO: event ID mismatches: 0
[12:17:12.726] <TB1> INFO: ROC errors: 0
[12:17:12.726] <TB1> INFO: missing ROC header(s): 0
[12:17:12.726] <TB1> INFO: misplaced readback start: 0
[12:17:12.726] <TB1> INFO: Pixel decoding errors: 0
[12:17:12.726] <TB1> INFO: pixel data incomplete: 0
[12:17:12.726] <TB1> INFO: pixel address: 0
[12:17:12.726] <TB1> INFO: pulse height fill bit: 0
[12:17:12.726] <TB1> INFO: buffer corruption: 0
[12:17:12.739] <TB1> INFO: Decoding statistics:
[12:17:12.739] <TB1> INFO: General information:
[12:17:12.739] <TB1> INFO: 16bit words read: 3446022
[12:17:12.739] <TB1> INFO: valid events total: 353536
[12:17:12.739] <TB1> INFO: empty events: 18269
[12:17:12.739] <TB1> INFO: valid events with pixels: 335267
[12:17:12.739] <TB1> INFO: valid pixel hits: 662403
[12:17:12.739] <TB1> INFO: Event errors: 0
[12:17:12.739] <TB1> INFO: start marker: 0
[12:17:12.739] <TB1> INFO: stop marker: 0
[12:17:12.739] <TB1> INFO: overflow: 0
[12:17:12.739] <TB1> INFO: invalid 5bit words: 0
[12:17:12.739] <TB1> INFO: invalid XOR eye diagram: 0
[12:17:12.739] <TB1> INFO: frame (failed synchr.): 0
[12:17:12.739] <TB1> INFO: idle data (no TBM trl): 0
[12:17:12.739] <TB1> INFO: no data (only TBM hdr): 0
[12:17:12.739] <TB1> INFO: TBM errors: 0
[12:17:12.739] <TB1> INFO: flawed TBM headers: 0
[12:17:12.739] <TB1> INFO: flawed TBM trailers: 0
[12:17:12.739] <TB1> INFO: event ID mismatches: 0
[12:17:12.739] <TB1> INFO: ROC errors: 0
[12:17:12.739] <TB1> INFO: missing ROC header(s): 0
[12:17:12.739] <TB1> INFO: misplaced readback start: 0
[12:17:12.739] <TB1> INFO: Pixel decoding errors: 0
[12:17:12.739] <TB1> INFO: pixel data incomplete: 0
[12:17:12.739] <TB1> INFO: pixel address: 0
[12:17:12.739] <TB1> INFO: pulse height fill bit: 0
[12:17:12.739] <TB1> INFO: buffer corruption: 0
[12:17:12.739] <TB1> INFO: enter test to run
[12:17:12.739] <TB1> INFO: test: exit no parameter change
[12:17:12.764] <TB1> QUIET: Connection to board 153 closed.
[12:17:12.765] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud