Test Date: 2016-10-19 09:44
Analysis date: 2016-10-19 15:03
Logfile
LogfileView
[11:03:17.369] <TB3> INFO: *** Welcome to pxar ***
[11:03:17.369] <TB3> INFO: *** Today: 2016/10/19
[11:03:17.376] <TB3> INFO: *** Version: c8ba-dirty
[11:03:17.376] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C15.dat
[11:03:17.376] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//tbmParameters_C1b.dat
[11:03:17.376] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//defaultMaskFile.dat
[11:03:17.376] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters_C15.dat
[11:03:17.451] <TB3> INFO: clk: 4
[11:03:17.451] <TB3> INFO: ctr: 4
[11:03:17.451] <TB3> INFO: sda: 19
[11:03:17.451] <TB3> INFO: tin: 9
[11:03:17.451] <TB3> INFO: level: 15
[11:03:17.451] <TB3> INFO: triggerdelay: 0
[11:03:17.451] <TB3> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[11:03:17.451] <TB3> INFO: Log level: INFO
[11:03:17.460] <TB3> INFO: Found DTB DTB_WWVASW
[11:03:17.468] <TB3> QUIET: Connection to board DTB_WWVASW opened.
[11:03:17.470] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 126
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWVASW
MAC address: 40D85511807E
Hostname: pixelDTB126
Comment:
------------------------------------------------------
[11:03:17.472] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[11:03:18.969] <TB3> INFO: DUT info:
[11:03:18.969] <TB3> INFO: The DUT currently contains the following objects:
[11:03:18.969] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[11:03:18.969] <TB3> INFO: TBM Core alpha (0): 7 registers set
[11:03:18.969] <TB3> INFO: TBM Core beta (1): 7 registers set
[11:03:18.969] <TB3> INFO: TBM Core alpha (2): 7 registers set
[11:03:18.969] <TB3> INFO: TBM Core beta (3): 7 registers set
[11:03:18.969] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[11:03:18.969] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:18.969] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:03:19.370] <TB3> INFO: enter 'restricted' command line mode
[11:03:19.370] <TB3> INFO: enter test to run
[11:03:19.370] <TB3> INFO: test: pretest no parameter change
[11:03:19.370] <TB3> INFO: running: pretest
[11:03:19.379] <TB3> INFO: ######################################################################
[11:03:19.379] <TB3> INFO: PixTestPretest::doTest()
[11:03:19.379] <TB3> INFO: ######################################################################
[11:03:19.380] <TB3> INFO: ----------------------------------------------------------------------
[11:03:19.380] <TB3> INFO: PixTestPretest::programROC()
[11:03:19.380] <TB3> INFO: ----------------------------------------------------------------------
[11:03:37.394] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:03:37.394] <TB3> INFO: IA differences per ROC: 19.3 16.1 20.9 16.9 21.7 18.5 17.7 16.9 20.1 18.5 19.3 18.5 15.3 20.1 18.5 20.9
[11:03:37.457] <TB3> INFO: ----------------------------------------------------------------------
[11:03:37.457] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:03:37.457] <TB3> INFO: ----------------------------------------------------------------------
[11:03:58.763] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 383.5 mA = 23.9688 mA/ROC
[11:03:58.763] <TB3> INFO: i(loss) [mA/ROC]: 19.3 19.3 20.1 20.1 19.3 20.9 18.5 20.1 18.5 20.9 18.5 19.3 19.3 20.1 19.3 20.1
[11:03:58.798] <TB3> INFO: ----------------------------------------------------------------------
[11:03:58.798] <TB3> INFO: PixTestPretest::findTiming()
[11:03:58.798] <TB3> INFO: ----------------------------------------------------------------------
[11:03:58.798] <TB3> INFO: PixTestCmd::init()
[11:03:59.377] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!

[11:04:30.910] <TB3> INFO: TBM phases: 160MHz: 0, 400MHz: 6, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[11:04:30.910] <TB3> INFO: (success/tries = 100/100), width = 3
[11:04:32.415] <TB3> INFO: ----------------------------------------------------------------------
[11:04:32.415] <TB3> INFO: PixTestPretest::findWorkingPixel()
[11:04:32.415] <TB3> INFO: ----------------------------------------------------------------------
[11:04:32.507] <TB3> INFO: Expecting 231680 events.
[11:04:42.434] <TB3> INFO: 231680 events read in total (9335ms).
[11:04:42.443] <TB3> INFO: Test took 10025ms.
[11:04:42.684] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:04:42.722] <TB3> INFO: ----------------------------------------------------------------------
[11:04:42.723] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[11:04:42.723] <TB3> INFO: ----------------------------------------------------------------------
[11:04:42.819] <TB3> INFO: Expecting 231680 events.
[11:04:52.888] <TB3> INFO: 231680 events read in total (9478ms).
[11:04:52.898] <TB3> INFO: Test took 10169ms.
[11:04:53.160] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[11:04:53.160] <TB3> INFO: CalDel: 106 101 82 91 105 116 92 81 98 84 99 111 97 93 97 84
[11:04:53.160] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[11:04:53.164] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C0.dat
[11:04:53.164] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C1.dat
[11:04:53.165] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C2.dat
[11:04:53.165] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C3.dat
[11:04:53.165] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C4.dat
[11:04:53.165] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C5.dat
[11:04:53.165] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C6.dat
[11:04:53.165] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C7.dat
[11:04:53.166] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C8.dat
[11:04:53.166] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C9.dat
[11:04:53.166] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C10.dat
[11:04:53.166] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C11.dat
[11:04:53.166] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C12.dat
[11:04:53.167] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C13.dat
[11:04:53.167] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C14.dat
[11:04:53.167] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters_C15.dat
[11:04:53.167] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//tbmParameters_C0a.dat
[11:04:53.167] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//tbmParameters_C0b.dat
[11:04:53.167] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//tbmParameters_C1a.dat
[11:04:53.167] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//tbmParameters_C1b.dat
[11:04:53.168] <TB3> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[11:04:53.222] <TB3> INFO: enter test to run
[11:04:53.222] <TB3> INFO: test: FullTest no parameter change
[11:04:53.222] <TB3> INFO: running: fulltest
[11:04:53.222] <TB3> INFO: ######################################################################
[11:04:53.222] <TB3> INFO: PixTestFullTest::doTest()
[11:04:53.222] <TB3> INFO: ######################################################################
[11:04:53.223] <TB3> INFO: ######################################################################
[11:04:53.223] <TB3> INFO: PixTestAlive::doTest()
[11:04:53.223] <TB3> INFO: ######################################################################
[11:04:53.225] <TB3> INFO: ----------------------------------------------------------------------
[11:04:53.225] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:04:53.225] <TB3> INFO: ----------------------------------------------------------------------
[11:04:53.466] <TB3> INFO: Expecting 41600 events.
[11:04:57.015] <TB3> INFO: 41600 events read in total (2958ms).
[11:04:57.016] <TB3> INFO: Test took 3789ms.
[11:04:57.253] <TB3> INFO: PixTestAlive::aliveTest() done
[11:04:57.253] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:04:57.255] <TB3> INFO: ----------------------------------------------------------------------
[11:04:57.255] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:04:57.255] <TB3> INFO: ----------------------------------------------------------------------
[11:04:57.498] <TB3> INFO: Expecting 41600 events.
[11:05:00.511] <TB3> INFO: 41600 events read in total (2421ms).
[11:05:00.512] <TB3> INFO: Test took 3255ms.
[11:05:00.512] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:05:00.747] <TB3> INFO: PixTestAlive::maskTest() done
[11:05:00.747] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:05:00.749] <TB3> INFO: ----------------------------------------------------------------------
[11:05:00.749] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:05:00.749] <TB3> INFO: ----------------------------------------------------------------------
[11:05:00.993] <TB3> INFO: Expecting 41600 events.
[11:05:04.539] <TB3> INFO: 41600 events read in total (2955ms).
[11:05:04.540] <TB3> INFO: Test took 3789ms.
[11:05:04.774] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[11:05:04.774] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:05:04.774] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[11:05:04.774] <TB3> INFO: Decoding statistics:
[11:05:04.774] <TB3> INFO: General information:
[11:05:04.774] <TB3> INFO: 16bit words read: 0
[11:05:04.774] <TB3> INFO: valid events total: 0
[11:05:04.774] <TB3> INFO: empty events: 0
[11:05:04.774] <TB3> INFO: valid events with pixels: 0
[11:05:04.774] <TB3> INFO: valid pixel hits: 0
[11:05:04.774] <TB3> INFO: Event errors: 0
[11:05:04.774] <TB3> INFO: start marker: 0
[11:05:04.774] <TB3> INFO: stop marker: 0
[11:05:04.774] <TB3> INFO: overflow: 0
[11:05:04.774] <TB3> INFO: invalid 5bit words: 0
[11:05:04.774] <TB3> INFO: invalid XOR eye diagram: 0
[11:05:04.774] <TB3> INFO: frame (failed synchr.): 0
[11:05:04.774] <TB3> INFO: idle data (no TBM trl): 0
[11:05:04.774] <TB3> INFO: no data (only TBM hdr): 0
[11:05:04.774] <TB3> INFO: TBM errors: 0
[11:05:04.774] <TB3> INFO: flawed TBM headers: 0
[11:05:04.774] <TB3> INFO: flawed TBM trailers: 0
[11:05:04.774] <TB3> INFO: event ID mismatches: 0
[11:05:04.774] <TB3> INFO: ROC errors: 0
[11:05:04.775] <TB3> INFO: missing ROC header(s): 0
[11:05:04.775] <TB3> INFO: misplaced readback start: 0
[11:05:04.775] <TB3> INFO: Pixel decoding errors: 0
[11:05:04.775] <TB3> INFO: pixel data incomplete: 0
[11:05:04.775] <TB3> INFO: pixel address: 0
[11:05:04.775] <TB3> INFO: pulse height fill bit: 0
[11:05:04.775] <TB3> INFO: buffer corruption: 0
[11:05:04.782] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C15.dat
[11:05:04.783] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[11:05:04.783] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[11:05:04.783] <TB3> INFO: ######################################################################
[11:05:04.783] <TB3> INFO: PixTestReadback::doTest()
[11:05:04.783] <TB3> INFO: ######################################################################
[11:05:04.783] <TB3> INFO: ----------------------------------------------------------------------
[11:05:04.783] <TB3> INFO: PixTestReadback::CalibrateVd()
[11:05:04.783] <TB3> INFO: ----------------------------------------------------------------------
[11:05:14.767] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C0.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C1.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C2.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C3.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C4.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C5.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C6.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C7.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C8.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C9.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C10.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C11.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C12.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C13.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C14.dat
[11:05:14.768] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C15.dat
[11:05:14.801] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:05:14.801] <TB3> INFO: ----------------------------------------------------------------------
[11:05:14.801] <TB3> INFO: PixTestReadback::CalibrateVa()
[11:05:14.801] <TB3> INFO: ----------------------------------------------------------------------
[11:05:24.741] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C0.dat
[11:05:24.741] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C1.dat
[11:05:24.741] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C2.dat
[11:05:24.741] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C3.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C4.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C5.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C6.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C7.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C8.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C9.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C10.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C11.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C12.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C13.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C14.dat
[11:05:24.742] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C15.dat
[11:05:24.774] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:05:24.774] <TB3> INFO: ----------------------------------------------------------------------
[11:05:24.774] <TB3> INFO: PixTestReadback::readbackVbg()
[11:05:24.774] <TB3> INFO: ----------------------------------------------------------------------
[11:05:32.448] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:05:32.448] <TB3> INFO: ----------------------------------------------------------------------
[11:05:32.448] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[11:05:32.448] <TB3> INFO: ----------------------------------------------------------------------
[11:05:32.448] <TB3> INFO: Vbg will be calibrated using Vd calibration
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 162.2calibrated Vbg = 1.19415 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 148.9calibrated Vbg = 1.1953 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 154.3calibrated Vbg = 1.1913 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 159.5calibrated Vbg = 1.18501 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 147.4calibrated Vbg = 1.18326 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 161.8calibrated Vbg = 1.1955 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 151.7calibrated Vbg = 1.19212 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 155.4calibrated Vbg = 1.19407 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 152.9calibrated Vbg = 1.18665 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 156.6calibrated Vbg = 1.18488 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 151.6calibrated Vbg = 1.17951 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 144.9calibrated Vbg = 1.17939 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 154.1calibrated Vbg = 1.18629 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 146calibrated Vbg = 1.18365 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 149.2calibrated Vbg = 1.1893 :::*/*/*/*/
[11:05:32.448] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 159.4calibrated Vbg = 1.18485 :::*/*/*/*/
[11:05:32.451] <TB3> INFO: ----------------------------------------------------------------------
[11:05:32.451] <TB3> INFO: PixTestReadback::CalibrateIa()
[11:05:32.451] <TB3> INFO: ----------------------------------------------------------------------
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C0.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C1.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C2.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C3.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C4.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C5.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C6.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C7.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C8.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C9.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C10.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C11.dat
[11:08:13.257] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C12.dat
[11:08:13.258] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C13.dat
[11:08:13.258] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C14.dat
[11:08:13.258] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//readbackCal_C15.dat
[11:08:13.292] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:08:13.293] <TB3> INFO: PixTestReadback::doTest() done
[11:08:13.294] <TB3> INFO: Decoding statistics:
[11:08:13.294] <TB3> INFO: General information:
[11:08:13.294] <TB3> INFO: 16bit words read: 1536
[11:08:13.294] <TB3> INFO: valid events total: 256
[11:08:13.294] <TB3> INFO: empty events: 256
[11:08:13.294] <TB3> INFO: valid events with pixels: 0
[11:08:13.294] <TB3> INFO: valid pixel hits: 0
[11:08:13.294] <TB3> INFO: Event errors: 0
[11:08:13.294] <TB3> INFO: start marker: 0
[11:08:13.294] <TB3> INFO: stop marker: 0
[11:08:13.294] <TB3> INFO: overflow: 0
[11:08:13.294] <TB3> INFO: invalid 5bit words: 0
[11:08:13.294] <TB3> INFO: invalid XOR eye diagram: 0
[11:08:13.294] <TB3> INFO: frame (failed synchr.): 0
[11:08:13.294] <TB3> INFO: idle data (no TBM trl): 0
[11:08:13.294] <TB3> INFO: no data (only TBM hdr): 0
[11:08:13.294] <TB3> INFO: TBM errors: 0
[11:08:13.294] <TB3> INFO: flawed TBM headers: 0
[11:08:13.294] <TB3> INFO: flawed TBM trailers: 0
[11:08:13.294] <TB3> INFO: event ID mismatches: 0
[11:08:13.294] <TB3> INFO: ROC errors: 0
[11:08:13.294] <TB3> INFO: missing ROC header(s): 0
[11:08:13.294] <TB3> INFO: misplaced readback start: 0
[11:08:13.294] <TB3> INFO: Pixel decoding errors: 0
[11:08:13.294] <TB3> INFO: pixel data incomplete: 0
[11:08:13.294] <TB3> INFO: pixel address: 0
[11:08:13.294] <TB3> INFO: pulse height fill bit: 0
[11:08:13.294] <TB3> INFO: buffer corruption: 0
[11:08:13.351] <TB3> INFO: ######################################################################
[11:08:13.351] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:08:13.351] <TB3> INFO: ######################################################################
[11:08:13.354] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[11:08:13.411] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:08:13.411] <TB3> INFO: run 1 of 1
[11:08:13.692] <TB3> INFO: Expecting 3120000 events.
[11:08:44.316] <TB3> INFO: 654445 events read in total (30032ms).
[11:08:56.323] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (238) != TBM ID (129)

[11:08:56.476] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 238 238 129 238 238 238 238 238

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

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

[11:08:56.476] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f2 8000 4030 252 21ef 4030 252 21ef e022 c000

[11:08:56.476] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ec 80b1 4030 252 21ef 4070 252 21ef e022 c000

[11:08:56.477] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ed 80c0 4031 252 21ef 4071 252 21ef e022 c000

[11:08:56.477] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4061 21ee 4071 252 21ef e022 c000

[11:08:56.477] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ef 8040 4032 252 21ef 4032 252 21ef e022 c000

[11:08:56.477] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f0 80b1 4030 252 21ed 4070 252 21ef e022 c000

[11:08:56.477] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f1 80c0 4071 252 21ed 4071 252 21ef e022 c000

[11:09:14.470] <TB3> INFO: 1306395 events read in total (60186ms).
[11:09:26.380] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (156) != TBM ID (129)

[11:09:26.535] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 156 156 129 156 156 156 156 156

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

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

[11:09:26.538] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a0 80b1 4070 4ae 2be8 4070 4ae 2bef e022 c000

[11:09:26.538] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09a 8000 4071 4ae 2be9 4071 4ae 2bef e022 c000

[11:09:26.538] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09b 8040 4031 4ae 2be9 4071 4ae 2bef e022 c000

[11:09:26.538] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4061 2bec 4071 4ae 2bef e022 c000

[11:09:26.538] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09d 80c0 4071 4ae 2be8 4071 4ae 2bef e022 c000

[11:09:26.538] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09e 8000 4071 4ae 2be7 4071 4ae 2bef e022 c000

[11:09:26.538] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a09f 8040 4032 4ae 2bea 4072 4ae 2bef e022 c000

[11:09:44.694] <TB3> INFO: 1954130 events read in total (90410ms).
[11:09:56.608] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (211) != TBM ID (129)

[11:09:56.753] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 211 211 129 211 211 211 211 211

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

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

[11:09:56.755] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d7 8040 4030 80a 2bef 4030 80a 2bef e022 c000

[11:09:56.755] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d1 80c0 4031 80a 2bef 4031 80a 2bef e022 c000

[11:09:56.755] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d2 8000 4030 80a 2bef 4030 80a 2bef e022 c000

[11:09:56.755] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4061 2bef 4031 80a 2bef e022 c000

[11:09:56.755] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d4 80b1 4070 80a 2bef 4070 80a 2bef e022 c000

[11:09:56.755] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d5 80c0 4060 80a 2bef 4060 80a 2bef e022 c000

[11:09:56.755] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d6 8000 4070 80a 2bef 4030 80a 2bef e022 c000

[11:10:14.716] <TB3> INFO: 2602375 events read in total (120432ms).
[11:10:24.303] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (8) != TBM ID (129)

[11:10:24.448] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 8 8 129 8 8 8 8 8

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

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

[11:10:24.449] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00c 80b1 4031 a66 2bcc 4071 a66 2bef e022 c000

[11:10:24.449] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a006 8000 4030 a66 2bcc 4070 a66 2bef e022 c000

[11:10:24.449] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a007 8040 4070 a66 2bce 4070 a66 2bef e022 c000

[11:10:24.449] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4061 2bcd 4060 a66 2bef e022 c000

[11:10:24.449] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a009 80c0 4061 a66 2bcc 4061 a66 2bef e022 c000

[11:10:24.449] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00a 8000 4031 a66 2bcc 4061 a66 2bef e022 c000

[11:10:24.449] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00b 8040 4031 a66 2bcd 4071 a66 2bef e022 c000

[11:10:39.538] <TB3> INFO: 3120000 events read in total (145254ms).
[11:10:39.606] <TB3> INFO: Test took 146196ms.
[11:11:04.922] <TB3> INFO: PixTestBBMap::doTest() done with 4 decoding errors: , duration: 171 seconds
[11:11:04.922] <TB3> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 1 0 0 0 0 1 1 0 2 0
[11:11:04.922] <TB3> INFO: separation cut (per ROC): 103 103 113 111 107 101 95 111 93 111 110 93 102 107 96 106
[11:11:04.922] <TB3> INFO: Decoding statistics:
[11:11:04.922] <TB3> INFO: General information:
[11:11:04.922] <TB3> INFO: 16bit words read: 0
[11:11:04.922] <TB3> INFO: valid events total: 0
[11:11:04.922] <TB3> INFO: empty events: 0
[11:11:04.922] <TB3> INFO: valid events with pixels: 0
[11:11:04.922] <TB3> INFO: valid pixel hits: 0
[11:11:04.922] <TB3> INFO: Event errors: 0
[11:11:04.922] <TB3> INFO: start marker: 0
[11:11:04.922] <TB3> INFO: stop marker: 0
[11:11:04.922] <TB3> INFO: overflow: 0
[11:11:04.922] <TB3> INFO: invalid 5bit words: 0
[11:11:04.922] <TB3> INFO: invalid XOR eye diagram: 0
[11:11:04.922] <TB3> INFO: frame (failed synchr.): 0
[11:11:04.922] <TB3> INFO: idle data (no TBM trl): 0
[11:11:04.922] <TB3> INFO: no data (only TBM hdr): 0
[11:11:04.922] <TB3> INFO: TBM errors: 0
[11:11:04.922] <TB3> INFO: flawed TBM headers: 0
[11:11:04.922] <TB3> INFO: flawed TBM trailers: 0
[11:11:04.922] <TB3> INFO: event ID mismatches: 0
[11:11:04.922] <TB3> INFO: ROC errors: 0
[11:11:04.922] <TB3> INFO: missing ROC header(s): 0
[11:11:04.922] <TB3> INFO: misplaced readback start: 0
[11:11:04.922] <TB3> INFO: Pixel decoding errors: 0
[11:11:04.922] <TB3> INFO: pixel data incomplete: 0
[11:11:04.922] <TB3> INFO: pixel address: 0
[11:11:04.922] <TB3> INFO: pulse height fill bit: 0
[11:11:04.922] <TB3> INFO: buffer corruption: 0
[11:11:04.970] <TB3> INFO: ######################################################################
[11:11:04.970] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:11:04.970] <TB3> INFO: ######################################################################
[11:11:04.970] <TB3> INFO: ----------------------------------------------------------------------
[11:11:04.970] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:11:04.970] <TB3> INFO: ----------------------------------------------------------------------
[11:11:04.970] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[11:11:04.983] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:11:04.983] <TB3> INFO: run 1 of 1
[11:11:05.222] <TB3> INFO: Expecting 36608000 events.
[11:11:28.875] <TB3> INFO: 662350 events read in total (23062ms).
[11:11:51.811] <TB3> INFO: 1317300 events read in total (45998ms).
[11:12:14.455] <TB3> INFO: 1969800 events read in total (68642ms).
[11:12:37.346] <TB3> INFO: 2623300 events read in total (91533ms).
[11:13:00.187] <TB3> INFO: 3276400 events read in total (114374ms).
[11:13:23.044] <TB3> INFO: 3930450 events read in total (137231ms).
[11:13:45.732] <TB3> INFO: 4583200 events read in total (159919ms).
[11:14:08.439] <TB3> INFO: 5236050 events read in total (182626ms).
[11:14:31.266] <TB3> INFO: 5889000 events read in total (205453ms).
[11:14:54.007] <TB3> INFO: 6540500 events read in total (228194ms).
[11:15:16.420] <TB3> INFO: 7189800 events read in total (250607ms).
[11:15:39.078] <TB3> INFO: 7840400 events read in total (273265ms).
[11:16:01.814] <TB3> INFO: 8491300 events read in total (296001ms).
[11:16:24.848] <TB3> INFO: 9143250 events read in total (319035ms).
[11:16:47.750] <TB3> INFO: 9793400 events read in total (341937ms).
[11:17:10.551] <TB3> INFO: 10444750 events read in total (364738ms).
[11:17:33.482] <TB3> INFO: 11095550 events read in total (387669ms).
[11:17:56.420] <TB3> INFO: 11745750 events read in total (410607ms).
[11:18:19.362] <TB3> INFO: 12396550 events read in total (433549ms).
[11:18:42.212] <TB3> INFO: 13047000 events read in total (456399ms).
[11:19:04.855] <TB3> INFO: 13696250 events read in total (479042ms).
[11:19:27.525] <TB3> INFO: 14345600 events read in total (501712ms).
[11:19:50.268] <TB3> INFO: 14995950 events read in total (524455ms).
[11:20:13.143] <TB3> INFO: 15645950 events read in total (547330ms).
[11:20:35.839] <TB3> INFO: 16295450 events read in total (570026ms).
[11:20:58.614] <TB3> INFO: 16944650 events read in total (592801ms).
[11:21:20.922] <TB3> INFO: 17590450 events read in total (615109ms).
[11:21:43.611] <TB3> INFO: 18238550 events read in total (637798ms).
[11:22:06.262] <TB3> INFO: 18882200 events read in total (660449ms).
[11:22:29.055] <TB3> INFO: 19526650 events read in total (683242ms).
[11:22:51.446] <TB3> INFO: 20172350 events read in total (705633ms).
[11:23:13.825] <TB3> INFO: 20817050 events read in total (728012ms).
[11:23:36.464] <TB3> INFO: 21460200 events read in total (750652ms).
[11:23:58.979] <TB3> INFO: 22103800 events read in total (773166ms).
[11:24:21.662] <TB3> INFO: 22749000 events read in total (795849ms).
[11:24:44.302] <TB3> INFO: 23394550 events read in total (818489ms).
[11:25:06.829] <TB3> INFO: 24038950 events read in total (841016ms).
[11:25:29.435] <TB3> INFO: 24680700 events read in total (863622ms).
[11:25:52.028] <TB3> INFO: 25323100 events read in total (886215ms).
[11:26:14.614] <TB3> INFO: 25966850 events read in total (908801ms).
[11:26:37.345] <TB3> INFO: 26609550 events read in total (931532ms).
[11:27:00.226] <TB3> INFO: 27253500 events read in total (954413ms).
[11:27:23.424] <TB3> INFO: 27898150 events read in total (977611ms).
[11:27:46.114] <TB3> INFO: 28542000 events read in total (1000301ms).
[11:28:08.916] <TB3> INFO: 29184100 events read in total (1023103ms).
[11:28:31.521] <TB3> INFO: 29824700 events read in total (1045708ms).
[11:28:54.421] <TB3> INFO: 30466950 events read in total (1068608ms).
[11:29:17.162] <TB3> INFO: 31108950 events read in total (1091349ms).
[11:29:39.726] <TB3> INFO: 31751500 events read in total (1113913ms).
[11:30:02.302] <TB3> INFO: 32394250 events read in total (1136489ms).
[11:30:25.133] <TB3> INFO: 33037500 events read in total (1159320ms).
[11:30:47.942] <TB3> INFO: 33682550 events read in total (1182129ms).
[11:31:10.895] <TB3> INFO: 34326650 events read in total (1205082ms).
[11:31:33.881] <TB3> INFO: 34972650 events read in total (1228068ms).
[11:31:56.799] <TB3> INFO: 35618900 events read in total (1250986ms).
[11:32:19.953] <TB3> INFO: 36270700 events read in total (1274140ms).
[11:32:32.247] <TB3> INFO: 36608000 events read in total (1286434ms).
[11:32:32.325] <TB3> INFO: Test took 1287342ms.
[11:32:32.881] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:34.831] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:36.325] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:37.828] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:39.350] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:40.862] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:42.358] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:43.829] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:45.583] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:47.362] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:49.455] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:51.457] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:53.314] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:55.370] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:57.214] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:32:59.095] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[11:33:01.091] <TB3> INFO: PixTestScurves::scurves() done
[11:33:01.091] <TB3> INFO: Vcal mean: 108.04 98.58 111.31 109.24 105.20 104.11 96.83 116.41 102.26 113.69 118.74 102.80 106.34 110.51 101.30 106.88
[11:33:01.091] <TB3> INFO: Vcal RMS: 4.66 5.60 5.20 4.99 5.08 5.59 5.21 5.02 5.20 4.83 5.80 5.68 5.28 7.82 5.06 5.11
[11:33:01.091] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1316 seconds
[11:33:01.091] <TB3> INFO: Decoding statistics:
[11:33:01.091] <TB3> INFO: General information:
[11:33:01.091] <TB3> INFO: 16bit words read: 0
[11:33:01.091] <TB3> INFO: valid events total: 0
[11:33:01.091] <TB3> INFO: empty events: 0
[11:33:01.091] <TB3> INFO: valid events with pixels: 0
[11:33:01.091] <TB3> INFO: valid pixel hits: 0
[11:33:01.091] <TB3> INFO: Event errors: 0
[11:33:01.091] <TB3> INFO: start marker: 0
[11:33:01.091] <TB3> INFO: stop marker: 0
[11:33:01.091] <TB3> INFO: overflow: 0
[11:33:01.091] <TB3> INFO: invalid 5bit words: 0
[11:33:01.091] <TB3> INFO: invalid XOR eye diagram: 0
[11:33:01.091] <TB3> INFO: frame (failed synchr.): 0
[11:33:01.091] <TB3> INFO: idle data (no TBM trl): 0
[11:33:01.091] <TB3> INFO: no data (only TBM hdr): 0
[11:33:01.091] <TB3> INFO: TBM errors: 0
[11:33:01.091] <TB3> INFO: flawed TBM headers: 0
[11:33:01.091] <TB3> INFO: flawed TBM trailers: 0
[11:33:01.091] <TB3> INFO: event ID mismatches: 0
[11:33:01.091] <TB3> INFO: ROC errors: 0
[11:33:01.091] <TB3> INFO: missing ROC header(s): 0
[11:33:01.091] <TB3> INFO: misplaced readback start: 0
[11:33:01.091] <TB3> INFO: Pixel decoding errors: 0
[11:33:01.091] <TB3> INFO: pixel data incomplete: 0
[11:33:01.091] <TB3> INFO: pixel address: 0
[11:33:01.092] <TB3> INFO: pulse height fill bit: 0
[11:33:01.092] <TB3> INFO: buffer corruption: 0
[11:33:01.157] <TB3> INFO: ######################################################################
[11:33:01.157] <TB3> INFO: PixTestTrim::doTest()
[11:33:01.157] <TB3> INFO: ######################################################################
[11:33:01.158] <TB3> INFO: ----------------------------------------------------------------------
[11:33:01.158] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[11:33:01.158] <TB3> INFO: ----------------------------------------------------------------------
[11:33:01.199] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[11:33:01.199] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:33:01.212] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:33:01.212] <TB3> INFO: run 1 of 1
[11:33:01.451] <TB3> INFO: Expecting 5025280 events.
[11:33:31.736] <TB3> INFO: 812800 events read in total (29680ms).
[11:34:01.860] <TB3> INFO: 1622928 events read in total (59804ms).
[11:34:31.575] <TB3> INFO: 2429552 events read in total (89519ms).
[11:35:01.551] <TB3> INFO: 3233816 events read in total (119495ms).
[11:35:31.141] <TB3> INFO: 4035352 events read in total (149085ms).
[11:36:01.786] <TB3> INFO: 4836872 events read in total (179730ms).
[11:36:09.185] <TB3> INFO: 5025280 events read in total (187129ms).
[11:36:09.243] <TB3> INFO: Test took 188030ms.
[11:36:26.542] <TB3> INFO: ROC 0 VthrComp = 117
[11:36:26.542] <TB3> INFO: ROC 1 VthrComp = 106
[11:36:26.542] <TB3> INFO: ROC 2 VthrComp = 128
[11:36:26.543] <TB3> INFO: ROC 3 VthrComp = 120
[11:36:26.543] <TB3> INFO: ROC 4 VthrComp = 117
[11:36:26.543] <TB3> INFO: ROC 5 VthrComp = 109
[11:36:26.543] <TB3> INFO: ROC 6 VthrComp = 101
[11:36:26.543] <TB3> INFO: ROC 7 VthrComp = 127
[11:36:26.544] <TB3> INFO: ROC 8 VthrComp = 108
[11:36:26.544] <TB3> INFO: ROC 9 VthrComp = 125
[11:36:26.544] <TB3> INFO: ROC 10 VthrComp = 127
[11:36:26.544] <TB3> INFO: ROC 11 VthrComp = 107
[11:36:26.544] <TB3> INFO: ROC 12 VthrComp = 107
[11:36:26.544] <TB3> INFO: ROC 13 VthrComp = 117
[11:36:26.544] <TB3> INFO: ROC 14 VthrComp = 109
[11:36:26.544] <TB3> INFO: ROC 15 VthrComp = 122
[11:36:26.785] <TB3> INFO: Expecting 41600 events.
[11:36:30.270] <TB3> INFO: 41600 events read in total (2893ms).
[11:36:30.271] <TB3> INFO: Test took 3724ms.
[11:36:30.280] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:36:30.280] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:36:30.291] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:36:30.291] <TB3> INFO: run 1 of 1
[11:36:30.570] <TB3> INFO: Expecting 5025280 events.
[11:36:56.830] <TB3> INFO: 590080 events read in total (25669ms).
[11:37:22.484] <TB3> INFO: 1178952 events read in total (51323ms).
[11:37:48.178] <TB3> INFO: 1767888 events read in total (77017ms).
[11:38:13.863] <TB3> INFO: 2355120 events read in total (102702ms).
[11:38:40.063] <TB3> INFO: 2940416 events read in total (128902ms).
[11:39:05.668] <TB3> INFO: 3524656 events read in total (154507ms).
[11:39:31.166] <TB3> INFO: 4108048 events read in total (180005ms).
[11:39:56.917] <TB3> INFO: 4690616 events read in total (205756ms).
[11:40:11.385] <TB3> INFO: 5025280 events read in total (220224ms).
[11:40:11.456] <TB3> INFO: Test took 221165ms.
[11:40:35.294] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 58.1538 for pixel 15/14 mean/min/max = 44.9824/31.7029/58.2618
[11:40:35.294] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 59.4738 for pixel 12/2 mean/min/max = 46.4142/33.3024/59.526
[11:40:35.295] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 56.9098 for pixel 21/72 mean/min/max = 44.1645/31.1825/57.1465
[11:40:35.295] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 58.3211 for pixel 0/70 mean/min/max = 45.0759/31.8035/58.3482
[11:40:35.296] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 56.5311 for pixel 44/71 mean/min/max = 44.1246/31.6371/56.6122
[11:40:35.296] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 61.5421 for pixel 16/61 mean/min/max = 47.6823/33.7977/61.567
[11:40:35.297] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 59.4706 for pixel 46/10 mean/min/max = 46.3616/33.2388/59.4844
[11:40:35.297] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 56.7287 for pixel 51/10 mean/min/max = 44.2626/31.5577/56.9675
[11:40:35.298] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 59.3672 for pixel 15/2 mean/min/max = 46.682/33.9709/59.3932
[11:40:35.298] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 58.1293 for pixel 0/39 mean/min/max = 45.0435/31.5762/58.5109
[11:40:35.299] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 59.8049 for pixel 13/61 mean/min/max = 45.0922/30.2983/59.8861
[11:40:35.299] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 61.5782 for pixel 32/75 mean/min/max = 47.5601/33.5208/61.5994
[11:40:35.299] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 62.0761 for pixel 11/40 mean/min/max = 48.1205/34.0117/62.2293
[11:40:35.300] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 62.8857 for pixel 0/79 mean/min/max = 46.214/29.2822/63.1459
[11:40:35.300] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 58.1752 for pixel 20/78 mean/min/max = 46.4319/34.5669/58.2969
[11:40:35.301] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 57.312 for pixel 23/72 mean/min/max = 44.6823/32.0159/57.3487
[11:40:35.301] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:40:35.390] <TB3> INFO: Expecting 411648 events.
[11:40:44.891] <TB3> INFO: 411648 events read in total (8909ms).
[11:40:44.899] <TB3> INFO: Expecting 411648 events.
[11:40:54.167] <TB3> INFO: 411648 events read in total (8865ms).
[11:40:54.179] <TB3> INFO: Expecting 411648 events.
[11:41:03.509] <TB3> INFO: 411648 events read in total (8927ms).
[11:41:03.523] <TB3> INFO: Expecting 411648 events.
[11:41:12.860] <TB3> INFO: 411648 events read in total (8934ms).
[11:41:12.875] <TB3> INFO: Expecting 411648 events.
[11:41:22.219] <TB3> INFO: 411648 events read in total (8941ms).
[11:41:22.239] <TB3> INFO: Expecting 411648 events.
[11:41:31.601] <TB3> INFO: 411648 events read in total (8959ms).
[11:41:31.623] <TB3> INFO: Expecting 411648 events.
[11:41:41.004] <TB3> INFO: 411648 events read in total (8978ms).
[11:41:41.030] <TB3> INFO: Expecting 411648 events.
[11:41:50.288] <TB3> INFO: 411648 events read in total (8855ms).
[11:41:50.316] <TB3> INFO: Expecting 411648 events.
[11:41:59.682] <TB3> INFO: 411648 events read in total (8963ms).
[11:41:59.713] <TB3> INFO: Expecting 411648 events.
[11:42:08.992] <TB3> INFO: 411648 events read in total (8876ms).
[11:42:09.028] <TB3> INFO: Expecting 411648 events.
[11:42:18.480] <TB3> INFO: 411648 events read in total (9049ms).
[11:42:18.517] <TB3> INFO: Expecting 411648 events.
[11:42:27.677] <TB3> INFO: 411648 events read in total (8756ms).
[11:42:27.716] <TB3> INFO: Expecting 411648 events.
[11:42:36.954] <TB3> INFO: 411648 events read in total (8835ms).
[11:42:36.003] <TB3> INFO: Expecting 411648 events.
[11:42:46.252] <TB3> INFO: 411648 events read in total (8846ms).
[11:42:46.305] <TB3> INFO: Expecting 411648 events.
[11:42:55.562] <TB3> INFO: 411648 events read in total (8854ms).
[11:42:55.002] <TB3> INFO: Expecting 411648 events.
[11:43:05.236] <TB3> INFO: 411648 events read in total (8831ms).
[11:43:05.295] <TB3> INFO: Test took 149994ms.
[11:43:06.171] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[11:43:06.185] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:43:06.185] <TB3> INFO: run 1 of 1
[11:43:06.424] <TB3> INFO: Expecting 5025280 events.
[11:43:32.671] <TB3> INFO: 584616 events read in total (25655ms).
[11:43:58.385] <TB3> INFO: 1168912 events read in total (51369ms).
[11:44:24.490] <TB3> INFO: 1752384 events read in total (77474ms).
[11:44:50.660] <TB3> INFO: 2335168 events read in total (103644ms).
[11:45:16.870] <TB3> INFO: 2917320 events read in total (129854ms).
[11:45:43.097] <TB3> INFO: 3498808 events read in total (156081ms).
[11:46:09.795] <TB3> INFO: 4078968 events read in total (182779ms).
[11:46:35.926] <TB3> INFO: 4660064 events read in total (208910ms).
[11:46:52.633] <TB3> INFO: 5025280 events read in total (225617ms).
[11:46:52.897] <TB3> INFO: Test took 226714ms.
[11:47:19.320] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 7.036037 .. 144.507495
[11:47:19.558] <TB3> INFO: Expecting 208000 events.
[11:47:29.421] <TB3> INFO: 208000 events read in total (9272ms).
[11:47:29.422] <TB3> INFO: Test took 10100ms.
[11:47:29.490] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 7 .. 154 (-1/-1) hits flags = 528 (plus default)
[11:47:29.504] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:47:29.504] <TB3> INFO: run 1 of 1
[11:47:29.782] <TB3> INFO: Expecting 4925440 events.
[11:47:55.541] <TB3> INFO: 576696 events read in total (25167ms).
[11:48:21.224] <TB3> INFO: 1153600 events read in total (50850ms).
[11:48:46.634] <TB3> INFO: 1730232 events read in total (76260ms).
[11:49:11.863] <TB3> INFO: 2307008 events read in total (101489ms).
[11:49:37.300] <TB3> INFO: 2883080 events read in total (126926ms).
[11:50:03.201] <TB3> INFO: 3458344 events read in total (152827ms).
[11:50:29.039] <TB3> INFO: 4033184 events read in total (178665ms).
[11:50:54.615] <TB3> INFO: 4608216 events read in total (204241ms).
[11:51:08.726] <TB3> INFO: 4925440 events read in total (218352ms).
[11:51:08.841] <TB3> INFO: Test took 219336ms.
[11:51:32.609] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 27.410632 .. 47.502619
[11:51:32.863] <TB3> INFO: Expecting 208000 events.
[11:51:42.552] <TB3> INFO: 208000 events read in total (9098ms).
[11:51:42.553] <TB3> INFO: Test took 9943ms.
[11:51:42.601] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 57 (-1/-1) hits flags = 528 (plus default)
[11:51:42.614] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:51:42.614] <TB3> INFO: run 1 of 1
[11:51:42.892] <TB3> INFO: Expecting 1364480 events.
[11:52:10.915] <TB3> INFO: 650696 events read in total (27431ms).
[11:52:38.100] <TB3> INFO: 1299808 events read in total (54617ms).
[11:52:41.235] <TB3> INFO: 1364480 events read in total (57752ms).
[11:52:41.271] <TB3> INFO: Test took 58657ms.
[11:52:56.150] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 24.846375 .. 44.613007
[11:52:56.429] <TB3> INFO: Expecting 208000 events.
[11:53:06.472] <TB3> INFO: 208000 events read in total (9452ms).
[11:53:06.473] <TB3> INFO: Test took 10321ms.
[11:53:06.544] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 14 .. 54 (-1/-1) hits flags = 528 (plus default)
[11:53:06.558] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:53:06.558] <TB3> INFO: run 1 of 1
[11:53:06.836] <TB3> INFO: Expecting 1364480 events.
[11:53:35.836] <TB3> INFO: 675336 events read in total (28408ms).
[11:54:03.926] <TB3> INFO: 1349168 events read in total (56498ms).
[11:54:04.982] <TB3> INFO: 1364480 events read in total (57555ms).
[11:54:05.014] <TB3> INFO: Test took 58456ms.
[11:54:18.698] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 24.359240 .. 44.613007
[11:54:18.937] <TB3> INFO: Expecting 208000 events.
[11:54:28.516] <TB3> INFO: 208000 events read in total (8988ms).
[11:54:28.516] <TB3> INFO: Test took 9817ms.
[11:54:28.564] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 14 .. 54 (-1/-1) hits flags = 528 (plus default)
[11:54:28.577] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:54:28.577] <TB3> INFO: run 1 of 1
[11:54:28.855] <TB3> INFO: Expecting 1364480 events.
[11:54:57.184] <TB3> INFO: 675896 events read in total (27737ms).
[11:55:25.324] <TB3> INFO: 1351256 events read in total (55877ms).
[11:55:26.300] <TB3> INFO: 1364480 events read in total (56853ms).
[11:55:26.326] <TB3> INFO: Test took 57749ms.
[11:55:40.386] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[11:55:40.386] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:55:40.400] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[11:55:40.400] <TB3> INFO: run 1 of 1
[11:55:40.636] <TB3> INFO: Expecting 1364480 events.
[11:56:09.642] <TB3> INFO: 667312 events read in total (28414ms).
[11:56:37.789] <TB3> INFO: 1333952 events read in total (56561ms).
[11:56:39.447] <TB3> INFO: 1364480 events read in total (58220ms).
[11:56:39.474] <TB3> INFO: Test took 59074ms.
[11:56:52.424] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C0.dat
[11:56:52.424] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C1.dat
[11:56:52.424] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C2.dat
[11:56:52.424] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C3.dat
[11:56:52.424] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C4.dat
[11:56:52.424] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C5.dat
[11:56:52.424] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C6.dat
[11:56:52.425] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C7.dat
[11:56:52.425] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C8.dat
[11:56:52.425] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C9.dat
[11:56:52.425] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C10.dat
[11:56:52.425] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C11.dat
[11:56:52.425] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C12.dat
[11:56:52.425] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C13.dat
[11:56:52.425] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C14.dat
[11:56:52.425] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C15.dat
[11:56:52.425] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C0.dat
[11:56:52.432] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C1.dat
[11:56:52.438] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C2.dat
[11:56:52.445] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C3.dat
[11:56:52.451] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C4.dat
[11:56:52.457] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C5.dat
[11:56:52.464] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C6.dat
[11:56:52.470] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C7.dat
[11:56:52.476] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C8.dat
[11:56:52.482] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C9.dat
[11:56:52.488] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C10.dat
[11:56:52.494] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C11.dat
[11:56:52.501] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C12.dat
[11:56:52.507] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C13.dat
[11:56:52.513] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C14.dat
[11:56:52.520] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//trimParameters35_C15.dat
[11:56:52.526] <TB3> INFO: PixTestTrim::trimTest() done
[11:56:52.526] <TB3> INFO: vtrim: 122 137 132 122 124 150 132 119 125 144 134 119 132 117 128 129
[11:56:52.526] <TB3> INFO: vthrcomp: 117 106 128 120 117 109 101 127 108 125 127 107 107 117 109 122
[11:56:52.526] <TB3> INFO: vcal mean: 34.98 34.97 35.01 34.91 34.97 34.99 34.94 34.97 35.01 34.97 34.91 35.02 34.91 34.99 35.03 34.95
[11:56:52.526] <TB3> INFO: vcal RMS: 1.09 0.97 1.06 1.06 1.01 0.99 0.99 1.07 0.99 1.07 1.10 1.00 1.06 1.15 0.93 0.98
[11:56:52.526] <TB3> INFO: bits mean: 10.00 9.15 10.24 9.25 10.26 9.40 9.45 9.78 9.16 9.78 9.88 8.79 8.80 8.79 8.99 9.94
[11:56:52.526] <TB3> INFO: bits RMS: 2.61 2.65 2.60 2.91 2.52 2.39 2.53 2.76 2.51 2.66 2.78 2.72 2.56 3.34 2.51 2.61
[11:56:52.535] <TB3> INFO: ----------------------------------------------------------------------
[11:56:52.535] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[11:56:52.535] <TB3> INFO: ----------------------------------------------------------------------
[11:56:52.538] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[11:56:52.552] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:56:52.552] <TB3> INFO: run 1 of 1
[11:56:52.789] <TB3> INFO: Expecting 4160000 events.
[11:57:24.864] <TB3> INFO: 732675 events read in total (31484ms).
[11:57:56.359] <TB3> INFO: 1458645 events read in total (62979ms).
[11:58:27.547] <TB3> INFO: 2181405 events read in total (94167ms).
[11:58:58.702] <TB3> INFO: 2898375 events read in total (125322ms).
[11:59:29.757] <TB3> INFO: 3613420 events read in total (156377ms).
[11:59:53.996] <TB3> INFO: 4160000 events read in total (180616ms).
[11:59:54.244] <TB3> INFO: Test took 181692ms.
[12:00:22.889] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 197 (-1/-1) hits flags = 528 (plus default)
[12:00:22.904] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:00:22.904] <TB3> INFO: run 1 of 1
[12:00:23.144] <TB3> INFO: Expecting 4118400 events.
[12:00:54.911] <TB3> INFO: 710705 events read in total (31176ms).
[12:01:25.781] <TB3> INFO: 1416470 events read in total (62046ms).
[12:01:56.810] <TB3> INFO: 2119745 events read in total (93075ms).
[12:02:27.484] <TB3> INFO: 2818030 events read in total (123749ms).
[12:02:58.416] <TB3> INFO: 3514685 events read in total (154681ms).
[12:03:24.969] <TB3> INFO: 4118400 events read in total (181234ms).
[12:03:25.166] <TB3> INFO: Test took 182262ms.
[12:03:51.028] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 182 (-1/-1) hits flags = 528 (plus default)
[12:03:51.041] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:03:51.041] <TB3> INFO: run 1 of 1
[12:03:51.280] <TB3> INFO: Expecting 3806400 events.
[12:04:23.708] <TB3> INFO: 731050 events read in total (31836ms).
[12:04:55.334] <TB3> INFO: 1456410 events read in total (63462ms).
[12:05:27.033] <TB3> INFO: 2177615 events read in total (95161ms).
[12:05:58.475] <TB3> INFO: 2894335 events read in total (126603ms).
[12:06:29.804] <TB3> INFO: 3610395 events read in total (157932ms).
[12:06:38.570] <TB3> INFO: 3806400 events read in total (166698ms).
[12:06:38.628] <TB3> INFO: Test took 167586ms.
[12:07:03.790] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 182 (-1/-1) hits flags = 528 (plus default)
[12:07:03.803] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:07:03.803] <TB3> INFO: run 1 of 1
[12:07:04.041] <TB3> INFO: Expecting 3806400 events.
[12:07:35.942] <TB3> INFO: 731175 events read in total (31310ms).
[12:08:07.804] <TB3> INFO: 1456535 events read in total (63172ms).
[12:08:39.623] <TB3> INFO: 2178400 events read in total (94991ms).
[12:09:10.519] <TB3> INFO: 2895170 events read in total (125887ms).
[12:09:42.829] <TB3> INFO: 3611400 events read in total (158197ms).
[12:09:51.671] <TB3> INFO: 3806400 events read in total (167039ms).
[12:09:51.728] <TB3> INFO: Test took 167924ms.
[12:10:17.380] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 182 (-1/-1) hits flags = 528 (plus default)
[12:10:17.393] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:10:17.393] <TB3> INFO: run 1 of 1
[12:10:17.630] <TB3> INFO: Expecting 3806400 events.
[12:10:49.153] <TB3> INFO: 731120 events read in total (30931ms).
[12:11:20.877] <TB3> INFO: 1456465 events read in total (62655ms).
[12:11:52.426] <TB3> INFO: 2178150 events read in total (94204ms).
[12:12:23.708] <TB3> INFO: 2894910 events read in total (125486ms).
[12:12:54.824] <TB3> INFO: 3611135 events read in total (156602ms).
[12:13:03.461] <TB3> INFO: 3806400 events read in total (165239ms).
[12:13:03.523] <TB3> INFO: Test took 166129ms.
[12:13:27.787] <TB3> INFO: PixTestTrim::trimBitTest() done
[12:13:27.788] <TB3> INFO: PixTestTrim::doTest() done, duration: 2426 seconds
[12:13:27.788] <TB3> INFO: Decoding statistics:
[12:13:27.788] <TB3> INFO: General information:
[12:13:27.788] <TB3> INFO: 16bit words read: 0
[12:13:27.788] <TB3> INFO: valid events total: 0
[12:13:27.788] <TB3> INFO: empty events: 0
[12:13:27.788] <TB3> INFO: valid events with pixels: 0
[12:13:27.788] <TB3> INFO: valid pixel hits: 0
[12:13:27.788] <TB3> INFO: Event errors: 0
[12:13:27.789] <TB3> INFO: start marker: 0
[12:13:27.789] <TB3> INFO: stop marker: 0
[12:13:27.789] <TB3> INFO: overflow: 0
[12:13:27.789] <TB3> INFO: invalid 5bit words: 0
[12:13:27.789] <TB3> INFO: invalid XOR eye diagram: 0
[12:13:27.789] <TB3> INFO: frame (failed synchr.): 0
[12:13:27.789] <TB3> INFO: idle data (no TBM trl): 0
[12:13:27.789] <TB3> INFO: no data (only TBM hdr): 0
[12:13:27.789] <TB3> INFO: TBM errors: 0
[12:13:27.789] <TB3> INFO: flawed TBM headers: 0
[12:13:27.789] <TB3> INFO: flawed TBM trailers: 0
[12:13:27.789] <TB3> INFO: event ID mismatches: 0
[12:13:27.789] <TB3> INFO: ROC errors: 0
[12:13:27.789] <TB3> INFO: missing ROC header(s): 0
[12:13:27.789] <TB3> INFO: misplaced readback start: 0
[12:13:27.789] <TB3> INFO: Pixel decoding errors: 0
[12:13:27.789] <TB3> INFO: pixel data incomplete: 0
[12:13:27.789] <TB3> INFO: pixel address: 0
[12:13:27.789] <TB3> INFO: pulse height fill bit: 0
[12:13:27.789] <TB3> INFO: buffer corruption: 0
[12:13:28.512] <TB3> INFO: ######################################################################
[12:13:28.512] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:13:28.512] <TB3> INFO: ######################################################################
[12:13:28.752] <TB3> INFO: Expecting 41600 events.
[12:13:32.302] <TB3> INFO: 41600 events read in total (2959ms).
[12:13:32.303] <TB3> INFO: Test took 3790ms.
[12:13:32.744] <TB3> INFO: Expecting 41600 events.
[12:13:36.285] <TB3> INFO: 41600 events read in total (2949ms).
[12:13:36.286] <TB3> INFO: Test took 3779ms.
[12:13:36.575] <TB3> INFO: Expecting 41600 events.
[12:13:40.062] <TB3> INFO: 41600 events read in total (2895ms).
[12:13:40.063] <TB3> INFO: Test took 3752ms.
[12:13:40.354] <TB3> INFO: Expecting 41600 events.
[12:13:43.869] <TB3> INFO: 41600 events read in total (2923ms).
[12:13:43.870] <TB3> INFO: Test took 3781ms.
[12:13:44.159] <TB3> INFO: Expecting 41600 events.
[12:13:47.724] <TB3> INFO: 41600 events read in total (2974ms).
[12:13:47.725] <TB3> INFO: Test took 3831ms.
[12:13:48.014] <TB3> INFO: Expecting 41600 events.
[12:13:51.496] <TB3> INFO: 41600 events read in total (2890ms).
[12:13:51.497] <TB3> INFO: Test took 3748ms.
[12:13:51.787] <TB3> INFO: Expecting 41600 events.
[12:13:55.386] <TB3> INFO: 41600 events read in total (3008ms).
[12:13:55.387] <TB3> INFO: Test took 3865ms.
[12:13:55.676] <TB3> INFO: Expecting 41600 events.
[12:13:59.230] <TB3> INFO: 41600 events read in total (2963ms).
[12:13:59.231] <TB3> INFO: Test took 3820ms.
[12:13:59.521] <TB3> INFO: Expecting 41600 events.
[12:14:03.045] <TB3> INFO: 41600 events read in total (2933ms).
[12:14:03.046] <TB3> INFO: Test took 3790ms.
[12:14:03.335] <TB3> INFO: Expecting 41600 events.
[12:14:06.913] <TB3> INFO: 41600 events read in total (2986ms).
[12:14:06.914] <TB3> INFO: Test took 3844ms.
[12:14:07.206] <TB3> INFO: Expecting 41600 events.
[12:14:10.742] <TB3> INFO: 41600 events read in total (2945ms).
[12:14:10.742] <TB3> INFO: Test took 3801ms.
[12:14:11.031] <TB3> INFO: Expecting 41600 events.
[12:14:14.581] <TB3> INFO: 41600 events read in total (2958ms).
[12:14:14.582] <TB3> INFO: Test took 3815ms.
[12:14:14.873] <TB3> INFO: Expecting 41600 events.
[12:14:18.350] <TB3> INFO: 41600 events read in total (2885ms).
[12:14:18.350] <TB3> INFO: Test took 3741ms.
[12:14:18.639] <TB3> INFO: Expecting 41600 events.
[12:14:22.126] <TB3> INFO: 41600 events read in total (2895ms).
[12:14:22.126] <TB3> INFO: Test took 3751ms.
[12:14:22.416] <TB3> INFO: Expecting 41600 events.
[12:14:26.006] <TB3> INFO: 41600 events read in total (2998ms).
[12:14:26.007] <TB3> INFO: Test took 3856ms.
[12:14:26.296] <TB3> INFO: Expecting 41600 events.
[12:14:29.881] <TB3> INFO: 41600 events read in total (2993ms).
[12:14:29.882] <TB3> INFO: Test took 3851ms.
[12:14:30.174] <TB3> INFO: Expecting 41600 events.
[12:14:33.708] <TB3> INFO: 41600 events read in total (2942ms).
[12:14:33.709] <TB3> INFO: Test took 3800ms.
[12:14:33.999] <TB3> INFO: Expecting 41600 events.
[12:14:37.583] <TB3> INFO: 41600 events read in total (2992ms).
[12:14:37.583] <TB3> INFO: Test took 3849ms.
[12:14:37.872] <TB3> INFO: Expecting 41600 events.
[12:14:41.404] <TB3> INFO: 41600 events read in total (2940ms).
[12:14:41.405] <TB3> INFO: Test took 3797ms.
[12:14:41.715] <TB3> INFO: Expecting 41600 events.
[12:14:45.317] <TB3> INFO: 41600 events read in total (3010ms).
[12:14:45.318] <TB3> INFO: Test took 3888ms.
[12:14:45.607] <TB3> INFO: Expecting 41600 events.
[12:14:49.121] <TB3> INFO: 41600 events read in total (2923ms).
[12:14:49.122] <TB3> INFO: Test took 3780ms.
[12:14:49.412] <TB3> INFO: Expecting 41600 events.
[12:14:52.000] <TB3> INFO: 41600 events read in total (2996ms).
[12:14:52.001] <TB3> INFO: Test took 3855ms.
[12:14:53.292] <TB3> INFO: Expecting 41600 events.
[12:14:56.825] <TB3> INFO: 41600 events read in total (2942ms).
[12:14:56.826] <TB3> INFO: Test took 3800ms.
[12:14:57.116] <TB3> INFO: Expecting 41600 events.
[12:15:00.657] <TB3> INFO: 41600 events read in total (2949ms).
[12:15:00.658] <TB3> INFO: Test took 3808ms.
[12:15:00.948] <TB3> INFO: Expecting 41600 events.
[12:15:04.456] <TB3> INFO: 41600 events read in total (2916ms).
[12:15:04.457] <TB3> INFO: Test took 3774ms.
[12:15:04.749] <TB3> INFO: Expecting 41600 events.
[12:15:08.278] <TB3> INFO: 41600 events read in total (2937ms).
[12:15:08.279] <TB3> INFO: Test took 3795ms.
[12:15:08.572] <TB3> INFO: Expecting 41600 events.
[12:15:12.070] <TB3> INFO: 41600 events read in total (2906ms).
[12:15:12.071] <TB3> INFO: Test took 3765ms.
[12:15:12.361] <TB3> INFO: Expecting 41600 events.
[12:15:15.838] <TB3> INFO: 41600 events read in total (2885ms).
[12:15:15.838] <TB3> INFO: Test took 3742ms.
[12:15:16.129] <TB3> INFO: Expecting 41600 events.
[12:15:19.675] <TB3> INFO: 41600 events read in total (2955ms).
[12:15:19.676] <TB3> INFO: Test took 3813ms.
[12:15:19.966] <TB3> INFO: Expecting 41600 events.
[12:15:23.511] <TB3> INFO: 41600 events read in total (2954ms).
[12:15:23.512] <TB3> INFO: Test took 3811ms.
[12:15:23.808] <TB3> INFO: Expecting 41600 events.
[12:15:27.443] <TB3> INFO: 41600 events read in total (3043ms).
[12:15:27.444] <TB3> INFO: Test took 3901ms.
[12:15:27.737] <TB3> INFO: Expecting 2560 events.
[12:15:28.622] <TB3> INFO: 2560 events read in total (294ms).
[12:15:28.623] <TB3> INFO: Test took 1163ms.
[12:15:28.929] <TB3> INFO: Expecting 2560 events.
[12:15:29.821] <TB3> INFO: 2560 events read in total (300ms).
[12:15:29.822] <TB3> INFO: Test took 1199ms.
[12:15:30.130] <TB3> INFO: Expecting 2560 events.
[12:15:31.022] <TB3> INFO: 2560 events read in total (301ms).
[12:15:31.022] <TB3> INFO: Test took 1200ms.
[12:15:31.330] <TB3> INFO: Expecting 2560 events.
[12:15:32.220] <TB3> INFO: 2560 events read in total (299ms).
[12:15:32.220] <TB3> INFO: Test took 1197ms.
[12:15:32.529] <TB3> INFO: Expecting 2560 events.
[12:15:33.421] <TB3> INFO: 2560 events read in total (300ms).
[12:15:33.421] <TB3> INFO: Test took 1200ms.
[12:15:33.729] <TB3> INFO: Expecting 2560 events.
[12:15:34.613] <TB3> INFO: 2560 events read in total (292ms).
[12:15:34.613] <TB3> INFO: Test took 1191ms.
[12:15:34.922] <TB3> INFO: Expecting 2560 events.
[12:15:35.801] <TB3> INFO: 2560 events read in total (287ms).
[12:15:35.801] <TB3> INFO: Test took 1187ms.
[12:15:36.109] <TB3> INFO: Expecting 2560 events.
[12:15:36.990] <TB3> INFO: 2560 events read in total (289ms).
[12:15:36.991] <TB3> INFO: Test took 1189ms.
[12:15:37.298] <TB3> INFO: Expecting 2560 events.
[12:15:38.178] <TB3> INFO: 2560 events read in total (288ms).
[12:15:38.179] <TB3> INFO: Test took 1188ms.
[12:15:38.485] <TB3> INFO: Expecting 2560 events.
[12:15:39.372] <TB3> INFO: 2560 events read in total (295ms).
[12:15:39.372] <TB3> INFO: Test took 1193ms.
[12:15:39.681] <TB3> INFO: Expecting 2560 events.
[12:15:40.561] <TB3> INFO: 2560 events read in total (288ms).
[12:15:40.562] <TB3> INFO: Test took 1189ms.
[12:15:40.870] <TB3> INFO: Expecting 2560 events.
[12:15:41.751] <TB3> INFO: 2560 events read in total (289ms).
[12:15:41.751] <TB3> INFO: Test took 1189ms.
[12:15:42.058] <TB3> INFO: Expecting 2560 events.
[12:15:42.946] <TB3> INFO: 2560 events read in total (296ms).
[12:15:42.946] <TB3> INFO: Test took 1194ms.
[12:15:43.256] <TB3> INFO: Expecting 2560 events.
[12:15:44.145] <TB3> INFO: 2560 events read in total (297ms).
[12:15:44.145] <TB3> INFO: Test took 1198ms.
[12:15:44.453] <TB3> INFO: Expecting 2560 events.
[12:15:45.342] <TB3> INFO: 2560 events read in total (297ms).
[12:15:45.342] <TB3> INFO: Test took 1197ms.
[12:15:45.651] <TB3> INFO: Expecting 2560 events.
[12:15:46.542] <TB3> INFO: 2560 events read in total (300ms).
[12:15:46.542] <TB3> INFO: Test took 1199ms.
[12:15:46.546] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:15:46.850] <TB3> INFO: Expecting 655360 events.
[12:16:01.710] <TB3> INFO: 655360 events read in total (14268ms).
[12:16:01.724] <TB3> INFO: Expecting 655360 events.
[12:16:16.898] <TB3> INFO: 655360 events read in total (14771ms).
[12:16:16.914] <TB3> INFO: Expecting 655360 events.
[12:16:31.587] <TB3> INFO: 655360 events read in total (14270ms).
[12:16:31.613] <TB3> INFO: Expecting 655360 events.
[12:16:46.204] <TB3> INFO: 655360 events read in total (14188ms).
[12:16:46.236] <TB3> INFO: Expecting 655360 events.
[12:17:00.757] <TB3> INFO: 655360 events read in total (14118ms).
[12:17:00.786] <TB3> INFO: Expecting 655360 events.
[12:17:15.374] <TB3> INFO: 655360 events read in total (14185ms).
[12:17:15.407] <TB3> INFO: Expecting 655360 events.
[12:17:30.064] <TB3> INFO: 655360 events read in total (14254ms).
[12:17:30.102] <TB3> INFO: Expecting 655360 events.
[12:17:44.693] <TB3> INFO: 655360 events read in total (14187ms).
[12:17:44.737] <TB3> INFO: Expecting 655360 events.
[12:17:59.443] <TB3> INFO: 655360 events read in total (14303ms).
[12:17:59.490] <TB3> INFO: Expecting 655360 events.
[12:18:14.035] <TB3> INFO: 655360 events read in total (14142ms).
[12:18:14.086] <TB3> INFO: Expecting 655360 events.
[12:18:28.693] <TB3> INFO: 655360 events read in total (14204ms).
[12:18:28.750] <TB3> INFO: Expecting 655360 events.
[12:18:43.289] <TB3> INFO: 655360 events read in total (14136ms).
[12:18:43.430] <TB3> INFO: Expecting 655360 events.
[12:18:58.007] <TB3> INFO: 655360 events read in total (14174ms).
[12:18:58.090] <TB3> INFO: Expecting 655360 events.
[12:19:12.691] <TB3> INFO: 655360 events read in total (14198ms).
[12:19:12.894] <TB3> INFO: Expecting 655360 events.
[12:19:27.555] <TB3> INFO: 655360 events read in total (14257ms).
[12:19:27.648] <TB3> INFO: Expecting 655360 events.
[12:19:42.237] <TB3> INFO: 655360 events read in total (14186ms).
[12:19:42.333] <TB3> INFO: Test took 235787ms.
[12:19:42.438] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:19:42.688] <TB3> INFO: Expecting 655360 events.
[12:19:57.303] <TB3> INFO: 655360 events read in total (14023ms).
[12:19:57.315] <TB3> INFO: Expecting 655360 events.
[12:20:11.988] <TB3> INFO: 655360 events read in total (14270ms).
[12:20:12.007] <TB3> INFO: Expecting 655360 events.
[12:20:26.554] <TB3> INFO: 655360 events read in total (14144ms).
[12:20:26.574] <TB3> INFO: Expecting 655360 events.
[12:20:41.205] <TB3> INFO: 655360 events read in total (14228ms).
[12:20:41.230] <TB3> INFO: Expecting 655360 events.
[12:20:55.452] <TB3> INFO: 655360 events read in total (13819ms).
[12:20:55.481] <TB3> INFO: Expecting 655360 events.
[12:21:09.947] <TB3> INFO: 655360 events read in total (14063ms).
[12:21:09.983] <TB3> INFO: Expecting 655360 events.
[12:21:24.404] <TB3> INFO: 655360 events read in total (14018ms).
[12:21:24.443] <TB3> INFO: Expecting 655360 events.
[12:21:38.833] <TB3> INFO: 655360 events read in total (13987ms).
[12:21:38.889] <TB3> INFO: Expecting 655360 events.
[12:21:53.241] <TB3> INFO: 655360 events read in total (13949ms).
[12:21:53.289] <TB3> INFO: Expecting 655360 events.
[12:22:07.786] <TB3> INFO: 655360 events read in total (14094ms).
[12:22:07.837] <TB3> INFO: Expecting 655360 events.
[12:22:22.258] <TB3> INFO: 655360 events read in total (14017ms).
[12:22:22.314] <TB3> INFO: Expecting 655360 events.
[12:22:36.885] <TB3> INFO: 655360 events read in total (14168ms).
[12:22:37.152] <TB3> INFO: Expecting 655360 events.
[12:22:51.616] <TB3> INFO: 655360 events read in total (14061ms).
[12:22:51.712] <TB3> INFO: Expecting 655360 events.
[12:23:06.465] <TB3> INFO: 655360 events read in total (14350ms).
[12:23:06.703] <TB3> INFO: Expecting 655360 events.
[12:23:21.483] <TB3> INFO: 655360 events read in total (14377ms).
[12:23:21.711] <TB3> INFO: Expecting 655360 events.
[12:23:36.313] <TB3> INFO: 655360 events read in total (14199ms).
[12:23:36.509] <TB3> INFO: Test took 234071ms.
[12:23:36.681] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.687] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.693] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.698] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.704] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.710] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:23:36.715] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:23:36.722] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[12:23:36.728] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[12:23:36.733] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.739] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:23:36.745] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:23:36.751] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[12:23:36.757] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[12:23:36.762] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[12:23:36.768] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.774] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.779] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:23:36.785] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:23:36.791] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.796] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.802] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.808] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:23:36.813] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:23:36.819] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.825] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.830] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.836] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.842] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:23:36.876] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C0.dat
[12:23:36.876] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C1.dat
[12:23:36.876] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C2.dat
[12:23:36.876] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C3.dat
[12:23:36.876] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C4.dat
[12:23:36.876] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C5.dat
[12:23:36.876] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C6.dat
[12:23:36.877] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C7.dat
[12:23:36.877] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C8.dat
[12:23:36.877] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C9.dat
[12:23:36.877] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C10.dat
[12:23:36.877] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C11.dat
[12:23:36.877] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C12.dat
[12:23:36.877] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C13.dat
[12:23:36.877] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C14.dat
[12:23:36.877] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//dacParameters35_C15.dat
[12:23:37.117] <TB3> INFO: Expecting 41600 events.
[12:23:40.288] <TB3> INFO: 41600 events read in total (2579ms).
[12:23:40.288] <TB3> INFO: Test took 3408ms.
[12:23:40.760] <TB3> INFO: Expecting 41600 events.
[12:23:43.815] <TB3> INFO: 41600 events read in total (2463ms).
[12:23:43.816] <TB3> INFO: Test took 3314ms.
[12:23:44.272] <TB3> INFO: Expecting 41600 events.
[12:23:47.419] <TB3> INFO: 41600 events read in total (2555ms).
[12:23:47.420] <TB3> INFO: Test took 3390ms.
[12:23:47.637] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:47.727] <TB3> INFO: Expecting 2560 events.
[12:23:48.615] <TB3> INFO: 2560 events read in total (296ms).
[12:23:48.616] <TB3> INFO: Test took 979ms.
[12:23:48.618] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:48.925] <TB3> INFO: Expecting 2560 events.
[12:23:49.814] <TB3> INFO: 2560 events read in total (298ms).
[12:23:49.814] <TB3> INFO: Test took 1196ms.
[12:23:49.816] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:50.123] <TB3> INFO: Expecting 2560 events.
[12:23:51.014] <TB3> INFO: 2560 events read in total (299ms).
[12:23:51.015] <TB3> INFO: Test took 1199ms.
[12:23:51.016] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:51.323] <TB3> INFO: Expecting 2560 events.
[12:23:52.211] <TB3> INFO: 2560 events read in total (296ms).
[12:23:52.212] <TB3> INFO: Test took 1196ms.
[12:23:52.215] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:52.520] <TB3> INFO: Expecting 2560 events.
[12:23:53.411] <TB3> INFO: 2560 events read in total (299ms).
[12:23:53.412] <TB3> INFO: Test took 1198ms.
[12:23:53.413] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:53.721] <TB3> INFO: Expecting 2560 events.
[12:23:54.616] <TB3> INFO: 2560 events read in total (304ms).
[12:23:54.617] <TB3> INFO: Test took 1204ms.
[12:23:54.620] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:54.924] <TB3> INFO: Expecting 2560 events.
[12:23:55.811] <TB3> INFO: 2560 events read in total (295ms).
[12:23:55.811] <TB3> INFO: Test took 1191ms.
[12:23:55.814] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:56.119] <TB3> INFO: Expecting 2560 events.
[12:23:56.001] <TB3> INFO: 2560 events read in total (290ms).
[12:23:56.002] <TB3> INFO: Test took 1188ms.
[12:23:57.004] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:57.311] <TB3> INFO: Expecting 2560 events.
[12:23:58.189] <TB3> INFO: 2560 events read in total (288ms).
[12:23:58.190] <TB3> INFO: Test took 1186ms.
[12:23:58.193] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:58.498] <TB3> INFO: Expecting 2560 events.
[12:23:59.381] <TB3> INFO: 2560 events read in total (292ms).
[12:23:59.382] <TB3> INFO: Test took 1189ms.
[12:23:59.384] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:23:59.689] <TB3> INFO: Expecting 2560 events.
[12:24:00.582] <TB3> INFO: 2560 events read in total (301ms).
[12:24:00.583] <TB3> INFO: Test took 1199ms.
[12:24:00.586] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:00.890] <TB3> INFO: Expecting 2560 events.
[12:24:01.770] <TB3> INFO: 2560 events read in total (288ms).
[12:24:01.771] <TB3> INFO: Test took 1185ms.
[12:24:01.774] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:02.078] <TB3> INFO: Expecting 2560 events.
[12:24:02.967] <TB3> INFO: 2560 events read in total (297ms).
[12:24:02.967] <TB3> INFO: Test took 1193ms.
[12:24:02.969] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:03.276] <TB3> INFO: Expecting 2560 events.
[12:24:04.164] <TB3> INFO: 2560 events read in total (296ms).
[12:24:04.165] <TB3> INFO: Test took 1196ms.
[12:24:04.168] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:04.473] <TB3> INFO: Expecting 2560 events.
[12:24:05.353] <TB3> INFO: 2560 events read in total (288ms).
[12:24:05.353] <TB3> INFO: Test took 1185ms.
[12:24:05.355] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:05.662] <TB3> INFO: Expecting 2560 events.
[12:24:06.547] <TB3> INFO: 2560 events read in total (293ms).
[12:24:06.548] <TB3> INFO: Test took 1193ms.
[12:24:06.551] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:06.856] <TB3> INFO: Expecting 2560 events.
[12:24:07.745] <TB3> INFO: 2560 events read in total (297ms).
[12:24:07.746] <TB3> INFO: Test took 1195ms.
[12:24:07.748] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:08.053] <TB3> INFO: Expecting 2560 events.
[12:24:08.944] <TB3> INFO: 2560 events read in total (299ms).
[12:24:08.944] <TB3> INFO: Test took 1196ms.
[12:24:08.947] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:09.253] <TB3> INFO: Expecting 2560 events.
[12:24:10.142] <TB3> INFO: 2560 events read in total (297ms).
[12:24:10.142] <TB3> INFO: Test took 1195ms.
[12:24:10.145] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:10.450] <TB3> INFO: Expecting 2560 events.
[12:24:11.342] <TB3> INFO: 2560 events read in total (300ms).
[12:24:11.343] <TB3> INFO: Test took 1198ms.
[12:24:11.346] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:11.650] <TB3> INFO: Expecting 2560 events.
[12:24:12.531] <TB3> INFO: 2560 events read in total (290ms).
[12:24:12.531] <TB3> INFO: Test took 1186ms.
[12:24:12.533] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:12.840] <TB3> INFO: Expecting 2560 events.
[12:24:13.720] <TB3> INFO: 2560 events read in total (288ms).
[12:24:13.720] <TB3> INFO: Test took 1187ms.
[12:24:13.723] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:14.029] <TB3> INFO: Expecting 2560 events.
[12:24:14.911] <TB3> INFO: 2560 events read in total (290ms).
[12:24:14.912] <TB3> INFO: Test took 1189ms.
[12:24:14.915] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:15.219] <TB3> INFO: Expecting 2560 events.
[12:24:16.109] <TB3> INFO: 2560 events read in total (297ms).
[12:24:16.109] <TB3> INFO: Test took 1194ms.
[12:24:16.113] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:16.417] <TB3> INFO: Expecting 2560 events.
[12:24:17.308] <TB3> INFO: 2560 events read in total (299ms).
[12:24:17.308] <TB3> INFO: Test took 1195ms.
[12:24:17.310] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:17.617] <TB3> INFO: Expecting 2560 events.
[12:24:18.513] <TB3> INFO: 2560 events read in total (304ms).
[12:24:18.513] <TB3> INFO: Test took 1203ms.
[12:24:18.516] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:18.822] <TB3> INFO: Expecting 2560 events.
[12:24:19.717] <TB3> INFO: 2560 events read in total (303ms).
[12:24:19.717] <TB3> INFO: Test took 1201ms.
[12:24:19.719] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:20.027] <TB3> INFO: Expecting 2560 events.
[12:24:20.913] <TB3> INFO: 2560 events read in total (294ms).
[12:24:20.914] <TB3> INFO: Test took 1195ms.
[12:24:20.917] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:21.222] <TB3> INFO: Expecting 2560 events.
[12:24:22.117] <TB3> INFO: 2560 events read in total (303ms).
[12:24:22.117] <TB3> INFO: Test took 1200ms.
[12:24:22.119] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:22.427] <TB3> INFO: Expecting 2560 events.
[12:24:23.320] <TB3> INFO: 2560 events read in total (301ms).
[12:24:23.320] <TB3> INFO: Test took 1201ms.
[12:24:23.322] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:23.630] <TB3> INFO: Expecting 2560 events.
[12:24:24.517] <TB3> INFO: 2560 events read in total (296ms).
[12:24:24.517] <TB3> INFO: Test took 1195ms.
[12:24:24.519] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:24:24.826] <TB3> INFO: Expecting 2560 events.
[12:24:25.722] <TB3> INFO: 2560 events read in total (304ms).
[12:24:25.722] <TB3> INFO: Test took 1204ms.
[12:24:26.210] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 657 seconds
[12:24:26.211] <TB3> INFO: PH scale (per ROC): 60 51 57 69 65 49 50 41 51 48 44 67 63 67 54 66
[12:24:26.211] <TB3> INFO: PH offset (per ROC): 135 103 102 108 125 80 103 98 98 102 98 131 112 110 129 118
[12:24:26.220] <TB3> INFO: Decoding statistics:
[12:24:26.220] <TB3> INFO: General information:
[12:24:26.220] <TB3> INFO: 16bit words read: 127888
[12:24:26.220] <TB3> INFO: valid events total: 20480
[12:24:26.220] <TB3> INFO: empty events: 17976
[12:24:26.220] <TB3> INFO: valid events with pixels: 2504
[12:24:26.220] <TB3> INFO: valid pixel hits: 2504
[12:24:26.220] <TB3> INFO: Event errors: 0
[12:24:26.220] <TB3> INFO: start marker: 0
[12:24:26.220] <TB3> INFO: stop marker: 0
[12:24:26.220] <TB3> INFO: overflow: 0
[12:24:26.220] <TB3> INFO: invalid 5bit words: 0
[12:24:26.220] <TB3> INFO: invalid XOR eye diagram: 0
[12:24:26.220] <TB3> INFO: frame (failed synchr.): 0
[12:24:26.220] <TB3> INFO: idle data (no TBM trl): 0
[12:24:26.220] <TB3> INFO: no data (only TBM hdr): 0
[12:24:26.220] <TB3> INFO: TBM errors: 0
[12:24:26.220] <TB3> INFO: flawed TBM headers: 0
[12:24:26.220] <TB3> INFO: flawed TBM trailers: 0
[12:24:26.220] <TB3> INFO: event ID mismatches: 0
[12:24:26.220] <TB3> INFO: ROC errors: 0
[12:24:26.220] <TB3> INFO: missing ROC header(s): 0
[12:24:26.221] <TB3> INFO: misplaced readback start: 0
[12:24:26.221] <TB3> INFO: Pixel decoding errors: 0
[12:24:26.221] <TB3> INFO: pixel data incomplete: 0
[12:24:26.221] <TB3> INFO: pixel address: 0
[12:24:26.221] <TB3> INFO: pulse height fill bit: 0
[12:24:26.221] <TB3> INFO: buffer corruption: 0
[12:24:26.381] <TB3> INFO: ######################################################################
[12:24:26.381] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:24:26.381] <TB3> INFO: ######################################################################
[12:24:26.396] <TB3> INFO: scanning low vcal = 10
[12:24:26.678] <TB3> INFO: Expecting 41600 events.
[12:24:30.297] <TB3> INFO: 41600 events read in total (3028ms).
[12:24:30.297] <TB3> INFO: Test took 3901ms.
[12:24:30.299] <TB3> INFO: scanning low vcal = 20
[12:24:30.590] <TB3> INFO: Expecting 41600 events.
[12:24:34.219] <TB3> INFO: 41600 events read in total (3038ms).
[12:24:34.220] <TB3> INFO: Test took 3921ms.
[12:24:34.222] <TB3> INFO: scanning low vcal = 30
[12:24:34.512] <TB3> INFO: Expecting 41600 events.
[12:24:38.203] <TB3> INFO: 41600 events read in total (3099ms).
[12:24:38.204] <TB3> INFO: Test took 3982ms.
[12:24:38.207] <TB3> INFO: scanning low vcal = 40
[12:24:38.484] <TB3> INFO: Expecting 41600 events.
[12:24:42.487] <TB3> INFO: 41600 events read in total (3411ms).
[12:24:42.488] <TB3> INFO: Test took 4281ms.
[12:24:42.491] <TB3> INFO: scanning low vcal = 50
[12:24:42.768] <TB3> INFO: Expecting 41600 events.
[12:24:46.804] <TB3> INFO: 41600 events read in total (3444ms).
[12:24:46.805] <TB3> INFO: Test took 4314ms.
[12:24:46.809] <TB3> INFO: scanning low vcal = 60
[12:24:47.086] <TB3> INFO: Expecting 41600 events.
[12:24:51.153] <TB3> INFO: 41600 events read in total (3475ms).
[12:24:51.153] <TB3> INFO: Test took 4344ms.
[12:24:51.156] <TB3> INFO: scanning low vcal = 70
[12:24:51.434] <TB3> INFO: Expecting 41600 events.
[12:24:55.476] <TB3> INFO: 41600 events read in total (3450ms).
[12:24:55.477] <TB3> INFO: Test took 4321ms.
[12:24:55.480] <TB3> INFO: scanning low vcal = 80
[12:24:55.761] <TB3> INFO: Expecting 41600 events.
[12:24:59.815] <TB3> INFO: 41600 events read in total (3463ms).
[12:24:59.815] <TB3> INFO: Test took 4335ms.
[12:24:59.819] <TB3> INFO: scanning low vcal = 90
[12:25:00.096] <TB3> INFO: Expecting 41600 events.
[12:25:04.111] <TB3> INFO: 41600 events read in total (3423ms).
[12:25:04.112] <TB3> INFO: Test took 4293ms.
[12:25:04.116] <TB3> INFO: scanning low vcal = 100
[12:25:04.392] <TB3> INFO: Expecting 41600 events.
[12:25:08.408] <TB3> INFO: 41600 events read in total (3424ms).
[12:25:08.408] <TB3> INFO: Test took 4292ms.
[12:25:08.411] <TB3> INFO: scanning low vcal = 110
[12:25:08.689] <TB3> INFO: Expecting 41600 events.
[12:25:12.736] <TB3> INFO: 41600 events read in total (3456ms).
[12:25:12.736] <TB3> INFO: Test took 4325ms.
[12:25:12.739] <TB3> INFO: scanning low vcal = 120
[12:25:13.017] <TB3> INFO: Expecting 41600 events.
[12:25:17.059] <TB3> INFO: 41600 events read in total (3450ms).
[12:25:17.059] <TB3> INFO: Test took 4319ms.
[12:25:17.062] <TB3> INFO: scanning low vcal = 130
[12:25:17.340] <TB3> INFO: Expecting 41600 events.
[12:25:21.387] <TB3> INFO: 41600 events read in total (3455ms).
[12:25:21.388] <TB3> INFO: Test took 4325ms.
[12:25:21.391] <TB3> INFO: scanning low vcal = 140
[12:25:21.668] <TB3> INFO: Expecting 41600 events.
[12:25:25.712] <TB3> INFO: 41600 events read in total (3452ms).
[12:25:25.713] <TB3> INFO: Test took 4322ms.
[12:25:25.716] <TB3> INFO: scanning low vcal = 150
[12:25:25.994] <TB3> INFO: Expecting 41600 events.
[12:25:30.051] <TB3> INFO: 41600 events read in total (3465ms).
[12:25:30.052] <TB3> INFO: Test took 4335ms.
[12:25:30.055] <TB3> INFO: scanning low vcal = 160
[12:25:30.332] <TB3> INFO: Expecting 41600 events.
[12:25:34.377] <TB3> INFO: 41600 events read in total (3453ms).
[12:25:34.378] <TB3> INFO: Test took 4323ms.
[12:25:34.381] <TB3> INFO: scanning low vcal = 170
[12:25:34.659] <TB3> INFO: Expecting 41600 events.
[12:25:38.697] <TB3> INFO: 41600 events read in total (3446ms).
[12:25:38.698] <TB3> INFO: Test took 4316ms.
[12:25:38.703] <TB3> INFO: scanning low vcal = 180
[12:25:38.979] <TB3> INFO: Expecting 41600 events.
[12:25:42.928] <TB3> INFO: 41600 events read in total (3356ms).
[12:25:42.929] <TB3> INFO: Test took 4225ms.
[12:25:42.932] <TB3> INFO: scanning low vcal = 190
[12:25:43.209] <TB3> INFO: Expecting 41600 events.
[12:25:47.184] <TB3> INFO: 41600 events read in total (3383ms).
[12:25:47.185] <TB3> INFO: Test took 4253ms.
[12:25:47.188] <TB3> INFO: scanning low vcal = 200
[12:25:47.469] <TB3> INFO: Expecting 41600 events.
[12:25:51.441] <TB3> INFO: 41600 events read in total (3381ms).
[12:25:51.441] <TB3> INFO: Test took 4253ms.
[12:25:51.445] <TB3> INFO: scanning low vcal = 210
[12:25:51.721] <TB3> INFO: Expecting 41600 events.
[12:25:55.676] <TB3> INFO: 41600 events read in total (3363ms).
[12:25:55.677] <TB3> INFO: Test took 4232ms.
[12:25:55.680] <TB3> INFO: scanning low vcal = 220
[12:25:55.956] <TB3> INFO: Expecting 41600 events.
[12:25:59.898] <TB3> INFO: 41600 events read in total (3350ms).
[12:25:59.899] <TB3> INFO: Test took 4219ms.
[12:25:59.902] <TB3> INFO: scanning low vcal = 230
[12:26:00.178] <TB3> INFO: Expecting 41600 events.
[12:26:04.159] <TB3> INFO: 41600 events read in total (3389ms).
[12:26:04.160] <TB3> INFO: Test took 4258ms.
[12:26:04.163] <TB3> INFO: scanning low vcal = 240
[12:26:04.443] <TB3> INFO: Expecting 41600 events.
[12:26:08.382] <TB3> INFO: 41600 events read in total (3347ms).
[12:26:08.383] <TB3> INFO: Test took 4219ms.
[12:26:08.386] <TB3> INFO: scanning low vcal = 250
[12:26:08.662] <TB3> INFO: Expecting 41600 events.
[12:26:12.604] <TB3> INFO: 41600 events read in total (3350ms).
[12:26:12.605] <TB3> INFO: Test took 4219ms.
[12:26:12.609] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[12:26:12.885] <TB3> INFO: Expecting 41600 events.
[12:26:16.899] <TB3> INFO: 41600 events read in total (3423ms).
[12:26:16.900] <TB3> INFO: Test took 4291ms.
[12:26:16.903] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[12:26:17.180] <TB3> INFO: Expecting 41600 events.
[12:26:21.219] <TB3> INFO: 41600 events read in total (3448ms).
[12:26:21.219] <TB3> INFO: Test took 4316ms.
[12:26:21.222] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[12:26:21.499] <TB3> INFO: Expecting 41600 events.
[12:26:25.558] <TB3> INFO: 41600 events read in total (3467ms).
[12:26:25.559] <TB3> INFO: Test took 4337ms.
[12:26:25.563] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[12:26:25.840] <TB3> INFO: Expecting 41600 events.
[12:26:29.951] <TB3> INFO: 41600 events read in total (3520ms).
[12:26:29.952] <TB3> INFO: Test took 4389ms.
[12:26:29.955] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:26:30.232] <TB3> INFO: Expecting 41600 events.
[12:26:34.263] <TB3> INFO: 41600 events read in total (3440ms).
[12:26:34.263] <TB3> INFO: Test took 4308ms.
[12:26:34.671] <TB3> INFO: PixTestGainPedestal::measure() done
[12:27:06.778] <TB3> INFO: PixTestGainPedestal::fit() done
[12:27:06.778] <TB3> INFO: non-linearity mean: 0.981 0.929 0.901 0.978 0.980 0.904 0.921 0.902 0.945 0.908 0.914 0.986 0.981 0.977 0.980 0.976
[12:27:06.778] <TB3> INFO: non-linearity RMS: 0.006 0.092 0.086 0.008 0.004 0.085 0.077 0.223 0.049 0.111 0.160 0.006 0.002 0.006 0.004 0.005
[12:27:06.778] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[12:27:06.792] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[12:27:06.807] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[12:27:06.820] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[12:27:06.834] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[12:27:06.848] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[12:27:06.861] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[12:27:06.875] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[12:27:06.888] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[12:27:06.901] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[12:27:06.916] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[12:27:06.937] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[12:27:06.957] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[12:27:06.977] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[12:27:06.998] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[12:27:07.018] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1014_FullQualification_2016-10-19_09h44m_1476863092//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[12:27:07.039] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 160 seconds
[12:27:07.039] <TB3> INFO: Decoding statistics:
[12:27:07.039] <TB3> INFO: General information:
[12:27:07.039] <TB3> INFO: 16bit words read: 3327976
[12:27:07.039] <TB3> INFO: valid events total: 332800
[12:27:07.039] <TB3> INFO: empty events: 0
[12:27:07.039] <TB3> INFO: valid events with pixels: 332800
[12:27:07.039] <TB3> INFO: valid pixel hits: 665588
[12:27:07.039] <TB3> INFO: Event errors: 0
[12:27:07.039] <TB3> INFO: start marker: 0
[12:27:07.039] <TB3> INFO: stop marker: 0
[12:27:07.039] <TB3> INFO: overflow: 0
[12:27:07.039] <TB3> INFO: invalid 5bit words: 0
[12:27:07.039] <TB3> INFO: invalid XOR eye diagram: 0
[12:27:07.039] <TB3> INFO: frame (failed synchr.): 0
[12:27:07.039] <TB3> INFO: idle data (no TBM trl): 0
[12:27:07.039] <TB3> INFO: no data (only TBM hdr): 0
[12:27:07.039] <TB3> INFO: TBM errors: 0
[12:27:07.039] <TB3> INFO: flawed TBM headers: 0
[12:27:07.039] <TB3> INFO: flawed TBM trailers: 0
[12:27:07.039] <TB3> INFO: event ID mismatches: 0
[12:27:07.040] <TB3> INFO: ROC errors: 0
[12:27:07.040] <TB3> INFO: missing ROC header(s): 0
[12:27:07.040] <TB3> INFO: misplaced readback start: 0
[12:27:07.040] <TB3> INFO: Pixel decoding errors: 0
[12:27:07.040] <TB3> INFO: pixel data incomplete: 0
[12:27:07.040] <TB3> INFO: pixel address: 0
[12:27:07.040] <TB3> INFO: pulse height fill bit: 0
[12:27:07.040] <TB3> INFO: buffer corruption: 0
[12:27:07.061] <TB3> INFO: Decoding statistics:
[12:27:07.061] <TB3> INFO: General information:
[12:27:07.061] <TB3> INFO: 16bit words read: 3457400
[12:27:07.061] <TB3> INFO: valid events total: 353536
[12:27:07.061] <TB3> INFO: empty events: 18232
[12:27:07.061] <TB3> INFO: valid events with pixels: 335304
[12:27:07.061] <TB3> INFO: valid pixel hits: 668092
[12:27:07.061] <TB3> INFO: Event errors: 0
[12:27:07.061] <TB3> INFO: start marker: 0
[12:27:07.061] <TB3> INFO: stop marker: 0
[12:27:07.061] <TB3> INFO: overflow: 0
[12:27:07.061] <TB3> INFO: invalid 5bit words: 0
[12:27:07.061] <TB3> INFO: invalid XOR eye diagram: 0
[12:27:07.061] <TB3> INFO: frame (failed synchr.): 0
[12:27:07.061] <TB3> INFO: idle data (no TBM trl): 0
[12:27:07.061] <TB3> INFO: no data (only TBM hdr): 0
[12:27:07.061] <TB3> INFO: TBM errors: 0
[12:27:07.061] <TB3> INFO: flawed TBM headers: 0
[12:27:07.061] <TB3> INFO: flawed TBM trailers: 0
[12:27:07.061] <TB3> INFO: event ID mismatches: 0
[12:27:07.061] <TB3> INFO: ROC errors: 0
[12:27:07.061] <TB3> INFO: missing ROC header(s): 0
[12:27:07.061] <TB3> INFO: misplaced readback start: 0
[12:27:07.061] <TB3> INFO: Pixel decoding errors: 0
[12:27:07.061] <TB3> INFO: pixel data incomplete: 0
[12:27:07.061] <TB3> INFO: pixel address: 0
[12:27:07.062] <TB3> INFO: pulse height fill bit: 0
[12:27:07.062] <TB3> INFO: buffer corruption: 0
[12:27:07.062] <TB3> INFO: enter test to run
[12:27:07.062] <TB3> INFO: test: exit no parameter change
[12:27:07.189] <TB3> QUIET: Connection to board 126 closed.
[12:27:07.190] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud