Test Date: 2016-10-26 12:02
Analysis date: 2016-10-26 17:22
Logfile
LogfileView
[12:53:57.271] <TB1> INFO: *** Welcome to pxar ***
[12:53:57.271] <TB1> INFO: *** Today: 2016/10/26
[12:53:57.278] <TB1> INFO: *** Version: c8ba-dirty
[12:53:57.278] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C15.dat
[12:53:57.278] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//tbmParameters_C1b.dat
[12:53:57.279] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//defaultMaskFile.dat
[12:53:57.279] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters_C15.dat
[12:53:57.380] <TB1> INFO: clk: 4
[12:53:57.380] <TB1> INFO: ctr: 4
[12:53:57.380] <TB1> INFO: sda: 19
[12:53:57.380] <TB1> INFO: tin: 9
[12:53:57.380] <TB1> INFO: level: 15
[12:53:57.380] <TB1> INFO: triggerdelay: 0
[12:53:57.380] <TB1> QUIET: Instanciating API for pxar v2.7.6+61~g7f4a123
[12:53:57.380] <TB1> INFO: Log level: INFO
[12:53:57.391] <TB1> INFO: Found DTB DTB_WXC03A
[12:53:57.402] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[12:53:57.404] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 154
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXC03A
MAC address: 40D85511809A
Hostname: pixelDTB154
Comment:
------------------------------------------------------
[12:53:57.406] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[12:53:58.963] <TB1> INFO: DUT info:
[12:53:58.963] <TB1> INFO: The DUT currently contains the following objects:
[12:53:58.963] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[12:53:58.963] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:53:58.963] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:53:58.963] <TB1> INFO: TBM Core alpha (2): 7 registers set
[12:53:58.963] <TB1> INFO: TBM Core beta (3): 7 registers set
[12:53:58.963] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[12:53:58.963] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.963] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:58.964] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:59.364] <TB1> INFO: enter 'restricted' command line mode
[12:53:59.364] <TB1> INFO: enter test to run
[12:53:59.364] <TB1> INFO: test: pretest no parameter change
[12:53:59.364] <TB1> INFO: running: pretest
[12:53:59.369] <TB1> INFO: ######################################################################
[12:53:59.369] <TB1> INFO: PixTestPretest::doTest()
[12:53:59.369] <TB1> INFO: ######################################################################
[12:53:59.370] <TB1> INFO: ----------------------------------------------------------------------
[12:53:59.370] <TB1> INFO: PixTestPretest::programROC()
[12:53:59.370] <TB1> INFO: ----------------------------------------------------------------------
[12:54:17.384] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[12:54:17.384] <TB1> INFO: IA differences per ROC: 21.7 16.9 20.1 20.9 17.7 20.1 20.1 21.7 19.3 20.1 21.7 19.3 20.9 20.1 20.1 19.3
[12:54:17.447] <TB1> INFO: ----------------------------------------------------------------------
[12:54:17.447] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[12:54:17.447] <TB1> INFO: ----------------------------------------------------------------------
[12:54:24.850] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 388.3 mA = 24.2687 mA/ROC
[12:54:24.850] <TB1> INFO: i(loss) [mA/ROC]: 20.1 19.3 19.3 19.3 18.5 19.3 19.3 19.3 19.3 18.5 19.3 18.5 19.3 19.3 18.5 19.3
[12:54:24.884] <TB1> INFO: ----------------------------------------------------------------------
[12:54:24.884] <TB1> INFO: PixTestPretest::findTiming()
[12:54:24.884] <TB1> INFO: ----------------------------------------------------------------------
[12:54:24.885] <TB1> INFO: PixTestCmd::init()
[12:54:25.460] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[12:54:57.249] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[12:54:57.249] <TB1> INFO: (success/tries = 100/100), width = 3
[12:54:58.760] <TB1> INFO: ----------------------------------------------------------------------
[12:54:58.760] <TB1> INFO: PixTestPretest::findWorkingPixel()
[12:54:58.760] <TB1> INFO: ----------------------------------------------------------------------
[12:54:58.855] <TB1> INFO: Expecting 231680 events.
[12:55:08.825] <TB1> INFO: 231680 events read in total (9378ms).
[12:55:08.834] <TB1> INFO: Test took 10069ms.
[12:55:09.081] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[12:55:09.117] <TB1> INFO: ----------------------------------------------------------------------
[12:55:09.117] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[12:55:09.117] <TB1> INFO: ----------------------------------------------------------------------
[12:55:09.213] <TB1> INFO: Expecting 231680 events.
[12:55:19.254] <TB1> INFO: 231680 events read in total (9449ms).
[12:55:19.263] <TB1> INFO: Test took 10140ms.
[12:55:19.522] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[12:55:19.522] <TB1> INFO: CalDel: 93 88 98 98 83 89 97 117 102 108 94 113 99 108 113 100
[12:55:19.522] <TB1> INFO: VthrComp: 51 51 51 51 51 54 51 51 51 51 52 51 51 51 55 51
[12:55:19.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C0.dat
[12:55:19.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C1.dat
[12:55:19.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C2.dat
[12:55:19.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C3.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C4.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C5.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C6.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C7.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C8.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C9.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C10.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C11.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C12.dat
[12:55:19.525] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C13.dat
[12:55:19.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C14.dat
[12:55:19.526] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters_C15.dat
[12:55:19.526] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//tbmParameters_C0a.dat
[12:55:19.526] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//tbmParameters_C0b.dat
[12:55:19.526] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//tbmParameters_C1a.dat
[12:55:19.526] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//tbmParameters_C1b.dat
[12:55:19.526] <TB1> INFO: PixTestPretest::doTest() done, duration: 80 seconds
[12:55:19.576] <TB1> INFO: enter test to run
[12:55:19.576] <TB1> INFO: test: FullTest no parameter change
[12:55:19.576] <TB1> INFO: running: fulltest
[12:55:19.576] <TB1> INFO: ######################################################################
[12:55:19.576] <TB1> INFO: PixTestFullTest::doTest()
[12:55:19.576] <TB1> INFO: ######################################################################
[12:55:19.577] <TB1> INFO: ######################################################################
[12:55:19.577] <TB1> INFO: PixTestAlive::doTest()
[12:55:19.577] <TB1> INFO: ######################################################################
[12:55:19.579] <TB1> INFO: ----------------------------------------------------------------------
[12:55:19.579] <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)
[12:55:19.579] <TB1> INFO: ----------------------------------------------------------------------
[12:55:19.862] <TB1> INFO: Expecting 41600 events.
[12:55:23.379] <TB1> INFO: 41600 events read in total (2926ms).
[12:55:23.380] <TB1> INFO: Test took 3800ms.
[12:55:23.614] <TB1> INFO: PixTestAlive::aliveTest() done
[12:55:23.614] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:55:23.616] <TB1> INFO: ----------------------------------------------------------------------
[12:55:23.616] <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)
[12:55:23.616] <TB1> INFO: ----------------------------------------------------------------------
[12:55:23.856] <TB1> INFO: Expecting 41600 events.
[12:55:26.869] <TB1> INFO: 41600 events read in total (2421ms).
[12:55:26.869] <TB1> INFO: Test took 3251ms.
[12:55:26.870] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[12:55:27.109] <TB1> INFO: PixTestAlive::maskTest() done
[12:55:27.109] <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
[12:55:27.110] <TB1> INFO: ----------------------------------------------------------------------
[12:55:27.110] <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)
[12:55:27.110] <TB1> INFO: ----------------------------------------------------------------------
[12:55:27.372] <TB1> INFO: Expecting 41600 events.
[12:55:30.909] <TB1> INFO: 41600 events read in total (2945ms).
[12:55:30.910] <TB1> INFO: Test took 3799ms.
[12:55:31.139] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[12:55:31.139] <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
[12:55:31.139] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[12:55:31.139] <TB1> INFO: Decoding statistics:
[12:55:31.139] <TB1> INFO: General information:
[12:55:31.139] <TB1> INFO: 16bit words read: 0
[12:55:31.139] <TB1> INFO: valid events total: 0
[12:55:31.139] <TB1> INFO: empty events: 0
[12:55:31.139] <TB1> INFO: valid events with pixels: 0
[12:55:31.139] <TB1> INFO: valid pixel hits: 0
[12:55:31.139] <TB1> INFO: Event errors: 0
[12:55:31.139] <TB1> INFO: start marker: 0
[12:55:31.139] <TB1> INFO: stop marker: 0
[12:55:31.139] <TB1> INFO: overflow: 0
[12:55:31.139] <TB1> INFO: invalid 5bit words: 0
[12:55:31.139] <TB1> INFO: invalid XOR eye diagram: 0
[12:55:31.139] <TB1> INFO: frame (failed synchr.): 0
[12:55:31.139] <TB1> INFO: idle data (no TBM trl): 0
[12:55:31.139] <TB1> INFO: no data (only TBM hdr): 0
[12:55:31.139] <TB1> INFO: TBM errors: 0
[12:55:31.140] <TB1> INFO: flawed TBM headers: 0
[12:55:31.140] <TB1> INFO: flawed TBM trailers: 0
[12:55:31.140] <TB1> INFO: event ID mismatches: 0
[12:55:31.140] <TB1> INFO: ROC errors: 0
[12:55:31.140] <TB1> INFO: missing ROC header(s): 0
[12:55:31.140] <TB1> INFO: misplaced readback start: 0
[12:55:31.140] <TB1> INFO: Pixel decoding errors: 0
[12:55:31.140] <TB1> INFO: pixel data incomplete: 0
[12:55:31.140] <TB1> INFO: pixel address: 0
[12:55:31.140] <TB1> INFO: pulse height fill bit: 0
[12:55:31.140] <TB1> INFO: buffer corruption: 0
[12:55:31.145] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C15.dat
[12:55:31.145] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[12:55:31.145] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[12:55:31.145] <TB1> INFO: ######################################################################
[12:55:31.145] <TB1> INFO: PixTestReadback::doTest()
[12:55:31.145] <TB1> INFO: ######################################################################
[12:55:31.145] <TB1> INFO: ----------------------------------------------------------------------
[12:55:31.145] <TB1> INFO: PixTestReadback::CalibrateVd()
[12:55:31.145] <TB1> INFO: ----------------------------------------------------------------------
[12:55:41.118] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C0.dat
[12:55:41.118] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C1.dat
[12:55:41.118] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C2.dat
[12:55:41.118] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C3.dat
[12:55:41.118] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C4.dat
[12:55:41.118] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C5.dat
[12:55:41.118] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C6.dat
[12:55:41.118] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C7.dat
[12:55:41.118] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C8.dat
[12:55:41.119] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C9.dat
[12:55:41.119] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C10.dat
[12:55:41.119] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C11.dat
[12:55:41.119] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C12.dat
[12:55:41.119] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C13.dat
[12:55:41.119] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C14.dat
[12:55:41.119] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C15.dat
[12:55:41.150] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[12:55:41.150] <TB1> INFO: ----------------------------------------------------------------------
[12:55:41.150] <TB1> INFO: PixTestReadback::CalibrateVa()
[12:55:41.150] <TB1> INFO: ----------------------------------------------------------------------
[12:55:51.083] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C0.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C1.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C2.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C3.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C4.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C5.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C6.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C7.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C8.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C9.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C10.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C11.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C12.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C13.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C14.dat
[12:55:51.084] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C15.dat
[12:55:51.113] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[12:55:51.113] <TB1> INFO: ----------------------------------------------------------------------
[12:55:51.113] <TB1> INFO: PixTestReadback::readbackVbg()
[12:55:51.113] <TB1> INFO: ----------------------------------------------------------------------
[12:55:58.779] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[12:55:58.779] <TB1> INFO: ----------------------------------------------------------------------
[12:55:58.779] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[12:55:58.779] <TB1> INFO: ----------------------------------------------------------------------
[12:55:58.779] <TB1> INFO: Vbg will be calibrated using Vd calibration
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 164.5calibrated Vbg = 1.17922 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 145.3calibrated Vbg = 1.18574 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 156calibrated Vbg = 1.17613 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 165.9calibrated Vbg = 1.1759 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 156.2calibrated Vbg = 1.17139 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 150.2calibrated Vbg = 1.17458 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 158.4calibrated Vbg = 1.17946 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 151.6calibrated Vbg = 1.18545 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 150.1calibrated Vbg = 1.17431 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 157.6calibrated Vbg = 1.17519 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 153.8calibrated Vbg = 1.16887 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 157.7calibrated Vbg = 1.17049 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 147.7calibrated Vbg = 1.16939 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 147.2calibrated Vbg = 1.17686 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 150.1calibrated Vbg = 1.18257 :::*/*/*/*/
[12:55:58.779] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 153.9calibrated Vbg = 1.17703 :::*/*/*/*/
[12:55:58.782] <TB1> INFO: ----------------------------------------------------------------------
[12:55:58.782] <TB1> INFO: PixTestReadback::CalibrateIa()
[12:55:58.782] <TB1> INFO: ----------------------------------------------------------------------
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C0.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C1.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C2.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C3.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C4.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C5.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C6.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C7.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C8.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C9.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C10.dat
[12:58:39.621] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C11.dat
[12:58:39.622] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C12.dat
[12:58:39.622] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C13.dat
[12:58:39.622] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C14.dat
[12:58:39.622] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//readbackCal_C15.dat
[12:58:39.654] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[12:58:39.656] <TB1> INFO: PixTestReadback::doTest() done
[12:58:39.656] <TB1> INFO: Decoding statistics:
[12:58:39.656] <TB1> INFO: General information:
[12:58:39.656] <TB1> INFO: 16bit words read: 1536
[12:58:39.656] <TB1> INFO: valid events total: 256
[12:58:39.656] <TB1> INFO: empty events: 256
[12:58:39.656] <TB1> INFO: valid events with pixels: 0
[12:58:39.656] <TB1> INFO: valid pixel hits: 0
[12:58:39.656] <TB1> INFO: Event errors: 0
[12:58:39.656] <TB1> INFO: start marker: 0
[12:58:39.656] <TB1> INFO: stop marker: 0
[12:58:39.656] <TB1> INFO: overflow: 0
[12:58:39.656] <TB1> INFO: invalid 5bit words: 0
[12:58:39.656] <TB1> INFO: invalid XOR eye diagram: 0
[12:58:39.656] <TB1> INFO: frame (failed synchr.): 0
[12:58:39.656] <TB1> INFO: idle data (no TBM trl): 0
[12:58:39.656] <TB1> INFO: no data (only TBM hdr): 0
[12:58:39.656] <TB1> INFO: TBM errors: 0
[12:58:39.656] <TB1> INFO: flawed TBM headers: 0
[12:58:39.656] <TB1> INFO: flawed TBM trailers: 0
[12:58:39.656] <TB1> INFO: event ID mismatches: 0
[12:58:39.656] <TB1> INFO: ROC errors: 0
[12:58:39.656] <TB1> INFO: missing ROC header(s): 0
[12:58:39.656] <TB1> INFO: misplaced readback start: 0
[12:58:39.656] <TB1> INFO: Pixel decoding errors: 0
[12:58:39.656] <TB1> INFO: pixel data incomplete: 0
[12:58:39.656] <TB1> INFO: pixel address: 0
[12:58:39.656] <TB1> INFO: pulse height fill bit: 0
[12:58:39.656] <TB1> INFO: buffer corruption: 0
[12:58:39.710] <TB1> INFO: ######################################################################
[12:58:39.710] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[12:58:39.710] <TB1> INFO: ######################################################################
[12:58:39.713] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[12:58:39.735] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:58:39.735] <TB1> INFO: run 1 of 1
[12:58:39.974] <TB1> INFO: Expecting 3120000 events.
[12:59:11.566] <TB1> INFO: 665665 events read in total (31000ms).
[12:59:23.708] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (194) != TBM ID (129)

[12:59:23.850] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 194 194 129 194 194 194 194 194

[12:59:23.850] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (195)

[12:59:23.851] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[12:59:23.851] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c6 8000 4030 4030 260 2fef e022 c000

[12:59:23.851] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c0 80b1 4030 4030 260 2fef e022 c000

[12:59:23.851] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c1 80c0 4831 4831 260 2fef e022 c000

[12:59:23.851] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4831 4831 2fed 4830 260 2fef e022 c000

[12:59:23.851] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c3 8040 4030 4031 260 2fef e022 c000

[12:59:23.851] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c4 80b1 4030 260 2fee 4030 260 2fef e022 c000

[12:59:23.851] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c5 80c0 4030 260 2fef 4030 260 2fef e022 c000

[12:59:41.662] <TB1> INFO: 1325680 events read in total (61096ms).
[12:59:53.750] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (241) != TBM ID (129)

[12:59:53.888] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 241 241 129 241 241 241 241 241

[12:59:53.888] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (242)

[12:59:53.890] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[12:59:53.890] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f5 80c0 4830 4830 e022 c000

[12:59:53.890] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ef 8040 4032 4032 e022 c000

[12:59:53.890] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f0 80b1 4030 4030 4c0 2fef e022 c000

[12:59:53.890] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4831 4831 e022 c000

[12:59:53.890] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f2 8000 4030 4030 4c0 2fef e022 c000

[12:59:53.890] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f3 8040 4030 4031 e022 c000

[12:59:53.890] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f4 80b1 4030 4030 e022 c000

[13:00:11.704] <TB1> INFO: 1982995 events read in total (91138ms).
[13:00:23.830] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (148) != TBM ID (129)

[13:00:23.973] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 148 148 129 148 148 148 148 148

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

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

[13:00:23.973] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a098 80b1 4031 820 27ef 4071 e022 c000

[13:00:23.973] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a092 8000 4030 820 27ef 4030 e022 c000

[13:00:23.973] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a093 8040 4030 820 27ef 4031 e022 c000

[13:00:23.973] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4831 4831 27ef 4030 e022 c000

[13:00:23.973] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a095 80c0 4030 820 27ef 4030 e022 c000

[13:00:23.973] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a096 8000 4030 820 27ef 4070 e022 c000

[13:00:23.973] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a097 8040 4030 820 27ef 4070 e022 c000

[13:00:41.763] <TB1> INFO: 2642670 events read in total (121197ms).
[13:00:50.633] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (111) != TBM ID (129)

[13:00:50.776] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 111 111 129 111 111 111 111 111

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

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

[13:00:50.776] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a073 8040 4030 a80 27ef 4031 a80 27ef e022 c000

[13:00:50.776] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06d 80c0 4030 4030 a80 27ef e022 c000

[13:00:50.776] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06e 8000 4030 4030 a80 27ef e022 c000

[13:00:50.776] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4831 4831 27ef 4033 a80 27ef e022 c000

[13:00:50.776] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a070 80b1 4030 a80 27ef 4030 a80 27ef e022 c000

[13:00:50.776] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a071 80c0 4031 4031 a80 27ef e022 c000

[13:00:50.776] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a072 8000 4030 a80 27ef 4030 a80 27ef e022 c000

[13:00:50.779] <TB1> WARNING: Channel 0 ROC 0: Readback start marker after 32 readouts!

[13:00:50.779] <TB1> WARNING: Channel 0 ROC 1: Readback start marker after 32 readouts!

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

[13:00:50.779] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a082 8000 4030 a80 27ef 4030 a80 27ef e022 c000

[13:00:50.779] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07c 80b1 4030 a80 27ef 4030 a80 27ef e022 c000

[13:00:50.779] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07d 80c0 4031 4031 a80 27ef e022 c000

[13:00:50.779] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07e 8000 4030 a80 27ef 4030 a80 27ef e022 c000

[13:00:50.779] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07f 8040 4032 a80 27ef 4032 a80 27ef e022 c000

[13:00:50.779] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a080 80b1 4030 a80 27ef 4030 a80 27ef e022 c000

[13:00:50.779] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4831 a80 27ef 4031 a80 27ef e022 c000

[13:01:03.589] <TB1> INFO: 3120000 events read in total (143023ms).
[13:01:03.660] <TB1> INFO: Test took 143925ms.
[13:01:28.290] <TB1> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 168 seconds
[13:01:28.291] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 1 1 0 0 0 0 0 0 15
[13:01:28.291] <TB1> INFO: separation cut (per ROC): 124 105 108 111 116 107 106 106 97 102 106 105 110 108 106 94
[13:01:28.291] <TB1> INFO: Decoding statistics:
[13:01:28.291] <TB1> INFO: General information:
[13:01:28.291] <TB1> INFO: 16bit words read: 0
[13:01:28.291] <TB1> INFO: valid events total: 0
[13:01:28.291] <TB1> INFO: empty events: 0
[13:01:28.291] <TB1> INFO: valid events with pixels: 0
[13:01:28.291] <TB1> INFO: valid pixel hits: 0
[13:01:28.291] <TB1> INFO: Event errors: 0
[13:01:28.291] <TB1> INFO: start marker: 0
[13:01:28.291] <TB1> INFO: stop marker: 0
[13:01:28.291] <TB1> INFO: overflow: 0
[13:01:28.291] <TB1> INFO: invalid 5bit words: 0
[13:01:28.291] <TB1> INFO: invalid XOR eye diagram: 0
[13:01:28.291] <TB1> INFO: frame (failed synchr.): 0
[13:01:28.291] <TB1> INFO: idle data (no TBM trl): 0
[13:01:28.291] <TB1> INFO: no data (only TBM hdr): 0
[13:01:28.291] <TB1> INFO: TBM errors: 0
[13:01:28.291] <TB1> INFO: flawed TBM headers: 0
[13:01:28.291] <TB1> INFO: flawed TBM trailers: 0
[13:01:28.291] <TB1> INFO: event ID mismatches: 0
[13:01:28.291] <TB1> INFO: ROC errors: 0
[13:01:28.291] <TB1> INFO: missing ROC header(s): 0
[13:01:28.291] <TB1> INFO: misplaced readback start: 0
[13:01:28.291] <TB1> INFO: Pixel decoding errors: 0
[13:01:28.291] <TB1> INFO: pixel data incomplete: 0
[13:01:28.291] <TB1> INFO: pixel address: 0
[13:01:28.291] <TB1> INFO: pulse height fill bit: 0
[13:01:28.291] <TB1> INFO: buffer corruption: 0
[13:01:28.327] <TB1> INFO: ######################################################################
[13:01:28.327] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[13:01:28.327] <TB1> INFO: ######################################################################
[13:01:28.327] <TB1> INFO: ----------------------------------------------------------------------
[13:01:28.327] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[13:01:28.327] <TB1> INFO: ----------------------------------------------------------------------
[13:01:28.327] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[13:01:28.341] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[13:01:28.341] <TB1> INFO: run 1 of 1
[13:01:28.625] <TB1> INFO: Expecting 36608000 events.
[13:01:51.771] <TB1> INFO: 678800 events read in total (22554ms).
[13:02:14.414] <TB1> INFO: 1343350 events read in total (45197ms).
[13:02:37.291] <TB1> INFO: 2008400 events read in total (68074ms).
[13:02:59.953] <TB1> INFO: 2672050 events read in total (90736ms).
[13:03:22.779] <TB1> INFO: 3337350 events read in total (113562ms).
[13:03:45.565] <TB1> INFO: 4001200 events read in total (136348ms).
[13:04:08.317] <TB1> INFO: 4666300 events read in total (159100ms).
[13:04:30.829] <TB1> INFO: 5330200 events read in total (181612ms).
[13:04:53.585] <TB1> INFO: 5993350 events read in total (204368ms).
[13:05:16.201] <TB1> INFO: 6659300 events read in total (226984ms).
[13:05:39.023] <TB1> INFO: 7322200 events read in total (249806ms).
[13:06:01.963] <TB1> INFO: 7987800 events read in total (272746ms).
[13:06:24.941] <TB1> INFO: 8652900 events read in total (295724ms).
[13:06:47.751] <TB1> INFO: 9316500 events read in total (318534ms).
[13:07:10.532] <TB1> INFO: 9978300 events read in total (341315ms).
[13:07:33.311] <TB1> INFO: 10641600 events read in total (364094ms).
[13:07:56.350] <TB1> INFO: 11302900 events read in total (387133ms).
[13:08:19.685] <TB1> INFO: 11965500 events read in total (410468ms).
[13:08:42.396] <TB1> INFO: 12626600 events read in total (433179ms).
[13:09:05.900] <TB1> INFO: 13287850 events read in total (456683ms).
[13:09:29.070] <TB1> INFO: 13948550 events read in total (479853ms).
[13:09:52.097] <TB1> INFO: 14610800 events read in total (502880ms).
[13:10:15.408] <TB1> INFO: 15272700 events read in total (526191ms).
[13:10:38.133] <TB1> INFO: 15934650 events read in total (548916ms).
[13:11:00.666] <TB1> INFO: 16596150 events read in total (571449ms).
[13:11:23.513] <TB1> INFO: 17257400 events read in total (594296ms).
[13:11:46.019] <TB1> INFO: 17915750 events read in total (616802ms).
[13:12:08.620] <TB1> INFO: 18575000 events read in total (639403ms).
[13:12:31.338] <TB1> INFO: 19233150 events read in total (662121ms).
[13:12:54.107] <TB1> INFO: 19890600 events read in total (684890ms).
[13:13:16.647] <TB1> INFO: 20548050 events read in total (707430ms).
[13:13:39.551] <TB1> INFO: 21205500 events read in total (730334ms).
[13:14:02.696] <TB1> INFO: 21863950 events read in total (753479ms).
[13:14:26.013] <TB1> INFO: 22519000 events read in total (776796ms).
[13:14:48.870] <TB1> INFO: 23176650 events read in total (799653ms).
[13:15:12.092] <TB1> INFO: 23834100 events read in total (822875ms).
[13:15:35.172] <TB1> INFO: 24491250 events read in total (845955ms).
[13:15:58.014] <TB1> INFO: 25149300 events read in total (868798ms).
[13:16:20.831] <TB1> INFO: 25807550 events read in total (891614ms).
[13:16:43.644] <TB1> INFO: 26464150 events read in total (914427ms).
[13:17:06.423] <TB1> INFO: 27119700 events read in total (937206ms).
[13:17:29.112] <TB1> INFO: 27776600 events read in total (959895ms).
[13:17:51.796] <TB1> INFO: 28431900 events read in total (982579ms).
[13:18:14.302] <TB1> INFO: 29088350 events read in total (1005085ms).
[13:18:36.879] <TB1> INFO: 29743300 events read in total (1027662ms).
[13:18:59.744] <TB1> INFO: 30400400 events read in total (1050527ms).
[13:19:22.234] <TB1> INFO: 31054400 events read in total (1073017ms).
[13:19:44.927] <TB1> INFO: 31711600 events read in total (1095710ms).
[13:20:07.700] <TB1> INFO: 32365900 events read in total (1118483ms).
[13:20:30.455] <TB1> INFO: 33023350 events read in total (1141238ms).
[13:20:53.269] <TB1> INFO: 33679000 events read in total (1164052ms).
[13:21:16.595] <TB1> INFO: 34337950 events read in total (1187378ms).
[13:21:39.445] <TB1> INFO: 34995500 events read in total (1210228ms).
[13:22:02.533] <TB1> INFO: 35654100 events read in total (1233316ms).
[13:22:25.595] <TB1> INFO: 36318800 events read in total (1256378ms).
[13:22:35.731] <TB1> INFO: 36608000 events read in total (1266514ms).
[13:22:35.841] <TB1> INFO: Test took 1267500ms.
[13:22:36.481] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:38.508] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:40.608] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:42.344] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:43.844] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:45.906] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:47.747] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:49.942] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:51.589] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:53.446] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:55.176] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:56.947] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:22:58.799] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:23:00.868] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:23:03.156] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:23:04.817] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:23:06.433] <TB1> INFO: PixTestScurves::scurves() done
[13:23:06.433] <TB1> INFO: Vcal mean: 121.87 112.19 116.21 119.88 123.54 117.33 108.88 111.26 116.87 119.76 122.10 116.83 122.47 121.49 117.54 112.69
[13:23:06.433] <TB1> INFO: Vcal RMS: 6.13 5.49 5.49 5.83 6.47 6.83 4.73 5.09 6.12 6.47 6.57 8.65 6.81 5.99 7.18 5.24
[13:23:06.433] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1298 seconds
[13:23:06.433] <TB1> INFO: Decoding statistics:
[13:23:06.433] <TB1> INFO: General information:
[13:23:06.433] <TB1> INFO: 16bit words read: 0
[13:23:06.433] <TB1> INFO: valid events total: 0
[13:23:06.433] <TB1> INFO: empty events: 0
[13:23:06.433] <TB1> INFO: valid events with pixels: 0
[13:23:06.433] <TB1> INFO: valid pixel hits: 0
[13:23:06.433] <TB1> INFO: Event errors: 0
[13:23:06.433] <TB1> INFO: start marker: 0
[13:23:06.433] <TB1> INFO: stop marker: 0
[13:23:06.433] <TB1> INFO: overflow: 0
[13:23:06.433] <TB1> INFO: invalid 5bit words: 0
[13:23:06.433] <TB1> INFO: invalid XOR eye diagram: 0
[13:23:06.433] <TB1> INFO: frame (failed synchr.): 0
[13:23:06.433] <TB1> INFO: idle data (no TBM trl): 0
[13:23:06.433] <TB1> INFO: no data (only TBM hdr): 0
[13:23:06.433] <TB1> INFO: TBM errors: 0
[13:23:06.433] <TB1> INFO: flawed TBM headers: 0
[13:23:06.433] <TB1> INFO: flawed TBM trailers: 0
[13:23:06.433] <TB1> INFO: event ID mismatches: 0
[13:23:06.433] <TB1> INFO: ROC errors: 0
[13:23:06.433] <TB1> INFO: missing ROC header(s): 0
[13:23:06.433] <TB1> INFO: misplaced readback start: 0
[13:23:06.433] <TB1> INFO: Pixel decoding errors: 0
[13:23:06.433] <TB1> INFO: pixel data incomplete: 0
[13:23:06.433] <TB1> INFO: pixel address: 0
[13:23:06.433] <TB1> INFO: pulse height fill bit: 0
[13:23:06.433] <TB1> INFO: buffer corruption: 0
[13:23:06.501] <TB1> INFO: ######################################################################
[13:23:06.501] <TB1> INFO: PixTestTrim::doTest()
[13:23:06.501] <TB1> INFO: ######################################################################
[13:23:06.502] <TB1> INFO: ----------------------------------------------------------------------
[13:23:06.502] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[13:23:06.502] <TB1> INFO: ----------------------------------------------------------------------
[13:23:06.545] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[13:23:06.545] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[13:23:06.558] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:23:06.558] <TB1> INFO: run 1 of 1
[13:23:06.825] <TB1> INFO: Expecting 5025280 events.
[13:23:37.341] <TB1> INFO: 824048 events read in total (29917ms).
[13:24:07.833] <TB1> INFO: 1645712 events read in total (60409ms).
[13:24:38.266] <TB1> INFO: 2463824 events read in total (90842ms).
[13:25:08.810] <TB1> INFO: 3278544 events read in total (121386ms).
[13:25:39.191] <TB1> INFO: 4090816 events read in total (151768ms).
[13:26:09.459] <TB1> INFO: 4901432 events read in total (182035ms).
[13:26:14.405] <TB1> INFO: 5025280 events read in total (186981ms).
[13:26:14.456] <TB1> INFO: Test took 187898ms.
[13:26:34.676] <TB1> INFO: ROC 0 VthrComp = 133
[13:26:34.676] <TB1> INFO: ROC 1 VthrComp = 112
[13:26:34.676] <TB1> INFO: ROC 2 VthrComp = 117
[13:26:34.676] <TB1> INFO: ROC 3 VthrComp = 125
[13:26:34.676] <TB1> INFO: ROC 4 VthrComp = 124
[13:26:34.676] <TB1> INFO: ROC 5 VthrComp = 118
[13:26:34.676] <TB1> INFO: ROC 6 VthrComp = 116
[13:26:34.676] <TB1> INFO: ROC 7 VthrComp = 112
[13:26:34.677] <TB1> INFO: ROC 8 VthrComp = 113
[13:26:34.677] <TB1> INFO: ROC 9 VthrComp = 114
[13:26:34.677] <TB1> INFO: ROC 10 VthrComp = 122
[13:26:34.677] <TB1> INFO: ROC 11 VthrComp = 109
[13:26:34.677] <TB1> INFO: ROC 12 VthrComp = 123
[13:26:34.677] <TB1> INFO: ROC 13 VthrComp = 121
[13:26:34.677] <TB1> INFO: ROC 14 VthrComp = 122
[13:26:34.677] <TB1> INFO: ROC 15 VthrComp = 113
[13:26:34.980] <TB1> INFO: Expecting 41600 events.
[13:26:38.586] <TB1> INFO: 41600 events read in total (3015ms).
[13:26:38.587] <TB1> INFO: Test took 3908ms.
[13:26:38.596] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[13:26:38.596] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[13:26:38.608] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:26:38.608] <TB1> INFO: run 1 of 1
[13:26:38.886] <TB1> INFO: Expecting 5025280 events.
[13:27:05.710] <TB1> INFO: 590552 events read in total (26233ms).
[13:27:31.674] <TB1> INFO: 1181376 events read in total (52197ms).
[13:27:57.768] <TB1> INFO: 1771864 events read in total (78291ms).
[13:28:23.518] <TB1> INFO: 2362256 events read in total (104041ms).
[13:28:49.562] <TB1> INFO: 2950360 events read in total (130085ms).
[13:29:15.084] <TB1> INFO: 3537256 events read in total (155607ms).
[13:29:40.744] <TB1> INFO: 4123392 events read in total (181267ms).
[13:30:06.488] <TB1> INFO: 4709152 events read in total (207011ms).
[13:30:20.791] <TB1> INFO: 5025280 events read in total (221314ms).
[13:30:20.885] <TB1> INFO: Test took 222277ms.
[13:30:44.409] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 59.8583 for pixel 10/9 mean/min/max = 45.6423/31.4139/59.8708
[13:30:44.409] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 62.4272 for pixel 12/1 mean/min/max = 47.4119/32.2544/62.5693
[13:30:44.410] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 61.8631 for pixel 22/0 mean/min/max = 46.9072/31.698/62.1163
[13:30:44.410] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 60.6815 for pixel 29/8 mean/min/max = 46.2129/31.6521/60.7737
[13:30:44.410] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 61.4932 for pixel 0/14 mean/min/max = 46.353/31.1903/61.5157
[13:30:44.411] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 63.8226 for pixel 1/79 mean/min/max = 47.4885/31.0522/63.9248
[13:30:44.411] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 58.3341 for pixel 51/1 mean/min/max = 45.3453/32.0732/58.6174
[13:30:44.411] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 60.4164 for pixel 18/2 mean/min/max = 46.5134/32.4327/60.5941
[13:30:44.412] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 63.9419 for pixel 45/13 mean/min/max = 47.9865/31.5407/64.4324
[13:30:44.412] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 63.6587 for pixel 29/37 mean/min/max = 48.0592/32.3352/63.7831
[13:30:44.413] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 61.7599 for pixel 3/32 mean/min/max = 46.3032/30.7679/61.8384
[13:30:44.413] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 70.2338 for pixel 0/19 mean/min/max = 51.099/31.9278/70.2702
[13:30:44.414] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 61.4523 for pixel 13/51 mean/min/max = 46.3941/30.9841/61.8041
[13:30:44.414] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 61.5243 for pixel 17/3 mean/min/max = 46.4282/31.213/61.6434
[13:30:44.414] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 66.0489 for pixel 2/16 mean/min/max = 48.1593/29.987/66.3317
[13:30:44.415] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 60.6196 for pixel 11/9 mean/min/max = 46.3951/32.1125/60.6776
[13:30:44.415] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:30:44.504] <TB1> INFO: Expecting 411648 events.
[13:30:53.894] <TB1> INFO: 411648 events read in total (8798ms).
[13:30:53.903] <TB1> INFO: Expecting 411648 events.
[13:31:03.206] <TB1> INFO: 411648 events read in total (8900ms).
[13:31:03.218] <TB1> INFO: Expecting 411648 events.
[13:31:12.307] <TB1> INFO: 411648 events read in total (8686ms).
[13:31:12.320] <TB1> INFO: Expecting 411648 events.
[13:31:21.418] <TB1> INFO: 411648 events read in total (8695ms).
[13:31:21.438] <TB1> INFO: Expecting 411648 events.
[13:31:30.774] <TB1> INFO: 411648 events read in total (8932ms).
[13:31:30.793] <TB1> INFO: Expecting 411648 events.
[13:31:40.140] <TB1> INFO: 411648 events read in total (8944ms).
[13:31:40.161] <TB1> INFO: Expecting 411648 events.
[13:31:49.609] <TB1> INFO: 411648 events read in total (9045ms).
[13:31:49.639] <TB1> INFO: Expecting 411648 events.
[13:31:58.880] <TB1> INFO: 411648 events read in total (8838ms).
[13:31:58.908] <TB1> INFO: Expecting 411648 events.
[13:32:08.082] <TB1> INFO: 411648 events read in total (8771ms).
[13:32:08.112] <TB1> INFO: Expecting 411648 events.
[13:32:17.546] <TB1> INFO: 411648 events read in total (9031ms).
[13:32:17.582] <TB1> INFO: Expecting 411648 events.
[13:32:26.799] <TB1> INFO: 411648 events read in total (8814ms).
[13:32:26.835] <TB1> INFO: Expecting 411648 events.
[13:32:36.022] <TB1> INFO: 411648 events read in total (8784ms).
[13:32:36.059] <TB1> INFO: Expecting 411648 events.
[13:32:45.430] <TB1> INFO: 411648 events read in total (8968ms).
[13:32:45.471] <TB1> INFO: Expecting 411648 events.
[13:32:54.632] <TB1> INFO: 411648 events read in total (8758ms).
[13:32:54.674] <TB1> INFO: Expecting 411648 events.
[13:33:04.017] <TB1> INFO: 411648 events read in total (8939ms).
[13:33:04.088] <TB1> INFO: Expecting 411648 events.
[13:33:13.389] <TB1> INFO: 411648 events read in total (8898ms).
[13:33:13.453] <TB1> INFO: Test took 149038ms.
[13:33:14.204] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[13:33:14.218] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:33:14.218] <TB1> INFO: run 1 of 1
[13:33:14.497] <TB1> INFO: Expecting 5025280 events.
[13:33:41.310] <TB1> INFO: 590488 events read in total (26221ms).
[13:34:07.714] <TB1> INFO: 1178720 events read in total (52625ms).
[13:34:34.595] <TB1> INFO: 1765672 events read in total (79506ms).
[13:35:01.049] <TB1> INFO: 2351152 events read in total (105960ms).
[13:35:27.678] <TB1> INFO: 2937064 events read in total (132590ms).
[13:35:54.204] <TB1> INFO: 3524920 events read in total (159115ms).
[13:36:20.748] <TB1> INFO: 4114416 events read in total (185659ms).
[13:36:46.905] <TB1> INFO: 4701280 events read in total (211816ms).
[13:37:01.682] <TB1> INFO: 5025280 events read in total (226593ms).
[13:37:01.846] <TB1> INFO: Test took 227628ms.
[13:37:23.893] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 2.096023 .. 147.155050
[13:37:24.177] <TB1> INFO: Expecting 208000 events.
[13:37:33.860] <TB1> INFO: 208000 events read in total (9090ms).
[13:37:33.862] <TB1> INFO: Test took 9968ms.
[13:37:33.912] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 2 .. 157 (-1/-1) hits flags = 528 (plus default)
[13:37:33.925] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:37:33.925] <TB1> INFO: run 1 of 1
[13:37:34.203] <TB1> INFO: Expecting 5191680 events.
[13:38:01.142] <TB1> INFO: 582584 events read in total (26347ms).
[13:38:27.155] <TB1> INFO: 1165112 events read in total (52361ms).
[13:38:52.979] <TB1> INFO: 1747672 events read in total (78184ms).
[13:39:18.460] <TB1> INFO: 2329944 events read in total (103665ms).
[13:39:44.000] <TB1> INFO: 2912616 events read in total (130205ms).
[13:40:11.395] <TB1> INFO: 3494320 events read in total (156600ms).
[13:40:37.645] <TB1> INFO: 4075824 events read in total (182850ms).
[13:41:03.520] <TB1> INFO: 4657232 events read in total (208725ms).
[13:41:27.633] <TB1> INFO: 5191680 events read in total (232838ms).
[13:41:27.734] <TB1> INFO: Test took 233809ms.
[13:41:57.062] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 26.416810 .. 46.183647
[13:41:57.313] <TB1> INFO: Expecting 208000 events.
[13:42:07.392] <TB1> INFO: 208000 events read in total (9487ms).
[13:42:07.394] <TB1> INFO: Test took 10331ms.
[13:42:07.471] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 56 (-1/-1) hits flags = 528 (plus default)
[13:42:07.486] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:42:07.487] <TB1> INFO: run 1 of 1
[13:42:07.809] <TB1> INFO: Expecting 1364480 events.
[13:42:36.339] <TB1> INFO: 658488 events read in total (27938ms).
[13:43:04.546] <TB1> INFO: 1314432 events read in total (56145ms).
[13:43:07.071] <TB1> INFO: 1364480 events read in total (58670ms).
[13:43:07.106] <TB1> INFO: Test took 59620ms.
[13:43:20.847] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 26.360558 .. 48.278743
[13:43:21.125] <TB1> INFO: Expecting 208000 events.
[13:43:30.995] <TB1> INFO: 208000 events read in total (9278ms).
[13:43:30.996] <TB1> INFO: Test took 10147ms.
[13:43:31.066] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 58 (-1/-1) hits flags = 528 (plus default)
[13:43:31.079] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:43:31.080] <TB1> INFO: run 1 of 1
[13:43:31.359] <TB1> INFO: Expecting 1431040 events.
[13:43:59.586] <TB1> INFO: 652136 events read in total (27635ms).
[13:44:28.089] <TB1> INFO: 1302928 events read in total (56138ms).
[13:44:34.029] <TB1> INFO: 1431040 events read in total (62078ms).
[13:44:34.064] <TB1> INFO: Test took 62985ms.
[13:44:48.613] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 23.816695 .. 47.456974
[13:44:48.852] <TB1> INFO: Expecting 208000 events.
[13:44:58.710] <TB1> INFO: 208000 events read in total (9266ms).
[13:44:58.711] <TB1> INFO: Test took 10097ms.
[13:44:58.759] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 13 .. 57 (-1/-1) hits flags = 528 (plus default)
[13:44:58.773] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:44:58.773] <TB1> INFO: run 1 of 1
[13:44:59.051] <TB1> INFO: Expecting 1497600 events.
[13:45:27.927] <TB1> INFO: 666728 events read in total (28284ms).
[13:45:56.012] <TB1> INFO: 1333152 events read in total (56369ms).
[13:46:03.238] <TB1> INFO: 1497600 events read in total (63595ms).
[13:46:03.279] <TB1> INFO: Test took 64507ms.
[13:46:16.884] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[13:46:16.884] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[13:46:16.898] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:46:16.898] <TB1> INFO: run 1 of 1
[13:46:17.175] <TB1> INFO: Expecting 1364480 events.
[13:46:45.589] <TB1> INFO: 667256 events read in total (27822ms).
[13:47:14.455] <TB1> INFO: 1333856 events read in total (56688ms).
[13:47:16.132] <TB1> INFO: 1364480 events read in total (58365ms).
[13:47:16.160] <TB1> INFO: Test took 59262ms.
[13:47:28.302] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C0.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C1.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C2.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C3.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C4.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C5.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C6.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C7.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C8.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C9.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C10.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C11.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C12.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C13.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C14.dat
[13:47:28.303] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C15.dat
[13:47:28.303] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C0.dat
[13:47:28.308] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C1.dat
[13:47:28.313] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C2.dat
[13:47:28.318] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C3.dat
[13:47:28.323] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C4.dat
[13:47:28.327] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C5.dat
[13:47:28.332] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C6.dat
[13:47:28.337] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C7.dat
[13:47:28.341] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C8.dat
[13:47:28.346] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C9.dat
[13:47:28.351] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C10.dat
[13:47:28.355] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C11.dat
[13:47:28.360] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C12.dat
[13:47:28.365] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C13.dat
[13:47:28.369] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C14.dat
[13:47:28.374] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//trimParameters35_C15.dat
[13:47:28.378] <TB1> INFO: PixTestTrim::trimTest() done
[13:47:28.378] <TB1> INFO: vtrim: 148 131 129 125 124 110 125 133 130 120 123 135 130 129 154 130
[13:47:28.378] <TB1> INFO: vthrcomp: 133 112 117 125 124 118 116 112 113 114 122 109 123 121 122 113
[13:47:28.378] <TB1> INFO: vcal mean: 34.96 34.95 35.01 34.96 34.92 35.03 34.98 34.95 35.18 35.14 34.92 35.10 34.96 34.98 35.05 34.97
[13:47:28.378] <TB1> INFO: vcal RMS: 1.03 1.13 1.09 1.10 1.16 1.21 1.01 1.08 1.35 1.32 1.15 1.28 1.18 1.17 1.28 1.08
[13:47:28.378] <TB1> INFO: bits mean: 9.71 9.26 9.54 9.12 9.55 9.35 9.44 9.39 9.58 9.34 9.65 8.74 9.89 9.78 9.79 9.89
[13:47:28.378] <TB1> INFO: bits RMS: 2.74 2.69 2.68 2.93 2.74 2.82 2.77 2.64 2.70 2.69 2.76 2.64 2.63 2.67 2.66 2.49
[13:47:28.386] <TB1> INFO: ----------------------------------------------------------------------
[13:47:28.386] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[13:47:28.386] <TB1> INFO: ----------------------------------------------------------------------
[13:47:28.389] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[13:47:28.401] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:47:28.401] <TB1> INFO: run 1 of 1
[13:47:28.638] <TB1> INFO: Expecting 4160000 events.
[13:48:00.425] <TB1> INFO: 748930 events read in total (31196ms).
[13:48:32.394] <TB1> INFO: 1493230 events read in total (63165ms).
[13:49:03.993] <TB1> INFO: 2232800 events read in total (94764ms).
[13:49:35.244] <TB1> INFO: 2968955 events read in total (126015ms).
[13:50:06.648] <TB1> INFO: 3702765 events read in total (157419ms).
[13:50:26.052] <TB1> INFO: 4160000 events read in total (176823ms).
[13:50:26.196] <TB1> INFO: Test took 177794ms.
[13:50:52.996] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 205 (-1/-1) hits flags = 528 (plus default)
[13:50:53.009] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:50:53.009] <TB1> INFO: run 1 of 1
[13:50:53.244] <TB1> INFO: Expecting 4284800 events.
[13:51:24.786] <TB1> INFO: 718160 events read in total (30950ms).
[13:51:55.610] <TB1> INFO: 1432955 events read in total (61774ms).
[13:52:26.858] <TB1> INFO: 2143810 events read in total (93023ms).
[13:52:57.549] <TB1> INFO: 2850095 events read in total (123713ms).
[13:53:28.186] <TB1> INFO: 3555220 events read in total (154350ms).
[13:53:59.262] <TB1> INFO: 4262030 events read in total (185426ms).
[13:54:00.656] <TB1> INFO: 4284800 events read in total (186820ms).
[13:54:00.766] <TB1> INFO: Test took 187758ms.
[13:54:27.003] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 196 (-1/-1) hits flags = 528 (plus default)
[13:54:28.015] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:54:28.015] <TB1> INFO: run 1 of 1
[13:54:28.252] <TB1> INFO: Expecting 4097600 events.
[13:55:00.334] <TB1> INFO: 730195 events read in total (31491ms).
[13:55:31.337] <TB1> INFO: 1456005 events read in total (62494ms).
[13:56:02.705] <TB1> INFO: 2177475 events read in total (93863ms).
[13:56:34.039] <TB1> INFO: 2895105 events read in total (125196ms).
[13:57:05.152] <TB1> INFO: 3610460 events read in total (156309ms).
[13:57:26.153] <TB1> INFO: 4097600 events read in total (177310ms).
[13:57:26.247] <TB1> INFO: Test took 178231ms.
[13:57:57.699] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 194 (-1/-1) hits flags = 528 (plus default)
[13:57:57.712] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:57:57.712] <TB1> INFO: run 1 of 1
[13:57:57.948] <TB1> INFO: Expecting 4056000 events.
[13:58:29.498] <TB1> INFO: 733340 events read in total (30959ms).
[13:59:01.040] <TB1> INFO: 1462270 events read in total (62501ms).
[13:59:32.133] <TB1> INFO: 2186320 events read in total (93594ms).
[14:00:03.591] <TB1> INFO: 2906635 events read in total (125052ms).
[14:00:34.714] <TB1> INFO: 3624530 events read in total (156175ms).
[14:00:53.507] <TB1> INFO: 4056000 events read in total (174968ms).
[14:00:53.604] <TB1> INFO: Test took 175891ms.
[14:01:18.009] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 194 (-1/-1) hits flags = 528 (plus default)
[14:01:18.021] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:01:18.021] <TB1> INFO: run 1 of 1
[14:01:18.268] <TB1> INFO: Expecting 4056000 events.
[14:01:50.657] <TB1> INFO: 733750 events read in total (31797ms).
[14:02:21.995] <TB1> INFO: 1463135 events read in total (63135ms).
[14:02:53.734] <TB1> INFO: 2187655 events read in total (94874ms).
[14:03:24.940] <TB1> INFO: 2908445 events read in total (126080ms).
[14:03:56.064] <TB1> INFO: 3626770 events read in total (157204ms).
[14:04:14.708] <TB1> INFO: 4056000 events read in total (175848ms).
[14:04:14.816] <TB1> INFO: Test took 176795ms.
[14:04:41.700] <TB1> INFO: PixTestTrim::trimBitTest() done
[14:04:41.702] <TB1> INFO: PixTestTrim::doTest() done, duration: 2495 seconds
[14:04:41.702] <TB1> INFO: Decoding statistics:
[14:04:41.702] <TB1> INFO: General information:
[14:04:41.702] <TB1> INFO: 16bit words read: 0
[14:04:41.702] <TB1> INFO: valid events total: 0
[14:04:41.702] <TB1> INFO: empty events: 0
[14:04:41.702] <TB1> INFO: valid events with pixels: 0
[14:04:41.702] <TB1> INFO: valid pixel hits: 0
[14:04:41.702] <TB1> INFO: Event errors: 0
[14:04:41.702] <TB1> INFO: start marker: 0
[14:04:41.702] <TB1> INFO: stop marker: 0
[14:04:41.702] <TB1> INFO: overflow: 0
[14:04:41.702] <TB1> INFO: invalid 5bit words: 0
[14:04:41.702] <TB1> INFO: invalid XOR eye diagram: 0
[14:04:41.702] <TB1> INFO: frame (failed synchr.): 0
[14:04:41.702] <TB1> INFO: idle data (no TBM trl): 0
[14:04:41.702] <TB1> INFO: no data (only TBM hdr): 0
[14:04:41.702] <TB1> INFO: TBM errors: 0
[14:04:41.702] <TB1> INFO: flawed TBM headers: 0
[14:04:41.702] <TB1> INFO: flawed TBM trailers: 0
[14:04:41.702] <TB1> INFO: event ID mismatches: 0
[14:04:41.702] <TB1> INFO: ROC errors: 0
[14:04:41.702] <TB1> INFO: missing ROC header(s): 0
[14:04:41.702] <TB1> INFO: misplaced readback start: 0
[14:04:41.702] <TB1> INFO: Pixel decoding errors: 0
[14:04:41.702] <TB1> INFO: pixel data incomplete: 0
[14:04:41.702] <TB1> INFO: pixel address: 0
[14:04:41.702] <TB1> INFO: pulse height fill bit: 0
[14:04:41.702] <TB1> INFO: buffer corruption: 0
[14:04:42.407] <TB1> INFO: ######################################################################
[14:04:42.407] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[14:04:42.407] <TB1> INFO: ######################################################################
[14:04:42.682] <TB1> INFO: Expecting 41600 events.
[14:04:46.165] <TB1> INFO: 41600 events read in total (2891ms).
[14:04:46.167] <TB1> INFO: Test took 3758ms.
[14:04:46.693] <TB1> INFO: Expecting 41600 events.
[14:04:50.308] <TB1> INFO: 41600 events read in total (3023ms).
[14:04:50.309] <TB1> INFO: Test took 3935ms.
[14:04:50.626] <TB1> INFO: Expecting 41600 events.
[14:04:54.153] <TB1> INFO: 41600 events read in total (2935ms).
[14:04:54.155] <TB1> INFO: Test took 3820ms.
[14:04:54.444] <TB1> INFO: Expecting 41600 events.
[14:04:57.949] <TB1> INFO: 41600 events read in total (2913ms).
[14:04:57.950] <TB1> INFO: Test took 3770ms.
[14:04:58.249] <TB1> INFO: Expecting 41600 events.
[14:05:01.924] <TB1> INFO: 41600 events read in total (3083ms).
[14:05:01.925] <TB1> INFO: Test took 3951ms.
[14:05:02.214] <TB1> INFO: Expecting 41600 events.
[14:05:05.866] <TB1> INFO: 41600 events read in total (3060ms).
[14:05:05.867] <TB1> INFO: Test took 3917ms.
[14:05:06.158] <TB1> INFO: Expecting 41600 events.
[14:05:09.660] <TB1> INFO: 41600 events read in total (2910ms).
[14:05:09.661] <TB1> INFO: Test took 3767ms.
[14:05:09.953] <TB1> INFO: Expecting 41600 events.
[14:05:13.501] <TB1> INFO: 41600 events read in total (2957ms).
[14:05:13.502] <TB1> INFO: Test took 3816ms.
[14:05:13.792] <TB1> INFO: Expecting 41600 events.
[14:05:17.310] <TB1> INFO: 41600 events read in total (2926ms).
[14:05:17.311] <TB1> INFO: Test took 3785ms.
[14:05:17.600] <TB1> INFO: Expecting 41600 events.
[14:05:21.129] <TB1> INFO: 41600 events read in total (2937ms).
[14:05:21.130] <TB1> INFO: Test took 3795ms.
[14:05:21.426] <TB1> INFO: Expecting 41600 events.
[14:05:24.983] <TB1> INFO: 41600 events read in total (2965ms).
[14:05:24.984] <TB1> INFO: Test took 3825ms.
[14:05:25.273] <TB1> INFO: Expecting 41600 events.
[14:05:28.821] <TB1> INFO: 41600 events read in total (2956ms).
[14:05:28.822] <TB1> INFO: Test took 3814ms.
[14:05:29.114] <TB1> INFO: Expecting 41600 events.
[14:05:32.881] <TB1> INFO: 41600 events read in total (3175ms).
[14:05:32.882] <TB1> INFO: Test took 4032ms.
[14:05:33.174] <TB1> INFO: Expecting 41600 events.
[14:05:36.664] <TB1> INFO: 41600 events read in total (2898ms).
[14:05:36.665] <TB1> INFO: Test took 3756ms.
[14:05:36.955] <TB1> INFO: Expecting 41600 events.
[14:05:40.526] <TB1> INFO: 41600 events read in total (2980ms).
[14:05:40.526] <TB1> INFO: Test took 3836ms.
[14:05:40.816] <TB1> INFO: Expecting 41600 events.
[14:05:44.333] <TB1> INFO: 41600 events read in total (2925ms).
[14:05:44.334] <TB1> INFO: Test took 3783ms.
[14:05:44.624] <TB1> INFO: Expecting 41600 events.
[14:05:48.179] <TB1> INFO: 41600 events read in total (2964ms).
[14:05:48.180] <TB1> INFO: Test took 3821ms.
[14:05:48.469] <TB1> INFO: Expecting 41600 events.
[14:05:51.983] <TB1> INFO: 41600 events read in total (2922ms).
[14:05:51.983] <TB1> INFO: Test took 3780ms.
[14:05:52.273] <TB1> INFO: Expecting 41600 events.
[14:05:55.881] <TB1> INFO: 41600 events read in total (3017ms).
[14:05:55.882] <TB1> INFO: Test took 3874ms.
[14:05:56.172] <TB1> INFO: Expecting 41600 events.
[14:05:59.725] <TB1> INFO: 41600 events read in total (2961ms).
[14:05:59.726] <TB1> INFO: Test took 3820ms.
[14:06:00.033] <TB1> INFO: Expecting 41600 events.
[14:06:03.590] <TB1> INFO: 41600 events read in total (2965ms).
[14:06:03.591] <TB1> INFO: Test took 3840ms.
[14:06:03.903] <TB1> INFO: Expecting 41600 events.
[14:06:07.540] <TB1> INFO: 41600 events read in total (3045ms).
[14:06:07.541] <TB1> INFO: Test took 3923ms.
[14:06:07.833] <TB1> INFO: Expecting 41600 events.
[14:06:11.332] <TB1> INFO: 41600 events read in total (2908ms).
[14:06:11.333] <TB1> INFO: Test took 3765ms.
[14:06:11.626] <TB1> INFO: Expecting 41600 events.
[14:06:15.213] <TB1> INFO: 41600 events read in total (2995ms).
[14:06:15.214] <TB1> INFO: Test took 3852ms.
[14:06:15.503] <TB1> INFO: Expecting 41600 events.
[14:06:19.003] <TB1> INFO: 41600 events read in total (2908ms).
[14:06:19.004] <TB1> INFO: Test took 3766ms.
[14:06:19.293] <TB1> INFO: Expecting 41600 events.
[14:06:22.781] <TB1> INFO: 41600 events read in total (2896ms).
[14:06:22.782] <TB1> INFO: Test took 3754ms.
[14:06:23.071] <TB1> INFO: Expecting 41600 events.
[14:06:26.587] <TB1> INFO: 41600 events read in total (2924ms).
[14:06:26.588] <TB1> INFO: Test took 3781ms.
[14:06:26.881] <TB1> INFO: Expecting 41600 events.
[14:06:30.474] <TB1> INFO: 41600 events read in total (3001ms).
[14:06:30.475] <TB1> INFO: Test took 3859ms.
[14:06:30.768] <TB1> INFO: Expecting 41600 events.
[14:06:34.294] <TB1> INFO: 41600 events read in total (2934ms).
[14:06:34.294] <TB1> INFO: Test took 3792ms.
[14:06:34.586] <TB1> INFO: Expecting 41600 events.
[14:06:38.118] <TB1> INFO: 41600 events read in total (2940ms).
[14:06:38.119] <TB1> INFO: Test took 3799ms.
[14:06:38.410] <TB1> INFO: Expecting 2560 events.
[14:06:39.302] <TB1> INFO: 2560 events read in total (300ms).
[14:06:39.302] <TB1> INFO: Test took 1169ms.
[14:06:39.610] <TB1> INFO: Expecting 2560 events.
[14:06:40.492] <TB1> INFO: 2560 events read in total (290ms).
[14:06:40.493] <TB1> INFO: Test took 1190ms.
[14:06:40.801] <TB1> INFO: Expecting 2560 events.
[14:06:41.693] <TB1> INFO: 2560 events read in total (300ms).
[14:06:41.693] <TB1> INFO: Test took 1200ms.
[14:06:41.000] <TB1> INFO: Expecting 2560 events.
[14:06:42.889] <TB1> INFO: 2560 events read in total (297ms).
[14:06:42.890] <TB1> INFO: Test took 1196ms.
[14:06:43.197] <TB1> INFO: Expecting 2560 events.
[14:06:44.085] <TB1> INFO: 2560 events read in total (296ms).
[14:06:44.086] <TB1> INFO: Test took 1196ms.
[14:06:44.394] <TB1> INFO: Expecting 2560 events.
[14:06:45.279] <TB1> INFO: 2560 events read in total (293ms).
[14:06:45.279] <TB1> INFO: Test took 1193ms.
[14:06:45.587] <TB1> INFO: Expecting 2560 events.
[14:06:46.469] <TB1> INFO: 2560 events read in total (290ms).
[14:06:46.470] <TB1> INFO: Test took 1191ms.
[14:06:46.777] <TB1> INFO: Expecting 2560 events.
[14:06:47.659] <TB1> INFO: 2560 events read in total (291ms).
[14:06:47.660] <TB1> INFO: Test took 1187ms.
[14:06:47.968] <TB1> INFO: Expecting 2560 events.
[14:06:48.850] <TB1> INFO: 2560 events read in total (291ms).
[14:06:48.850] <TB1> INFO: Test took 1190ms.
[14:06:49.158] <TB1> INFO: Expecting 2560 events.
[14:06:50.046] <TB1> INFO: 2560 events read in total (296ms).
[14:06:50.046] <TB1> INFO: Test took 1195ms.
[14:06:50.353] <TB1> INFO: Expecting 2560 events.
[14:06:51.235] <TB1> INFO: 2560 events read in total (290ms).
[14:06:51.235] <TB1> INFO: Test took 1188ms.
[14:06:51.543] <TB1> INFO: Expecting 2560 events.
[14:06:52.424] <TB1> INFO: 2560 events read in total (289ms).
[14:06:52.424] <TB1> INFO: Test took 1189ms.
[14:06:52.731] <TB1> INFO: Expecting 2560 events.
[14:06:53.620] <TB1> INFO: 2560 events read in total (297ms).
[14:06:53.620] <TB1> INFO: Test took 1195ms.
[14:06:53.929] <TB1> INFO: Expecting 2560 events.
[14:06:54.812] <TB1> INFO: 2560 events read in total (292ms).
[14:06:54.813] <TB1> INFO: Test took 1192ms.
[14:06:55.120] <TB1> INFO: Expecting 2560 events.
[14:06:56.006] <TB1> INFO: 2560 events read in total (294ms).
[14:06:56.006] <TB1> INFO: Test took 1193ms.
[14:06:56.314] <TB1> INFO: Expecting 2560 events.
[14:06:57.199] <TB1> INFO: 2560 events read in total (293ms).
[14:06:57.199] <TB1> INFO: Test took 1193ms.
[14:06:57.202] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:06:57.509] <TB1> INFO: Expecting 655360 events.
[14:07:12.609] <TB1> INFO: 655360 events read in total (14509ms).
[14:07:12.621] <TB1> INFO: Expecting 655360 events.
[14:07:27.039] <TB1> INFO: 655360 events read in total (14015ms).
[14:07:27.061] <TB1> INFO: Expecting 655360 events.
[14:07:41.734] <TB1> INFO: 655360 events read in total (14270ms).
[14:07:41.759] <TB1> INFO: Expecting 655360 events.
[14:07:56.310] <TB1> INFO: 655360 events read in total (14148ms).
[14:07:56.339] <TB1> INFO: Expecting 655360 events.
[14:08:10.840] <TB1> INFO: 655360 events read in total (14098ms).
[14:08:10.871] <TB1> INFO: Expecting 655360 events.
[14:08:25.425] <TB1> INFO: 655360 events read in total (14151ms).
[14:08:25.458] <TB1> INFO: Expecting 655360 events.
[14:08:39.845] <TB1> INFO: 655360 events read in total (13984ms).
[14:08:39.883] <TB1> INFO: Expecting 655360 events.
[14:08:54.610] <TB1> INFO: 655360 events read in total (14324ms).
[14:08:54.653] <TB1> INFO: Expecting 655360 events.
[14:09:09.013] <TB1> INFO: 655360 events read in total (13958ms).
[14:09:09.064] <TB1> INFO: Expecting 655360 events.
[14:09:23.868] <TB1> INFO: 655360 events read in total (14401ms).
[14:09:23.920] <TB1> INFO: Expecting 655360 events.
[14:09:38.267] <TB1> INFO: 655360 events read in total (13944ms).
[14:09:38.379] <TB1> INFO: Expecting 655360 events.
[14:09:53.134] <TB1> INFO: 655360 events read in total (14352ms).
[14:09:53.215] <TB1> INFO: Expecting 655360 events.
[14:10:07.665] <TB1> INFO: 655360 events read in total (14047ms).
[14:10:07.779] <TB1> INFO: Expecting 655360 events.
[14:10:22.497] <TB1> INFO: 655360 events read in total (14315ms).
[14:10:22.584] <TB1> INFO: Expecting 655360 events.
[14:10:37.364] <TB1> INFO: 655360 events read in total (14377ms).
[14:10:37.457] <TB1> INFO: Expecting 655360 events.
[14:10:52.122] <TB1> INFO: 655360 events read in total (14262ms).
[14:10:52.222] <TB1> INFO: Test took 235020ms.
[14:10:52.316] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:10:52.575] <TB1> INFO: Expecting 655360 events.
[14:11:07.386] <TB1> INFO: 655360 events read in total (14220ms).
[14:11:07.398] <TB1> INFO: Expecting 655360 events.
[14:11:22.045] <TB1> INFO: 655360 events read in total (14244ms).
[14:11:22.062] <TB1> INFO: Expecting 655360 events.
[14:11:36.722] <TB1> INFO: 655360 events read in total (14257ms).
[14:11:36.742] <TB1> INFO: Expecting 655360 events.
[14:11:51.438] <TB1> INFO: 655360 events read in total (14292ms).
[14:11:51.462] <TB1> INFO: Expecting 655360 events.
[14:12:05.988] <TB1> INFO: 655360 events read in total (14123ms).
[14:12:06.019] <TB1> INFO: Expecting 655360 events.
[14:12:20.782] <TB1> INFO: 655360 events read in total (14360ms).
[14:12:20.815] <TB1> INFO: Expecting 655360 events.
[14:12:35.437] <TB1> INFO: 655360 events read in total (14219ms).
[14:12:35.482] <TB1> INFO: Expecting 655360 events.
[14:12:49.752] <TB1> INFO: 655360 events read in total (13867ms).
[14:12:49.794] <TB1> INFO: Expecting 655360 events.
[14:13:04.115] <TB1> INFO: 655360 events read in total (13918ms).
[14:13:04.160] <TB1> INFO: Expecting 655360 events.
[14:13:18.709] <TB1> INFO: 655360 events read in total (14147ms).
[14:13:18.759] <TB1> INFO: Expecting 655360 events.
[14:13:33.514] <TB1> INFO: 655360 events read in total (14352ms).
[14:13:33.580] <TB1> INFO: Expecting 655360 events.
[14:13:47.974] <TB1> INFO: 655360 events read in total (13990ms).
[14:13:48.072] <TB1> INFO: Expecting 655360 events.
[14:14:02.748] <TB1> INFO: 655360 events read in total (14273ms).
[14:14:02.829] <TB1> INFO: Expecting 655360 events.
[14:14:17.460] <TB1> INFO: 655360 events read in total (14228ms).
[14:14:17.572] <TB1> INFO: Expecting 655360 events.
[14:14:31.916] <TB1> INFO: 655360 events read in total (13941ms).
[14:14:32.006] <TB1> INFO: Expecting 655360 events.
[14:14:46.630] <TB1> INFO: 655360 events read in total (14221ms).
[14:14:46.764] <TB1> INFO: Test took 234448ms.
[14:14:46.959] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:46.964] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:46.970] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:46.976] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:46.983] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:14:46.991] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[14:14:46.999] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[14:14:47.006] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.014] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.022] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:14:47.030] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[14:14:47.037] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.045] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.053] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:14:47.061] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[14:14:47.068] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[14:14:47.076] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.084] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:14:47.092] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.100] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.107] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.115] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.122] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.130] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.138] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:14:47.176] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C0.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C1.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C2.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C3.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C4.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C5.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C6.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C7.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C8.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C9.dat
[14:14:47.177] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C10.dat
[14:14:47.178] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C11.dat
[14:14:47.178] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C12.dat
[14:14:47.178] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C13.dat
[14:14:47.178] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C14.dat
[14:14:47.178] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//dacParameters35_C15.dat
[14:14:47.417] <TB1> INFO: Expecting 41600 events.
[14:14:50.528] <TB1> INFO: 41600 events read in total (2519ms).
[14:14:50.529] <TB1> INFO: Test took 3348ms.
[14:14:50.978] <TB1> INFO: Expecting 41600 events.
[14:14:54.014] <TB1> INFO: 41600 events read in total (2444ms).
[14:14:54.015] <TB1> INFO: Test took 3273ms.
[14:14:54.463] <TB1> INFO: Expecting 41600 events.
[14:14:57.659] <TB1> INFO: 41600 events read in total (2604ms).
[14:14:57.659] <TB1> INFO: Test took 3434ms.
[14:14:57.877] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:14:57.967] <TB1> INFO: Expecting 2560 events.
[14:14:58.861] <TB1> INFO: 2560 events read in total (302ms).
[14:14:58.862] <TB1> INFO: Test took 985ms.
[14:14:58.864] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:14:59.170] <TB1> INFO: Expecting 2560 events.
[14:15:00.060] <TB1> INFO: 2560 events read in total (298ms).
[14:15:00.060] <TB1> INFO: Test took 1196ms.
[14:15:00.062] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:00.368] <TB1> INFO: Expecting 2560 events.
[14:15:01.261] <TB1> INFO: 2560 events read in total (301ms).
[14:15:01.261] <TB1> INFO: Test took 1199ms.
[14:15:01.264] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:01.569] <TB1> INFO: Expecting 2560 events.
[14:15:02.456] <TB1> INFO: 2560 events read in total (295ms).
[14:15:02.457] <TB1> INFO: Test took 1193ms.
[14:15:02.460] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:02.766] <TB1> INFO: Expecting 2560 events.
[14:15:03.657] <TB1> INFO: 2560 events read in total (300ms).
[14:15:03.658] <TB1> INFO: Test took 1198ms.
[14:15:03.662] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:03.965] <TB1> INFO: Expecting 2560 events.
[14:15:04.851] <TB1> INFO: 2560 events read in total (294ms).
[14:15:04.851] <TB1> INFO: Test took 1189ms.
[14:15:04.854] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:05.160] <TB1> INFO: Expecting 2560 events.
[14:15:06.051] <TB1> INFO: 2560 events read in total (300ms).
[14:15:06.052] <TB1> INFO: Test took 1199ms.
[14:15:06.055] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:06.359] <TB1> INFO: Expecting 2560 events.
[14:15:07.250] <TB1> INFO: 2560 events read in total (299ms).
[14:15:07.251] <TB1> INFO: Test took 1197ms.
[14:15:07.253] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:07.560] <TB1> INFO: Expecting 2560 events.
[14:15:08.445] <TB1> INFO: 2560 events read in total (294ms).
[14:15:08.445] <TB1> INFO: Test took 1192ms.
[14:15:08.448] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:08.753] <TB1> INFO: Expecting 2560 events.
[14:15:09.636] <TB1> INFO: 2560 events read in total (291ms).
[14:15:09.636] <TB1> INFO: Test took 1188ms.
[14:15:09.639] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:09.944] <TB1> INFO: Expecting 2560 events.
[14:15:10.834] <TB1> INFO: 2560 events read in total (298ms).
[14:15:10.835] <TB1> INFO: Test took 1196ms.
[14:15:10.839] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:11.142] <TB1> INFO: Expecting 2560 events.
[14:15:12.028] <TB1> INFO: 2560 events read in total (294ms).
[14:15:12.029] <TB1> INFO: Test took 1190ms.
[14:15:12.031] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:12.344] <TB1> INFO: Expecting 2560 events.
[14:15:13.235] <TB1> INFO: 2560 events read in total (299ms).
[14:15:13.235] <TB1> INFO: Test took 1204ms.
[14:15:13.239] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:13.545] <TB1> INFO: Expecting 2560 events.
[14:15:14.433] <TB1> INFO: 2560 events read in total (296ms).
[14:15:14.434] <TB1> INFO: Test took 1195ms.
[14:15:14.438] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:14.742] <TB1> INFO: Expecting 2560 events.
[14:15:15.628] <TB1> INFO: 2560 events read in total (294ms).
[14:15:15.628] <TB1> INFO: Test took 1190ms.
[14:15:15.631] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:15.936] <TB1> INFO: Expecting 2560 events.
[14:15:16.827] <TB1> INFO: 2560 events read in total (299ms).
[14:15:16.827] <TB1> INFO: Test took 1196ms.
[14:15:16.833] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:17.135] <TB1> INFO: Expecting 2560 events.
[14:15:18.020] <TB1> INFO: 2560 events read in total (293ms).
[14:15:18.021] <TB1> INFO: Test took 1188ms.
[14:15:18.025] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:18.329] <TB1> INFO: Expecting 2560 events.
[14:15:19.215] <TB1> INFO: 2560 events read in total (294ms).
[14:15:19.215] <TB1> INFO: Test took 1190ms.
[14:15:19.218] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:19.525] <TB1> INFO: Expecting 2560 events.
[14:15:20.408] <TB1> INFO: 2560 events read in total (292ms).
[14:15:20.408] <TB1> INFO: Test took 1190ms.
[14:15:20.411] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:20.716] <TB1> INFO: Expecting 2560 events.
[14:15:21.604] <TB1> INFO: 2560 events read in total (296ms).
[14:15:21.604] <TB1> INFO: Test took 1193ms.
[14:15:21.608] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:21.911] <TB1> INFO: Expecting 2560 events.
[14:15:22.799] <TB1> INFO: 2560 events read in total (296ms).
[14:15:22.800] <TB1> INFO: Test took 1192ms.
[14:15:22.802] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:23.109] <TB1> INFO: Expecting 2560 events.
[14:15:23.999] <TB1> INFO: 2560 events read in total (298ms).
[14:15:23.999] <TB1> INFO: Test took 1197ms.
[14:15:23.003] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:24.308] <TB1> INFO: Expecting 2560 events.
[14:15:25.189] <TB1> INFO: 2560 events read in total (289ms).
[14:15:25.190] <TB1> INFO: Test took 1188ms.
[14:15:25.195] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:25.498] <TB1> INFO: Expecting 2560 events.
[14:15:26.391] <TB1> INFO: 2560 events read in total (301ms).
[14:15:26.391] <TB1> INFO: Test took 1196ms.
[14:15:26.395] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:26.699] <TB1> INFO: Expecting 2560 events.
[14:15:27.593] <TB1> INFO: 2560 events read in total (302ms).
[14:15:27.593] <TB1> INFO: Test took 1198ms.
[14:15:27.597] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:27.901] <TB1> INFO: Expecting 2560 events.
[14:15:28.792] <TB1> INFO: 2560 events read in total (299ms).
[14:15:28.792] <TB1> INFO: Test took 1195ms.
[14:15:28.794] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:29.101] <TB1> INFO: Expecting 2560 events.
[14:15:29.987] <TB1> INFO: 2560 events read in total (294ms).
[14:15:29.988] <TB1> INFO: Test took 1194ms.
[14:15:29.992] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:30.296] <TB1> INFO: Expecting 2560 events.
[14:15:31.181] <TB1> INFO: 2560 events read in total (293ms).
[14:15:31.181] <TB1> INFO: Test took 1189ms.
[14:15:31.183] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:31.489] <TB1> INFO: Expecting 2560 events.
[14:15:32.378] <TB1> INFO: 2560 events read in total (297ms).
[14:15:32.378] <TB1> INFO: Test took 1195ms.
[14:15:32.382] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:32.686] <TB1> INFO: Expecting 2560 events.
[14:15:33.577] <TB1> INFO: 2560 events read in total (299ms).
[14:15:33.577] <TB1> INFO: Test took 1195ms.
[14:15:33.579] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:33.885] <TB1> INFO: Expecting 2560 events.
[14:15:34.769] <TB1> INFO: 2560 events read in total (292ms).
[14:15:34.769] <TB1> INFO: Test took 1190ms.
[14:15:34.771] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:15:35.078] <TB1> INFO: Expecting 2560 events.
[14:15:35.962] <TB1> INFO: 2560 events read in total (293ms).
[14:15:35.963] <TB1> INFO: Test took 1192ms.
[14:15:36.442] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 654 seconds
[14:15:36.442] <TB1> INFO: PH scale (per ROC): 58 54 56 37 55 52 59 41 52 54 49 39 39 58 61 46
[14:15:36.442] <TB1> INFO: PH offset (per ROC): 125 129 130 99 118 107 131 117 140 121 124 95 97 133 137 93
[14:15:36.452] <TB1> INFO: Decoding statistics:
[14:15:36.452] <TB1> INFO: General information:
[14:15:36.452] <TB1> INFO: 16bit words read: 127884
[14:15:36.452] <TB1> INFO: valid events total: 20480
[14:15:36.452] <TB1> INFO: empty events: 17978
[14:15:36.452] <TB1> INFO: valid events with pixels: 2502
[14:15:36.452] <TB1> INFO: valid pixel hits: 2502
[14:15:36.452] <TB1> INFO: Event errors: 0
[14:15:36.452] <TB1> INFO: start marker: 0
[14:15:36.452] <TB1> INFO: stop marker: 0
[14:15:36.452] <TB1> INFO: overflow: 0
[14:15:36.452] <TB1> INFO: invalid 5bit words: 0
[14:15:36.452] <TB1> INFO: invalid XOR eye diagram: 0
[14:15:36.452] <TB1> INFO: frame (failed synchr.): 0
[14:15:36.452] <TB1> INFO: idle data (no TBM trl): 0
[14:15:36.452] <TB1> INFO: no data (only TBM hdr): 0
[14:15:36.452] <TB1> INFO: TBM errors: 0
[14:15:36.452] <TB1> INFO: flawed TBM headers: 0
[14:15:36.452] <TB1> INFO: flawed TBM trailers: 0
[14:15:36.452] <TB1> INFO: event ID mismatches: 0
[14:15:36.452] <TB1> INFO: ROC errors: 0
[14:15:36.452] <TB1> INFO: missing ROC header(s): 0
[14:15:36.452] <TB1> INFO: misplaced readback start: 0
[14:15:36.452] <TB1> INFO: Pixel decoding errors: 0
[14:15:36.452] <TB1> INFO: pixel data incomplete: 0
[14:15:36.452] <TB1> INFO: pixel address: 0
[14:15:36.452] <TB1> INFO: pulse height fill bit: 0
[14:15:36.452] <TB1> INFO: buffer corruption: 0
[14:15:36.615] <TB1> INFO: ######################################################################
[14:15:36.615] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[14:15:36.615] <TB1> INFO: ######################################################################
[14:15:36.630] <TB1> INFO: scanning low vcal = 10
[14:15:36.868] <TB1> INFO: Expecting 41600 events.
[14:15:40.442] <TB1> INFO: 41600 events read in total (2983ms).
[14:15:40.442] <TB1> INFO: Test took 3812ms.
[14:15:40.444] <TB1> INFO: scanning low vcal = 20
[14:15:40.739] <TB1> INFO: Expecting 41600 events.
[14:15:44.349] <TB1> INFO: 41600 events read in total (3019ms).
[14:15:44.349] <TB1> INFO: Test took 3905ms.
[14:15:44.351] <TB1> INFO: scanning low vcal = 30
[14:15:44.642] <TB1> INFO: Expecting 41600 events.
[14:15:48.285] <TB1> INFO: 41600 events read in total (3051ms).
[14:15:48.286] <TB1> INFO: Test took 3935ms.
[14:15:48.289] <TB1> INFO: scanning low vcal = 40
[14:15:48.566] <TB1> INFO: Expecting 41600 events.
[14:15:52.530] <TB1> INFO: 41600 events read in total (3372ms).
[14:15:52.531] <TB1> INFO: Test took 4242ms.
[14:15:52.534] <TB1> INFO: scanning low vcal = 50
[14:15:52.811] <TB1> INFO: Expecting 41600 events.
[14:15:56.826] <TB1> INFO: 41600 events read in total (3423ms).
[14:15:56.827] <TB1> INFO: Test took 4293ms.
[14:15:56.831] <TB1> INFO: scanning low vcal = 60
[14:15:57.108] <TB1> INFO: Expecting 41600 events.
[14:16:01.109] <TB1> INFO: 41600 events read in total (3410ms).
[14:16:01.109] <TB1> INFO: Test took 4278ms.
[14:16:01.113] <TB1> INFO: scanning low vcal = 70
[14:16:01.390] <TB1> INFO: Expecting 41600 events.
[14:16:05.382] <TB1> INFO: 41600 events read in total (3400ms).
[14:16:05.383] <TB1> INFO: Test took 4270ms.
[14:16:05.386] <TB1> INFO: scanning low vcal = 80
[14:16:05.663] <TB1> INFO: Expecting 41600 events.
[14:16:09.674] <TB1> INFO: 41600 events read in total (3419ms).
[14:16:09.675] <TB1> INFO: Test took 4289ms.
[14:16:09.678] <TB1> INFO: scanning low vcal = 90
[14:16:09.954] <TB1> INFO: Expecting 41600 events.
[14:16:14.014] <TB1> INFO: 41600 events read in total (3468ms).
[14:16:14.015] <TB1> INFO: Test took 4337ms.
[14:16:14.019] <TB1> INFO: scanning low vcal = 100
[14:16:14.296] <TB1> INFO: Expecting 41600 events.
[14:16:18.341] <TB1> INFO: 41600 events read in total (3453ms).
[14:16:18.342] <TB1> INFO: Test took 4323ms.
[14:16:18.346] <TB1> INFO: scanning low vcal = 110
[14:16:18.623] <TB1> INFO: Expecting 41600 events.
[14:16:22.620] <TB1> INFO: 41600 events read in total (3406ms).
[14:16:22.621] <TB1> INFO: Test took 4275ms.
[14:16:22.625] <TB1> INFO: scanning low vcal = 120
[14:16:22.902] <TB1> INFO: Expecting 41600 events.
[14:16:26.979] <TB1> INFO: 41600 events read in total (3486ms).
[14:16:26.980] <TB1> INFO: Test took 4355ms.
[14:16:26.983] <TB1> INFO: scanning low vcal = 130
[14:16:27.260] <TB1> INFO: Expecting 41600 events.
[14:16:31.291] <TB1> INFO: 41600 events read in total (3439ms).
[14:16:31.292] <TB1> INFO: Test took 4309ms.
[14:16:31.296] <TB1> INFO: scanning low vcal = 140
[14:16:31.572] <TB1> INFO: Expecting 41600 events.
[14:16:35.564] <TB1> INFO: 41600 events read in total (3400ms).
[14:16:35.564] <TB1> INFO: Test took 4269ms.
[14:16:35.568] <TB1> INFO: scanning low vcal = 150
[14:16:35.847] <TB1> INFO: Expecting 41600 events.
[14:16:39.861] <TB1> INFO: 41600 events read in total (3423ms).
[14:16:39.862] <TB1> INFO: Test took 4294ms.
[14:16:39.867] <TB1> INFO: scanning low vcal = 160
[14:16:40.143] <TB1> INFO: Expecting 41600 events.
[14:16:44.181] <TB1> INFO: 41600 events read in total (3446ms).
[14:16:44.181] <TB1> INFO: Test took 4313ms.
[14:16:44.185] <TB1> INFO: scanning low vcal = 170
[14:16:44.462] <TB1> INFO: Expecting 41600 events.
[14:16:48.467] <TB1> INFO: 41600 events read in total (3413ms).
[14:16:48.468] <TB1> INFO: Test took 4283ms.
[14:16:48.473] <TB1> INFO: scanning low vcal = 180
[14:16:48.747] <TB1> INFO: Expecting 41600 events.
[14:16:52.739] <TB1> INFO: 41600 events read in total (3400ms).
[14:16:52.740] <TB1> INFO: Test took 4266ms.
[14:16:52.744] <TB1> INFO: scanning low vcal = 190
[14:16:53.019] <TB1> INFO: Expecting 41600 events.
[14:16:57.088] <TB1> INFO: 41600 events read in total (3477ms).
[14:16:57.088] <TB1> INFO: Test took 4344ms.
[14:16:57.092] <TB1> INFO: scanning low vcal = 200
[14:16:57.368] <TB1> INFO: Expecting 41600 events.
[14:17:01.364] <TB1> INFO: 41600 events read in total (3404ms).
[14:17:01.366] <TB1> INFO: Test took 4274ms.
[14:17:01.369] <TB1> INFO: scanning low vcal = 210
[14:17:01.646] <TB1> INFO: Expecting 41600 events.
[14:17:05.622] <TB1> INFO: 41600 events read in total (3385ms).
[14:17:05.623] <TB1> INFO: Test took 4253ms.
[14:17:05.627] <TB1> INFO: scanning low vcal = 220
[14:17:05.903] <TB1> INFO: Expecting 41600 events.
[14:17:09.915] <TB1> INFO: 41600 events read in total (3420ms).
[14:17:09.915] <TB1> INFO: Test took 4288ms.
[14:17:09.919] <TB1> INFO: scanning low vcal = 230
[14:17:10.196] <TB1> INFO: Expecting 41600 events.
[14:17:14.217] <TB1> INFO: 41600 events read in total (3430ms).
[14:17:14.218] <TB1> INFO: Test took 4299ms.
[14:17:14.221] <TB1> INFO: scanning low vcal = 240
[14:17:14.499] <TB1> INFO: Expecting 41600 events.
[14:17:18.490] <TB1> INFO: 41600 events read in total (3399ms).
[14:17:18.491] <TB1> INFO: Test took 4269ms.
[14:17:18.494] <TB1> INFO: scanning low vcal = 250
[14:17:18.771] <TB1> INFO: Expecting 41600 events.
[14:17:22.749] <TB1> INFO: 41600 events read in total (3387ms).
[14:17:22.750] <TB1> INFO: Test took 4256ms.
[14:17:22.755] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[14:17:23.031] <TB1> INFO: Expecting 41600 events.
[14:17:27.064] <TB1> INFO: 41600 events read in total (3442ms).
[14:17:27.065] <TB1> INFO: Test took 4310ms.
[14:17:27.070] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[14:17:27.349] <TB1> INFO: Expecting 41600 events.
[14:17:31.334] <TB1> INFO: 41600 events read in total (3394ms).
[14:17:31.335] <TB1> INFO: Test took 4265ms.
[14:17:31.339] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[14:17:31.616] <TB1> INFO: Expecting 41600 events.
[14:17:35.586] <TB1> INFO: 41600 events read in total (3379ms).
[14:17:35.587] <TB1> INFO: Test took 4248ms.
[14:17:35.593] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[14:17:35.868] <TB1> INFO: Expecting 41600 events.
[14:17:39.873] <TB1> INFO: 41600 events read in total (3413ms).
[14:17:39.874] <TB1> INFO: Test took 4281ms.
[14:17:39.878] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[14:17:40.155] <TB1> INFO: Expecting 41600 events.
[14:17:44.215] <TB1> INFO: 41600 events read in total (3468ms).
[14:17:44.215] <TB1> INFO: Test took 4336ms.
[14:17:44.677] <TB1> INFO: PixTestGainPedestal::measure() done
[14:18:20.283] <TB1> INFO: PixTestGainPedestal::fit() done
[14:18:20.283] <TB1> INFO: non-linearity mean: 0.979 0.979 0.977 0.989 0.985 0.975 0.980 0.937 0.983 0.985 0.977 0.931 0.926 0.986 0.984 0.932
[14:18:20.283] <TB1> INFO: non-linearity RMS: 0.004 0.004 0.005 0.183 0.003 0.006 0.003 0.110 0.003 0.004 0.006 0.115 0.115 0.003 0.003 0.143
[14:18:20.283] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[14:18:20.301] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[14:18:20.314] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[14:18:20.327] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[14:18:20.340] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[14:18:20.352] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[14:18:20.365] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[14:18:20.378] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[14:18:20.391] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[14:18:20.404] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[14:18:20.417] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[14:18:20.429] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[14:18:20.442] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[14:18:20.455] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[14:18:20.468] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[14:18:20.480] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[14:18:20.493] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 163 seconds
[14:18:20.493] <TB1> INFO: Decoding statistics:
[14:18:20.493] <TB1> INFO: General information:
[14:18:20.493] <TB1> INFO: 16bit words read: 3327638
[14:18:20.493] <TB1> INFO: valid events total: 332800
[14:18:20.493] <TB1> INFO: empty events: 0
[14:18:20.493] <TB1> INFO: valid events with pixels: 332800
[14:18:20.493] <TB1> INFO: valid pixel hits: 665419
[14:18:20.493] <TB1> INFO: Event errors: 0
[14:18:20.493] <TB1> INFO: start marker: 0
[14:18:20.493] <TB1> INFO: stop marker: 0
[14:18:20.493] <TB1> INFO: overflow: 0
[14:18:20.493] <TB1> INFO: invalid 5bit words: 0
[14:18:20.493] <TB1> INFO: invalid XOR eye diagram: 0
[14:18:20.493] <TB1> INFO: frame (failed synchr.): 0
[14:18:20.493] <TB1> INFO: idle data (no TBM trl): 0
[14:18:20.493] <TB1> INFO: no data (only TBM hdr): 0
[14:18:20.493] <TB1> INFO: TBM errors: 0
[14:18:20.493] <TB1> INFO: flawed TBM headers: 0
[14:18:20.493] <TB1> INFO: flawed TBM trailers: 0
[14:18:20.493] <TB1> INFO: event ID mismatches: 0
[14:18:20.493] <TB1> INFO: ROC errors: 0
[14:18:20.493] <TB1> INFO: missing ROC header(s): 0
[14:18:20.493] <TB1> INFO: misplaced readback start: 0
[14:18:20.493] <TB1> INFO: Pixel decoding errors: 0
[14:18:20.493] <TB1> INFO: pixel data incomplete: 0
[14:18:20.493] <TB1> INFO: pixel address: 0
[14:18:20.493] <TB1> INFO: pulse height fill bit: 0
[14:18:20.493] <TB1> INFO: buffer corruption: 0
[14:18:20.509] <TB1> INFO: Decoding statistics:
[14:18:20.509] <TB1> INFO: General information:
[14:18:20.509] <TB1> INFO: 16bit words read: 3457058
[14:18:20.509] <TB1> INFO: valid events total: 353536
[14:18:20.509] <TB1> INFO: empty events: 18234
[14:18:20.509] <TB1> INFO: valid events with pixels: 335302
[14:18:20.509] <TB1> INFO: valid pixel hits: 667921
[14:18:20.509] <TB1> INFO: Event errors: 0
[14:18:20.509] <TB1> INFO: start marker: 0
[14:18:20.509] <TB1> INFO: stop marker: 0
[14:18:20.509] <TB1> INFO: overflow: 0
[14:18:20.509] <TB1> INFO: invalid 5bit words: 0
[14:18:20.509] <TB1> INFO: invalid XOR eye diagram: 0
[14:18:20.509] <TB1> INFO: frame (failed synchr.): 0
[14:18:20.509] <TB1> INFO: idle data (no TBM trl): 0
[14:18:20.509] <TB1> INFO: no data (only TBM hdr): 0
[14:18:20.509] <TB1> INFO: TBM errors: 0
[14:18:20.509] <TB1> INFO: flawed TBM headers: 0
[14:18:20.509] <TB1> INFO: flawed TBM trailers: 0
[14:18:20.509] <TB1> INFO: event ID mismatches: 0
[14:18:20.509] <TB1> INFO: ROC errors: 0
[14:18:20.509] <TB1> INFO: missing ROC header(s): 0
[14:18:20.509] <TB1> INFO: misplaced readback start: 0
[14:18:20.509] <TB1> INFO: Pixel decoding errors: 0
[14:18:20.509] <TB1> INFO: pixel data incomplete: 0
[14:18:20.509] <TB1> INFO: pixel address: 0
[14:18:20.509] <TB1> INFO: pulse height fill bit: 0
[14:18:20.509] <TB1> INFO: buffer corruption: 0
[14:18:20.509] <TB1> INFO: enter test to run
[14:18:20.509] <TB1> INFO: test: exit no parameter change
[14:18:20.648] <TB1> QUIET: Connection to board 154 closed.
[14:18:20.650] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud