Test Date: 2016-10-17 13:57
Analysis date: 2016-10-17 20:48
Logfile
LogfileView
[14:50:35.866] <TB1> INFO: *** Welcome to pxar ***
[14:50:35.866] <TB1> INFO: *** Today: 2016/10/17
[14:50:35.874] <TB1> INFO: *** Version: c8ba-dirty
[14:50:35.874] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C15.dat
[14:50:35.875] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//tbmParameters_C1b.dat
[14:50:35.875] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//defaultMaskFile.dat
[14:50:35.875] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters_C15.dat
[14:50:35.940] <TB1> INFO: clk: 4
[14:50:35.940] <TB1> INFO: ctr: 4
[14:50:35.940] <TB1> INFO: sda: 19
[14:50:35.940] <TB1> INFO: tin: 9
[14:50:35.940] <TB1> INFO: level: 15
[14:50:35.940] <TB1> INFO: triggerdelay: 0
[14:50:35.940] <TB1> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[14:50:35.940] <TB1> INFO: Log level: INFO
[14:50:35.948] <TB1> INFO: Found DTB DTB_WXC03A
[14:50:35.960] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[14:50:35.962] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 154
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXC03A
MAC address: 40D85511809A
Hostname: pixelDTB154
Comment:
------------------------------------------------------
[14:50:35.963] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[14:50:37.455] <TB1> INFO: DUT info:
[14:50:37.455] <TB1> INFO: The DUT currently contains the following objects:
[14:50:37.455] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[14:50:37.455] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:50:37.455] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:50:37.455] <TB1> INFO: TBM Core alpha (2): 7 registers set
[14:50:37.455] <TB1> INFO: TBM Core beta (3): 7 registers set
[14:50:37.455] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[14:50:37.456] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.456] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:50:37.857] <TB1> INFO: enter 'restricted' command line mode
[14:50:37.857] <TB1> INFO: enter test to run
[14:50:37.857] <TB1> INFO: test: pretest no parameter change
[14:50:37.857] <TB1> INFO: running: pretest
[14:50:37.863] <TB1> INFO: ######################################################################
[14:50:37.863] <TB1> INFO: PixTestPretest::doTest()
[14:50:37.863] <TB1> INFO: ######################################################################
[14:50:37.864] <TB1> INFO: ----------------------------------------------------------------------
[14:50:37.864] <TB1> INFO: PixTestPretest::programROC()
[14:50:37.864] <TB1> INFO: ----------------------------------------------------------------------
[14:50:55.877] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[14:50:55.877] <TB1> INFO: IA differences per ROC: 19.3 19.3 17.7 18.5 20.9 19.3 18.5 16.9 20.1 18.5 20.1 17.7 19.3 18.5 18.5 20.9
[14:50:55.939] <TB1> INFO: ----------------------------------------------------------------------
[14:50:55.939] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[14:50:55.939] <TB1> INFO: ----------------------------------------------------------------------
[14:51:17.241] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 395.5 mA = 24.7188 mA/ROC
[14:51:17.241] <TB1> INFO: i(loss) [mA/ROC]: 20.9 19.3 20.9 20.9 20.9 20.1 20.9 20.9 20.1 20.9 19.3 20.9 19.3 19.3 20.1 19.3
[14:51:17.276] <TB1> INFO: ----------------------------------------------------------------------
[14:51:17.276] <TB1> INFO: PixTestPretest::findTiming()
[14:51:17.276] <TB1> INFO: ----------------------------------------------------------------------
[14:51:17.276] <TB1> INFO: PixTestCmd::init()
[14:51:17.855] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[14:51:49.558] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[14:51:49.558] <TB1> INFO: (success/tries = 100/100), width = 3
[14:51:51.065] <TB1> INFO: ----------------------------------------------------------------------
[14:51:51.065] <TB1> INFO: PixTestPretest::findWorkingPixel()
[14:51:51.065] <TB1> INFO: ----------------------------------------------------------------------
[14:51:51.158] <TB1> INFO: Expecting 231680 events.
[14:52:01.059] <TB1> INFO: 231680 events read in total (9309ms).
[14:52:01.067] <TB1> INFO: Test took 9999ms.
[14:52:01.319] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[14:52:01.354] <TB1> INFO: ----------------------------------------------------------------------
[14:52:01.355] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[14:52:01.355] <TB1> INFO: ----------------------------------------------------------------------
[14:52:01.450] <TB1> INFO: Expecting 231680 events.
[14:52:11.324] <TB1> INFO: 231680 events read in total (9283ms).
[14:52:11.333] <TB1> INFO: Test took 9973ms.
[14:52:11.601] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[14:52:11.601] <TB1> INFO: CalDel: 109 101 111 87 120 111 114 117 109 101 80 110 97 89 101 102
[14:52:11.601] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[14:52:11.605] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C0.dat
[14:52:11.605] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C1.dat
[14:52:11.606] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C2.dat
[14:52:11.606] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C3.dat
[14:52:11.606] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C4.dat
[14:52:11.606] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C5.dat
[14:52:11.606] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C6.dat
[14:52:11.607] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C7.dat
[14:52:11.607] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C8.dat
[14:52:11.607] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C9.dat
[14:52:11.607] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C10.dat
[14:52:11.607] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C11.dat
[14:52:11.607] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C12.dat
[14:52:11.608] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C13.dat
[14:52:11.608] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C14.dat
[14:52:11.608] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters_C15.dat
[14:52:11.608] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//tbmParameters_C0a.dat
[14:52:11.608] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//tbmParameters_C0b.dat
[14:52:11.608] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//tbmParameters_C1a.dat
[14:52:11.608] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//tbmParameters_C1b.dat
[14:52:11.608] <TB1> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[14:52:11.659] <TB1> INFO: enter test to run
[14:52:11.659] <TB1> INFO: test: FullTest no parameter change
[14:52:11.659] <TB1> INFO: running: fulltest
[14:52:11.659] <TB1> INFO: ######################################################################
[14:52:11.659] <TB1> INFO: PixTestFullTest::doTest()
[14:52:11.659] <TB1> INFO: ######################################################################
[14:52:11.661] <TB1> INFO: ######################################################################
[14:52:11.661] <TB1> INFO: PixTestAlive::doTest()
[14:52:11.661] <TB1> INFO: ######################################################################
[14:52:11.662] <TB1> INFO: ----------------------------------------------------------------------
[14:52:11.662] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:52:11.662] <TB1> INFO: ----------------------------------------------------------------------
[14:52:11.899] <TB1> INFO: Expecting 41600 events.
[14:52:15.397] <TB1> INFO: 41600 events read in total (2907ms).
[14:52:15.398] <TB1> INFO: Test took 3735ms.
[14:52:15.626] <TB1> INFO: PixTestAlive::aliveTest() done
[14:52:15.626] <TB1> INFO: number of dead pixels (per ROC): 0 0 1 0 0 0 1 1 0 0 0 0 0 0 0 0
[14:52:15.628] <TB1> INFO: ----------------------------------------------------------------------
[14:52:15.628] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:52:15.628] <TB1> INFO: ----------------------------------------------------------------------
[14:52:15.917] <TB1> INFO: Expecting 41600 events.
[14:52:18.864] <TB1> INFO: 41600 events read in total (2355ms).
[14:52:18.864] <TB1> INFO: Test took 3235ms.
[14:52:18.864] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[14:52:19.106] <TB1> INFO: PixTestAlive::maskTest() done
[14:52:19.106] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:52:19.108] <TB1> INFO: ----------------------------------------------------------------------
[14:52:19.108] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:52:19.108] <TB1> INFO: ----------------------------------------------------------------------
[14:52:19.394] <TB1> INFO: Expecting 41600 events.
[14:52:22.981] <TB1> INFO: 41600 events read in total (2996ms).
[14:52:22.981] <TB1> INFO: Test took 3871ms.
[14:52:23.208] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[14:52:23.208] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:52:23.208] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[14:52:23.208] <TB1> INFO: Decoding statistics:
[14:52:23.208] <TB1> INFO: General information:
[14:52:23.208] <TB1> INFO: 16bit words read: 0
[14:52:23.208] <TB1> INFO: valid events total: 0
[14:52:23.208] <TB1> INFO: empty events: 0
[14:52:23.208] <TB1> INFO: valid events with pixels: 0
[14:52:23.208] <TB1> INFO: valid pixel hits: 0
[14:52:23.208] <TB1> INFO: Event errors: 0
[14:52:23.208] <TB1> INFO: start marker: 0
[14:52:23.208] <TB1> INFO: stop marker: 0
[14:52:23.209] <TB1> INFO: overflow: 0
[14:52:23.209] <TB1> INFO: invalid 5bit words: 0
[14:52:23.209] <TB1> INFO: invalid XOR eye diagram: 0
[14:52:23.209] <TB1> INFO: frame (failed synchr.): 0
[14:52:23.209] <TB1> INFO: idle data (no TBM trl): 0
[14:52:23.209] <TB1> INFO: no data (only TBM hdr): 0
[14:52:23.209] <TB1> INFO: TBM errors: 0
[14:52:23.209] <TB1> INFO: flawed TBM headers: 0
[14:52:23.209] <TB1> INFO: flawed TBM trailers: 0
[14:52:23.209] <TB1> INFO: event ID mismatches: 0
[14:52:23.209] <TB1> INFO: ROC errors: 0
[14:52:23.209] <TB1> INFO: missing ROC header(s): 0
[14:52:23.209] <TB1> INFO: misplaced readback start: 0
[14:52:23.209] <TB1> INFO: Pixel decoding errors: 0
[14:52:23.209] <TB1> INFO: pixel data incomplete: 0
[14:52:23.209] <TB1> INFO: pixel address: 0
[14:52:23.209] <TB1> INFO: pulse height fill bit: 0
[14:52:23.209] <TB1> INFO: buffer corruption: 0
[14:52:23.213] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C15.dat
[14:52:23.213] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[14:52:23.213] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[14:52:23.213] <TB1> INFO: ######################################################################
[14:52:23.213] <TB1> INFO: PixTestReadback::doTest()
[14:52:23.213] <TB1> INFO: ######################################################################
[14:52:23.213] <TB1> INFO: ----------------------------------------------------------------------
[14:52:23.213] <TB1> INFO: PixTestReadback::CalibrateVd()
[14:52:23.213] <TB1> INFO: ----------------------------------------------------------------------
[14:52:33.168] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C0.dat
[14:52:33.168] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C1.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C2.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C3.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C4.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C5.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C6.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C7.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C8.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C9.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C10.dat
[14:52:33.169] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C11.dat
[14:52:33.170] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C12.dat
[14:52:33.170] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C13.dat
[14:52:33.170] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C14.dat
[14:52:33.170] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C15.dat
[14:52:33.201] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:52:33.201] <TB1> INFO: ----------------------------------------------------------------------
[14:52:33.201] <TB1> INFO: PixTestReadback::CalibrateVa()
[14:52:33.201] <TB1> INFO: ----------------------------------------------------------------------
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C0.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C1.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C2.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C3.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C4.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C5.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C6.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C7.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C8.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C9.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C10.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C11.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C12.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C13.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C14.dat
[14:52:43.141] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C15.dat
[14:52:43.172] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:52:43.172] <TB1> INFO: ----------------------------------------------------------------------
[14:52:43.172] <TB1> INFO: PixTestReadback::readbackVbg()
[14:52:43.172] <TB1> INFO: ----------------------------------------------------------------------
[14:52:50.842] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:52:50.842] <TB1> INFO: ----------------------------------------------------------------------
[14:52:50.842] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[14:52:50.842] <TB1> INFO: ----------------------------------------------------------------------
[14:52:50.842] <TB1> INFO: Vbg will be calibrated using Vd calibration
[14:52:50.842] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 150.6calibrated Vbg = 1.17971 :::*/*/*/*/
[14:52:50.842] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 154calibrated Vbg = 1.17257 :::*/*/*/*/
[14:52:50.842] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 155.4calibrated Vbg = 1.18212 :::*/*/*/*/
[14:52:50.842] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 153.8calibrated Vbg = 1.17764 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 150.7calibrated Vbg = 1.17223 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 158.6calibrated Vbg = 1.17986 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 152.6calibrated Vbg = 1.18348 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 152.4calibrated Vbg = 1.18025 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 159.8calibrated Vbg = 1.17364 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 150calibrated Vbg = 1.17944 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 152.1calibrated Vbg = 1.16697 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 156.4calibrated Vbg = 1.16947 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 158.8calibrated Vbg = 1.17448 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 146.6calibrated Vbg = 1.17641 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 156.4calibrated Vbg = 1.18047 :::*/*/*/*/
[14:52:50.843] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 157.9calibrated Vbg = 1.18178 :::*/*/*/*/
[14:52:50.845] <TB1> INFO: ----------------------------------------------------------------------
[14:52:50.845] <TB1> INFO: PixTestReadback::CalibrateIa()
[14:52:50.845] <TB1> INFO: ----------------------------------------------------------------------
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C0.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C1.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C2.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C3.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C4.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C5.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C6.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C7.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C8.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C9.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C10.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C11.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C12.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C13.dat
[14:55:31.690] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C14.dat
[14:55:31.691] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//readbackCal_C15.dat
[14:55:31.719] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:55:31.720] <TB1> INFO: PixTestReadback::doTest() done
[14:55:31.720] <TB1> INFO: Decoding statistics:
[14:55:31.720] <TB1> INFO: General information:
[14:55:31.720] <TB1> INFO: 16bit words read: 1536
[14:55:31.720] <TB1> INFO: valid events total: 256
[14:55:31.720] <TB1> INFO: empty events: 256
[14:55:31.720] <TB1> INFO: valid events with pixels: 0
[14:55:31.720] <TB1> INFO: valid pixel hits: 0
[14:55:31.720] <TB1> INFO: Event errors: 0
[14:55:31.720] <TB1> INFO: start marker: 0
[14:55:31.720] <TB1> INFO: stop marker: 0
[14:55:31.720] <TB1> INFO: overflow: 0
[14:55:31.720] <TB1> INFO: invalid 5bit words: 0
[14:55:31.720] <TB1> INFO: invalid XOR eye diagram: 0
[14:55:31.720] <TB1> INFO: frame (failed synchr.): 0
[14:55:31.720] <TB1> INFO: idle data (no TBM trl): 0
[14:55:31.720] <TB1> INFO: no data (only TBM hdr): 0
[14:55:31.720] <TB1> INFO: TBM errors: 0
[14:55:31.720] <TB1> INFO: flawed TBM headers: 0
[14:55:31.720] <TB1> INFO: flawed TBM trailers: 0
[14:55:31.720] <TB1> INFO: event ID mismatches: 0
[14:55:31.720] <TB1> INFO: ROC errors: 0
[14:55:31.720] <TB1> INFO: missing ROC header(s): 0
[14:55:31.720] <TB1> INFO: misplaced readback start: 0
[14:55:31.721] <TB1> INFO: Pixel decoding errors: 0
[14:55:31.721] <TB1> INFO: pixel data incomplete: 0
[14:55:31.721] <TB1> INFO: pixel address: 0
[14:55:31.721] <TB1> INFO: pulse height fill bit: 0
[14:55:31.721] <TB1> INFO: buffer corruption: 0
[14:55:31.768] <TB1> INFO: ######################################################################
[14:55:31.768] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[14:55:31.768] <TB1> INFO: ######################################################################
[14:55:31.771] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[14:55:31.796] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:55:31.796] <TB1> INFO: run 1 of 1
[14:55:32.036] <TB1> INFO: Expecting 3120000 events.
[14:56:02.751] <TB1> INFO: 654650 events read in total (30123ms).
[14:56:14.673] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (187) != TBM ID (129)

[14:56:14.816] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 187 187 129 187 187 187 187 187

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

[14:56:14.816] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:56:14.816] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bf 8040 4063 252 21ef 4063 252 21ef e022 c000

[14:56:14.816] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b9 80c0 4061 252 21ef 4061 252 21ef e022 c000

[14:56:14.816] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ba 8000 4061 252 21ef 4061 252 21ef e022 c000

[14:56:14.816] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4071 21ef 4061 252 21ef e022 c000

[14:56:14.816] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bc 80b1 4061 252 21ef 4061 252 21ef e022 c000

[14:56:14.816] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bd 80c0 4061 252 21ef 4061 252 21ef e022 c000

[14:56:14.816] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0be 8000 4061 252 21ef 4061 252 21ef e022 c000

[14:56:32.589] <TB1> INFO: 1302275 events read in total (59961ms).
[14:56:44.461] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (132) != TBM ID (129)

[14:56:44.599] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 132 132 129 132 132 132 132 132

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

[14:56:44.601] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:56:44.601] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a088 80b1 4060 4060 e022 c000

[14:56:44.601] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a082 8000 4060 4060 e022 c000

[14:56:44.601] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a083 8040 4060 4061 e022 c000

[14:56:44.601] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4071 4ae 21ef e022 c000

[14:56:44.601] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a085 80c0 4060 4060 e022 c000

[14:56:44.601] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a086 8000 4060 4060 e022 c000

[14:56:44.601] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a087 8040 4060 4060 e022 c000

[14:57:02.307] <TB1> INFO: 1947315 events read in total (89679ms).
[14:57:14.161] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (52) != TBM ID (129)

[14:57:14.303] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 52 52 129 52 52 52 52 52

[14:57:14.305] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (53)

[14:57:14.306] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:57:14.306] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a038 80b1 4060 808 29ef 4060 808 29ef e022 c000

[14:57:14.306] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a032 8000 4060 808 29ef 4060 808 29ef e022 c000

[14:57:14.306] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a033 8040 4060 808 29ef 4061 e022 c000

[14:57:14.306] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4071 29ef 4060 808 29ef e022 c000

[14:57:14.306] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a035 80c0 4060 808 29ef 4060 e022 c000

[14:57:14.306] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a036 8000 4060 808 29ef 4060 e022 c000

[14:57:14.306] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a037 8040 4060 808 29ef 4060 808 29ef e022 c000

[14:57:32.006] <TB1> INFO: 2591015 events read in total (119378ms).
[14:57:41.804] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (168) != TBM ID (129)

[14:57:41.946] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 168 168 129 168 168 168 168 168

[14:57:41.946] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (169)

[14:57:41.946] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:57:41.946] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ac 80b1 4060 a62 2def 4060 a62 2ded e022 c000

[14:57:41.946] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a6 8000 4060 a62 2def 4060 a62 2ded e022 c000

[14:57:41.946] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a7 8040 4060 a62 2def 4060 a62 2ded e022 c000

[14:57:41.946] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4071 4071 2def 4060 a62 2ded e022 c000

[14:57:41.946] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a9 80c0 4061 a62 2def 4061 a62 2ded e022 c000

[14:57:41.946] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0aa 8000 4061 a62 2def 4061 a62 2ded e022 c000

[14:57:41.946] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ab 8040 4060 a62 2def 4060 a62 2ded e022 c000

[14:57:57.147] <TB1> INFO: 3120000 events read in total (144519ms).
[14:57:57.237] <TB1> INFO: Test took 145441ms.
[14:58:21.940] <TB1> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 170 seconds
[14:58:21.940] <TB1> INFO: number of dead bumps (per ROC): 1 1 0 0 1 0 0 0 0 0 0 12 28 23 0 1
[14:58:21.940] <TB1> INFO: separation cut (per ROC): 95 109 97 112 100 101 97 93 102 105 103 98 101 95 107 102
[14:58:21.940] <TB1> INFO: Decoding statistics:
[14:58:21.940] <TB1> INFO: General information:
[14:58:21.940] <TB1> INFO: 16bit words read: 0
[14:58:21.940] <TB1> INFO: valid events total: 0
[14:58:21.940] <TB1> INFO: empty events: 0
[14:58:21.940] <TB1> INFO: valid events with pixels: 0
[14:58:21.940] <TB1> INFO: valid pixel hits: 0
[14:58:21.940] <TB1> INFO: Event errors: 0
[14:58:21.940] <TB1> INFO: start marker: 0
[14:58:21.940] <TB1> INFO: stop marker: 0
[14:58:21.940] <TB1> INFO: overflow: 0
[14:58:21.940] <TB1> INFO: invalid 5bit words: 0
[14:58:21.940] <TB1> INFO: invalid XOR eye diagram: 0
[14:58:21.940] <TB1> INFO: frame (failed synchr.): 0
[14:58:21.940] <TB1> INFO: idle data (no TBM trl): 0
[14:58:21.940] <TB1> INFO: no data (only TBM hdr): 0
[14:58:21.940] <TB1> INFO: TBM errors: 0
[14:58:21.940] <TB1> INFO: flawed TBM headers: 0
[14:58:21.940] <TB1> INFO: flawed TBM trailers: 0
[14:58:21.940] <TB1> INFO: event ID mismatches: 0
[14:58:21.940] <TB1> INFO: ROC errors: 0
[14:58:21.940] <TB1> INFO: missing ROC header(s): 0
[14:58:21.940] <TB1> INFO: misplaced readback start: 0
[14:58:21.940] <TB1> INFO: Pixel decoding errors: 0
[14:58:21.940] <TB1> INFO: pixel data incomplete: 0
[14:58:21.940] <TB1> INFO: pixel address: 0
[14:58:21.940] <TB1> INFO: pulse height fill bit: 0
[14:58:21.940] <TB1> INFO: buffer corruption: 0
[14:58:21.978] <TB1> INFO: ######################################################################
[14:58:21.978] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:58:21.978] <TB1> INFO: ######################################################################
[14:58:21.978] <TB1> INFO: ----------------------------------------------------------------------
[14:58:21.978] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:58:21.978] <TB1> INFO: ----------------------------------------------------------------------
[14:58:21.978] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[14:58:21.992] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[14:58:21.992] <TB1> INFO: run 1 of 1
[14:58:22.249] <TB1> INFO: Expecting 36608000 events.
[14:58:45.478] <TB1> INFO: 658900 events read in total (22638ms).
[14:59:08.431] <TB1> INFO: 1307550 events read in total (45591ms).
[14:59:30.865] <TB1> INFO: 1951900 events read in total (68025ms).
[14:59:53.519] <TB1> INFO: 2595850 events read in total (90679ms).
[15:00:16.343] <TB1> INFO: 3241800 events read in total (113503ms).
[15:00:39.159] <TB1> INFO: 3884350 events read in total (136319ms).
[15:01:01.970] <TB1> INFO: 4528500 events read in total (159130ms).
[15:01:24.894] <TB1> INFO: 5173850 events read in total (182054ms).
[15:01:48.260] <TB1> INFO: 5818950 events read in total (205420ms).
[15:02:11.147] <TB1> INFO: 6464750 events read in total (228307ms).
[15:02:34.080] <TB1> INFO: 7108650 events read in total (251240ms).
[15:02:56.701] <TB1> INFO: 7751700 events read in total (273861ms).
[15:03:19.136] <TB1> INFO: 8394650 events read in total (296296ms).
[15:03:42.222] <TB1> INFO: 9039100 events read in total (319382ms).
[15:04:05.034] <TB1> INFO: 9681550 events read in total (342194ms).
[15:04:27.364] <TB1> INFO: 10323350 events read in total (364524ms).
[15:04:49.950] <TB1> INFO: 10963500 events read in total (387110ms).
[15:05:12.702] <TB1> INFO: 11603750 events read in total (409862ms).
[15:05:35.383] <TB1> INFO: 12242100 events read in total (432543ms).
[15:05:58.226] <TB1> INFO: 12881050 events read in total (455386ms).
[15:06:20.871] <TB1> INFO: 13521300 events read in total (478031ms).
[15:06:43.407] <TB1> INFO: 14159450 events read in total (500567ms).
[15:07:06.047] <TB1> INFO: 14799200 events read in total (523207ms).
[15:07:28.809] <TB1> INFO: 15437450 events read in total (545969ms).
[15:07:51.487] <TB1> INFO: 16076100 events read in total (568647ms).
[15:08:14.268] <TB1> INFO: 16715850 events read in total (591428ms).
[15:08:37.437] <TB1> INFO: 17354500 events read in total (614597ms).
[15:09:00.669] <TB1> INFO: 17993900 events read in total (637829ms).
[15:09:23.378] <TB1> INFO: 18630050 events read in total (660538ms).
[15:09:46.451] <TB1> INFO: 19266800 events read in total (683611ms).
[15:10:09.282] <TB1> INFO: 19901500 events read in total (706442ms).
[15:10:31.838] <TB1> INFO: 20536600 events read in total (728998ms).
[15:10:54.618] <TB1> INFO: 21171000 events read in total (751778ms).
[15:11:17.330] <TB1> INFO: 21804800 events read in total (774490ms).
[15:11:39.775] <TB1> INFO: 22438700 events read in total (796935ms).
[15:12:02.509] <TB1> INFO: 23075300 events read in total (819669ms).
[15:12:24.985] <TB1> INFO: 23711650 events read in total (842145ms).
[15:12:47.539] <TB1> INFO: 24346000 events read in total (864699ms).
[15:13:09.865] <TB1> INFO: 24979900 events read in total (887025ms).
[15:13:32.103] <TB1> INFO: 25613900 events read in total (909263ms).
[15:13:54.636] <TB1> INFO: 26248200 events read in total (931796ms).
[15:14:17.017] <TB1> INFO: 26881400 events read in total (954177ms).
[15:14:39.491] <TB1> INFO: 27513300 events read in total (976651ms).
[15:15:02.166] <TB1> INFO: 28145450 events read in total (999326ms).
[15:15:24.593] <TB1> INFO: 28775250 events read in total (1021753ms).
[15:15:47.101] <TB1> INFO: 29406950 events read in total (1044261ms).
[15:16:09.531] <TB1> INFO: 30038600 events read in total (1066691ms).
[15:16:32.138] <TB1> INFO: 30668800 events read in total (1089298ms).
[15:16:54.783] <TB1> INFO: 31300050 events read in total (1111943ms).
[15:17:17.361] <TB1> INFO: 31931650 events read in total (1134521ms).
[15:17:39.876] <TB1> INFO: 32562850 events read in total (1157036ms).
[15:18:02.346] <TB1> INFO: 33193100 events read in total (1179506ms).
[15:18:24.715] <TB1> INFO: 33825600 events read in total (1201875ms).
[15:18:47.168] <TB1> INFO: 34457450 events read in total (1224328ms).
[15:19:09.727] <TB1> INFO: 35089900 events read in total (1246887ms).
[15:19:32.088] <TB1> INFO: 35722100 events read in total (1269248ms).
[15:19:54.796] <TB1> INFO: 36363100 events read in total (1291956ms).
[15:20:03.756] <TB1> INFO: 36608000 events read in total (1300916ms).
[15:20:03.832] <TB1> INFO: Test took 1301839ms.
[15:20:04.258] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:05.931] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:07.644] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:09.538] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:11.601] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:13.626] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:15.538] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:17.256] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:18.852] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:20.607] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:22.408] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:24.179] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:26.450] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:28.659] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:31.080] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:33.498] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:20:35.957] <TB1> INFO: PixTestScurves::scurves() done
[15:20:35.957] <TB1> INFO: Vcal mean: 103.93 113.18 104.45 115.83 108.63 106.78 105.04 99.42 104.35 112.40 97.79 97.42 120.08 99.80 104.82 100.11
[15:20:35.957] <TB1> INFO: Vcal RMS: 5.32 5.41 6.13 5.27 4.39 5.22 5.08 5.14 5.14 4.99 4.96 6.48 6.43 5.34 5.07 6.09
[15:20:35.957] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1333 seconds
[15:20:35.957] <TB1> INFO: Decoding statistics:
[15:20:35.957] <TB1> INFO: General information:
[15:20:35.957] <TB1> INFO: 16bit words read: 0
[15:20:35.957] <TB1> INFO: valid events total: 0
[15:20:35.957] <TB1> INFO: empty events: 0
[15:20:35.957] <TB1> INFO: valid events with pixels: 0
[15:20:35.957] <TB1> INFO: valid pixel hits: 0
[15:20:35.957] <TB1> INFO: Event errors: 0
[15:20:35.957] <TB1> INFO: start marker: 0
[15:20:35.957] <TB1> INFO: stop marker: 0
[15:20:35.957] <TB1> INFO: overflow: 0
[15:20:35.957] <TB1> INFO: invalid 5bit words: 0
[15:20:35.957] <TB1> INFO: invalid XOR eye diagram: 0
[15:20:35.957] <TB1> INFO: frame (failed synchr.): 0
[15:20:35.957] <TB1> INFO: idle data (no TBM trl): 0
[15:20:35.957] <TB1> INFO: no data (only TBM hdr): 0
[15:20:35.957] <TB1> INFO: TBM errors: 0
[15:20:35.957] <TB1> INFO: flawed TBM headers: 0
[15:20:35.957] <TB1> INFO: flawed TBM trailers: 0
[15:20:35.957] <TB1> INFO: event ID mismatches: 0
[15:20:35.957] <TB1> INFO: ROC errors: 0
[15:20:35.957] <TB1> INFO: missing ROC header(s): 0
[15:20:35.957] <TB1> INFO: misplaced readback start: 0
[15:20:35.957] <TB1> INFO: Pixel decoding errors: 0
[15:20:35.957] <TB1> INFO: pixel data incomplete: 0
[15:20:35.957] <TB1> INFO: pixel address: 0
[15:20:35.957] <TB1> INFO: pulse height fill bit: 0
[15:20:35.957] <TB1> INFO: buffer corruption: 0
[15:20:36.021] <TB1> INFO: ######################################################################
[15:20:36.021] <TB1> INFO: PixTestTrim::doTest()
[15:20:36.021] <TB1> INFO: ######################################################################
[15:20:36.023] <TB1> INFO: ----------------------------------------------------------------------
[15:20:36.023] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[15:20:36.023] <TB1> INFO: ----------------------------------------------------------------------
[15:20:36.063] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[15:20:36.063] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:20:36.075] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:20:36.075] <TB1> INFO: run 1 of 1
[15:20:36.311] <TB1> INFO: Expecting 5025280 events.
[15:21:06.576] <TB1> INFO: 807480 events read in total (29664ms).
[15:21:36.370] <TB1> INFO: 1612560 events read in total (59458ms).
[15:22:05.770] <TB1> INFO: 2414096 events read in total (88859ms).
[15:22:35.560] <TB1> INFO: 3211112 events read in total (118648ms).
[15:23:05.133] <TB1> INFO: 4004288 events read in total (148221ms).
[15:23:34.665] <TB1> INFO: 4794512 events read in total (177753ms).
[15:23:43.489] <TB1> INFO: 5025280 events read in total (186577ms).
[15:23:43.554] <TB1> INFO: Test took 187480ms.
[15:24:04.565] <TB1> INFO: ROC 0 VthrComp = 115
[15:24:04.565] <TB1> INFO: ROC 1 VthrComp = 126
[15:24:04.566] <TB1> INFO: ROC 2 VthrComp = 111
[15:24:04.566] <TB1> INFO: ROC 3 VthrComp = 131
[15:24:04.566] <TB1> INFO: ROC 4 VthrComp = 121
[15:24:04.566] <TB1> INFO: ROC 5 VthrComp = 115
[15:24:04.566] <TB1> INFO: ROC 6 VthrComp = 114
[15:24:04.566] <TB1> INFO: ROC 7 VthrComp = 108
[15:24:04.566] <TB1> INFO: ROC 8 VthrComp = 112
[15:24:04.566] <TB1> INFO: ROC 9 VthrComp = 123
[15:24:04.566] <TB1> INFO: ROC 10 VthrComp = 113
[15:24:04.566] <TB1> INFO: ROC 11 VthrComp = 106
[15:24:04.567] <TB1> INFO: ROC 12 VthrComp = 126
[15:24:04.567] <TB1> INFO: ROC 13 VthrComp = 108
[15:24:04.567] <TB1> INFO: ROC 14 VthrComp = 119
[15:24:04.567] <TB1> INFO: ROC 15 VthrComp = 112
[15:24:04.567] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[15:24:04.567] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:24:04.581] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:24:04.581] <TB1> INFO: run 1 of 1
[15:24:04.910] <TB1> INFO: Expecting 5025280 events.
[15:24:31.361] <TB1> INFO: 590416 events read in total (25859ms).
[15:24:57.388] <TB1> INFO: 1179480 events read in total (51886ms).
[15:25:23.521] <TB1> INFO: 1768224 events read in total (78019ms).
[15:25:49.673] <TB1> INFO: 2356728 events read in total (104171ms).
[15:26:15.511] <TB1> INFO: 2943616 events read in total (130009ms).
[15:26:41.558] <TB1> INFO: 3528960 events read in total (156056ms).
[15:27:07.482] <TB1> INFO: 4112760 events read in total (181980ms).
[15:27:33.383] <TB1> INFO: 4694968 events read in total (207881ms).
[15:27:48.204] <TB1> INFO: 5025280 events read in total (222702ms).
[15:27:48.293] <TB1> INFO: Test took 223712ms.
[15:28:14.613] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 58.9286 for pixel 3/43 mean/min/max = 45.4668/31.8928/59.0408
[15:28:14.613] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 59.2216 for pixel 0/66 mean/min/max = 45.6643/32.0635/59.2652
[15:28:14.614] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 62.5253 for pixel 51/12 mean/min/max = 47.7318/32.6479/62.8157
[15:28:14.614] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 58.898 for pixel 3/6 mean/min/max = 45.8293/32.7401/58.9185
[15:28:14.614] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 58.5313 for pixel 3/0 mean/min/max = 45.4749/32.2975/58.6522
[15:28:14.615] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 59.9519 for pixel 24/1 mean/min/max = 45.5487/31.0923/60.0051
[15:28:14.615] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 59.1149 for pixel 50/9 mean/min/max = 45.603/31.964/59.242
[15:28:14.616] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 58.8994 for pixel 17/2 mean/min/max = 46.6565/34.3164/58.9966
[15:28:14.616] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 59.8428 for pixel 19/8 mean/min/max = 46.1409/32.3973/59.8846
[15:28:14.616] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 57.8489 for pixel 3/19 mean/min/max = 44.7573/31.5817/57.933
[15:28:14.617] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 56.9837 for pixel 8/78 mean/min/max = 44.6309/32.2684/56.9934
[15:28:14.617] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 63.1508 for pixel 0/10 mean/min/max = 47.6888/32.2003/63.1772
[15:28:14.618] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 61.0571 for pixel 10/5 mean/min/max = 46.2571/31.2214/61.2927
[15:28:14.618] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 57.6077 for pixel 19/14 mean/min/max = 46.2649/34.6905/57.8393
[15:28:14.618] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 57.1589 for pixel 0/50 mean/min/max = 44.225/30.9792/57.4709
[15:28:14.619] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 61.0973 for pixel 2/1 mean/min/max = 46.307/31.4386/61.1754
[15:28:14.619] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:28:14.708] <TB1> INFO: Expecting 411648 events.
[15:28:24.219] <TB1> INFO: 411648 events read in total (8920ms).
[15:28:24.227] <TB1> INFO: Expecting 411648 events.
[15:28:33.766] <TB1> INFO: 411648 events read in total (9136ms).
[15:28:33.777] <TB1> INFO: Expecting 411648 events.
[15:28:43.188] <TB1> INFO: 411648 events read in total (9008ms).
[15:28:43.202] <TB1> INFO: Expecting 411648 events.
[15:28:52.616] <TB1> INFO: 411648 events read in total (9012ms).
[15:28:52.633] <TB1> INFO: Expecting 411648 events.
[15:29:02.095] <TB1> INFO: 411648 events read in total (9059ms).
[15:29:02.115] <TB1> INFO: Expecting 411648 events.
[15:29:11.672] <TB1> INFO: 411648 events read in total (9154ms).
[15:29:11.695] <TB1> INFO: Expecting 411648 events.
[15:29:21.106] <TB1> INFO: 411648 events read in total (9008ms).
[15:29:21.132] <TB1> INFO: Expecting 411648 events.
[15:29:30.624] <TB1> INFO: 411648 events read in total (9090ms).
[15:29:30.653] <TB1> INFO: Expecting 411648 events.
[15:29:40.142] <TB1> INFO: 411648 events read in total (9086ms).
[15:29:40.176] <TB1> INFO: Expecting 411648 events.
[15:29:49.611] <TB1> INFO: 411648 events read in total (9032ms).
[15:29:49.646] <TB1> INFO: Expecting 411648 events.
[15:29:59.159] <TB1> INFO: 411648 events read in total (9106ms).
[15:29:59.210] <TB1> INFO: Expecting 411648 events.
[15:30:08.648] <TB1> INFO: 411648 events read in total (9035ms).
[15:30:08.688] <TB1> INFO: Expecting 411648 events.
[15:30:17.000] <TB1> INFO: 411648 events read in total (8909ms).
[15:30:18.045] <TB1> INFO: Expecting 411648 events.
[15:30:27.344] <TB1> INFO: 411648 events read in total (8896ms).
[15:30:27.391] <TB1> INFO: Expecting 411648 events.
[15:30:36.940] <TB1> INFO: 411648 events read in total (9146ms).
[15:30:37.032] <TB1> INFO: Expecting 411648 events.
[15:30:46.232] <TB1> INFO: 411648 events read in total (8797ms).
[15:30:46.288] <TB1> INFO: Test took 151669ms.
[15:30:47.251] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[15:30:47.263] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:30:47.263] <TB1> INFO: run 1 of 1
[15:30:47.519] <TB1> INFO: Expecting 5025280 events.
[15:31:14.044] <TB1> INFO: 585464 events read in total (25921ms).
[15:31:40.022] <TB1> INFO: 1168456 events read in total (51899ms).
[15:32:06.128] <TB1> INFO: 1752160 events read in total (78005ms).
[15:32:32.185] <TB1> INFO: 2334936 events read in total (104062ms).
[15:32:58.271] <TB1> INFO: 2916000 events read in total (130148ms).
[15:33:24.461] <TB1> INFO: 3495448 events read in total (156338ms).
[15:33:50.770] <TB1> INFO: 4074920 events read in total (182647ms).
[15:34:16.620] <TB1> INFO: 4653528 events read in total (208497ms).
[15:34:33.331] <TB1> INFO: 5025280 events read in total (225208ms).
[15:34:33.470] <TB1> INFO: Test took 226208ms.
[15:34:56.798] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 11.020083 .. 145.282265
[15:34:57.038] <TB1> INFO: Expecting 208000 events.
[15:35:07.058] <TB1> INFO: 208000 events read in total (9420ms).
[15:35:07.059] <TB1> INFO: Test took 10260ms.
[15:35:07.106] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 1 .. 155 (-1/-1) hits flags = 528 (plus default)
[15:35:07.119] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:35:07.119] <TB1> INFO: run 1 of 1
[15:35:07.398] <TB1> INFO: Expecting 5158400 events.
[15:35:33.542] <TB1> INFO: 584616 events read in total (25552ms).
[15:35:58.988] <TB1> INFO: 1169152 events read in total (50998ms).
[15:36:24.797] <TB1> INFO: 1753440 events read in total (76807ms).
[15:36:50.933] <TB1> INFO: 2337816 events read in total (102943ms).
[15:37:16.584] <TB1> INFO: 2921984 events read in total (128594ms).
[15:37:42.345] <TB1> INFO: 3505136 events read in total (154355ms).
[15:38:08.529] <TB1> INFO: 4088088 events read in total (180539ms).
[15:38:34.703] <TB1> INFO: 4670192 events read in total (206713ms).
[15:38:56.288] <TB1> INFO: 5158400 events read in total (228298ms).
[15:38:56.557] <TB1> INFO: Test took 229437ms.
[15:39:21.295] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 27.247233 .. 47.425788
[15:39:21.539] <TB1> INFO: Expecting 208000 events.
[15:39:31.390] <TB1> INFO: 208000 events read in total (9260ms).
[15:39:31.391] <TB1> INFO: Test took 10093ms.
[15:39:31.442] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 57 (-1/-1) hits flags = 528 (plus default)
[15:39:31.455] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:39:31.455] <TB1> INFO: run 1 of 1
[15:39:31.734] <TB1> INFO: Expecting 1364480 events.
[15:40:01.197] <TB1> INFO: 651688 events read in total (28872ms).
[15:40:28.997] <TB1> INFO: 1302160 events read in total (56674ms).
[15:40:32.073] <TB1> INFO: 1364480 events read in total (59748ms).
[15:40:32.102] <TB1> INFO: Test took 60647ms.
[15:40:45.590] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 25.818906 .. 46.636638
[15:40:45.833] <TB1> INFO: Expecting 208000 events.
[15:40:55.583] <TB1> INFO: 208000 events read in total (9159ms).
[15:40:55.584] <TB1> INFO: Test took 9992ms.
[15:40:55.631] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 15 .. 56 (-1/-1) hits flags = 528 (plus default)
[15:40:55.644] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:40:55.644] <TB1> INFO: run 1 of 1
[15:40:55.922] <TB1> INFO: Expecting 1397760 events.
[15:41:24.054] <TB1> INFO: 663808 events read in total (27540ms).
[15:41:51.718] <TB1> INFO: 1326712 events read in total (55204ms).
[15:41:55.046] <TB1> INFO: 1397760 events read in total (58532ms).
[15:41:55.080] <TB1> INFO: Test took 59436ms.
[15:42:09.779] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 23.971977 .. 45.417491
[15:42:10.015] <TB1> INFO: Expecting 208000 events.
[15:42:19.804] <TB1> INFO: 208000 events read in total (9197ms).
[15:42:19.805] <TB1> INFO: Test took 10025ms.
[15:42:19.862] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 13 .. 55 (-1/-1) hits flags = 528 (plus default)
[15:42:19.876] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:42:19.876] <TB1> INFO: run 1 of 1
[15:42:20.154] <TB1> INFO: Expecting 1431040 events.
[15:42:49.474] <TB1> INFO: 676168 events read in total (28728ms).
[15:43:17.310] <TB1> INFO: 1351560 events read in total (56564ms).
[15:43:20.885] <TB1> INFO: 1431040 events read in total (60140ms).
[15:43:20.912] <TB1> INFO: Test took 61037ms.
[15:43:33.325] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[15:43:33.325] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[15:43:33.339] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:43:33.339] <TB1> INFO: run 1 of 1
[15:43:33.659] <TB1> INFO: Expecting 1364480 events.
[15:44:02.070] <TB1> INFO: 667720 events read in total (27819ms).
[15:44:30.040] <TB1> INFO: 1335112 events read in total (55789ms).
[15:44:31.669] <TB1> INFO: 1364480 events read in total (57419ms).
[15:44:31.696] <TB1> INFO: Test took 58356ms.
[15:44:44.141] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C0.dat
[15:44:44.142] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C1.dat
[15:44:44.142] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C2.dat
[15:44:44.142] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C3.dat
[15:44:44.142] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C4.dat
[15:44:44.142] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C5.dat
[15:44:44.143] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C6.dat
[15:44:44.143] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C7.dat
[15:44:44.143] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C8.dat
[15:44:44.143] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C9.dat
[15:44:44.143] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C10.dat
[15:44:44.143] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C11.dat
[15:44:44.143] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C12.dat
[15:44:44.143] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C13.dat
[15:44:44.143] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C14.dat
[15:44:44.144] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C15.dat
[15:44:44.144] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C0.dat
[15:44:44.151] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C1.dat
[15:44:44.157] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C2.dat
[15:44:44.162] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C3.dat
[15:44:44.166] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C4.dat
[15:44:44.171] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C5.dat
[15:44:44.176] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C6.dat
[15:44:44.180] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C7.dat
[15:44:44.185] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C8.dat
[15:44:44.190] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C9.dat
[15:44:44.194] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C10.dat
[15:44:44.199] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C11.dat
[15:44:44.204] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C12.dat
[15:44:44.208] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C13.dat
[15:44:44.213] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C14.dat
[15:44:44.218] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//trimParameters35_C15.dat
[15:44:44.223] <TB1> INFO: PixTestTrim::trimTest() done
[15:44:44.223] <TB1> INFO: vtrim: 137 133 139 147 130 131 133 130 131 128 149 125 149 112 126 139
[15:44:44.223] <TB1> INFO: vthrcomp: 115 126 111 131 121 115 114 108 112 123 113 106 126 108 119 112
[15:44:44.223] <TB1> INFO: vcal mean: 34.97 34.98 34.98 34.97 34.99 34.94 34.98 34.99 34.97 34.93 34.98 35.05 34.99 34.99 34.94 34.97
[15:44:44.223] <TB1> INFO: vcal RMS: 0.95 1.00 1.10 0.95 0.99 0.99 1.09 1.07 0.95 0.98 0.84 1.01 1.04 0.90 0.91 0.93
[15:44:44.223] <TB1> INFO: bits mean: 9.33 8.92 8.29 9.42 9.45 9.76 9.60 9.24 9.49 9.59 9.71 8.13 9.61 8.74 9.72 9.35
[15:44:44.223] <TB1> INFO: bits RMS: 2.83 2.97 2.89 2.60 2.72 2.74 2.68 2.42 2.63 2.75 2.61 3.04 2.68 2.64 2.85 2.83
[15:44:44.230] <TB1> INFO: ----------------------------------------------------------------------
[15:44:44.230] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[15:44:44.230] <TB1> INFO: ----------------------------------------------------------------------
[15:44:44.232] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[15:44:44.246] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:44:44.246] <TB1> INFO: run 1 of 1
[15:44:44.488] <TB1> INFO: Expecting 4160000 events.
[15:45:16.187] <TB1> INFO: 716315 events read in total (31107ms).
[15:45:46.993] <TB1> INFO: 1426660 events read in total (61913ms).
[15:46:17.946] <TB1> INFO: 2132770 events read in total (92867ms).
[15:46:49.076] <TB1> INFO: 2834300 events read in total (123996ms).
[15:47:19.703] <TB1> INFO: 3532260 events read in total (154623ms).
[15:47:47.059] <TB1> INFO: 4160000 events read in total (181979ms).
[15:47:47.148] <TB1> INFO: Test took 182901ms.
[15:48:11.280] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 196 (-1/-1) hits flags = 528 (plus default)
[15:48:11.294] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:48:11.294] <TB1> INFO: run 1 of 1
[15:48:11.534] <TB1> INFO: Expecting 4097600 events.
[15:48:42.681] <TB1> INFO: 700570 events read in total (30555ms).
[15:49:13.136] <TB1> INFO: 1395970 events read in total (61010ms).
[15:49:43.796] <TB1> INFO: 2087790 events read in total (91670ms).
[15:50:14.295] <TB1> INFO: 2775865 events read in total (122169ms).
[15:50:44.589] <TB1> INFO: 3461170 events read in total (152463ms).
[15:51:12.414] <TB1> INFO: 4097600 events read in total (180288ms).
[15:51:12.579] <TB1> INFO: Test took 181286ms.
[15:51:36.358] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 183 (-1/-1) hits flags = 528 (plus default)
[15:51:36.371] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:51:36.371] <TB1> INFO: run 1 of 1
[15:51:36.620] <TB1> INFO: Expecting 3827200 events.
[15:52:08.267] <TB1> INFO: 716940 events read in total (31056ms).
[15:52:39.349] <TB1> INFO: 1427115 events read in total (62138ms).
[15:53:10.420] <TB1> INFO: 2133080 events read in total (93209ms).
[15:53:41.085] <TB1> INFO: 2835700 events read in total (123874ms).
[15:54:11.358] <TB1> INFO: 3534880 events read in total (154147ms).
[15:54:24.334] <TB1> INFO: 3827200 events read in total (167123ms).
[15:54:24.428] <TB1> INFO: Test took 168056ms.
[15:54:49.641] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 183 (-1/-1) hits flags = 528 (plus default)
[15:54:49.652] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:54:49.652] <TB1> INFO: run 1 of 1
[15:54:49.897] <TB1> INFO: Expecting 3827200 events.
[15:55:21.664] <TB1> INFO: 716755 events read in total (31175ms).
[15:55:52.833] <TB1> INFO: 1427040 events read in total (62344ms).
[15:56:23.898] <TB1> INFO: 2133120 events read in total (93410ms).
[15:56:55.294] <TB1> INFO: 2835695 events read in total (124805ms).
[15:57:26.527] <TB1> INFO: 3535120 events read in total (156038ms).
[15:57:39.498] <TB1> INFO: 3827200 events read in total (169009ms).
[15:57:39.711] <TB1> INFO: Test took 170059ms.
[15:58:07.328] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 183 (-1/-1) hits flags = 528 (plus default)
[15:58:07.342] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:58:07.342] <TB1> INFO: run 1 of 1
[15:58:07.667] <TB1> INFO: Expecting 3827200 events.
[15:58:39.212] <TB1> INFO: 717210 events read in total (30952ms).
[15:59:10.176] <TB1> INFO: 1427625 events read in total (61916ms).
[15:59:41.318] <TB1> INFO: 2133900 events read in total (93058ms).
[16:00:11.788] <TB1> INFO: 2836835 events read in total (123529ms).
[16:00:42.099] <TB1> INFO: 3536335 events read in total (153839ms).
[16:00:54.964] <TB1> INFO: 3827200 events read in total (166704ms).
[16:00:55.191] <TB1> INFO: Test took 167849ms.
[16:01:21.878] <TB1> INFO: PixTestTrim::trimBitTest() done
[16:01:21.879] <TB1> INFO: PixTestTrim::doTest() done, duration: 2445 seconds
[16:01:21.879] <TB1> INFO: Decoding statistics:
[16:01:21.879] <TB1> INFO: General information:
[16:01:21.879] <TB1> INFO: 16bit words read: 0
[16:01:21.879] <TB1> INFO: valid events total: 0
[16:01:21.879] <TB1> INFO: empty events: 0
[16:01:21.879] <TB1> INFO: valid events with pixels: 0
[16:01:21.879] <TB1> INFO: valid pixel hits: 0
[16:01:21.879] <TB1> INFO: Event errors: 0
[16:01:21.879] <TB1> INFO: start marker: 0
[16:01:21.879] <TB1> INFO: stop marker: 0
[16:01:21.879] <TB1> INFO: overflow: 0
[16:01:21.879] <TB1> INFO: invalid 5bit words: 0
[16:01:21.879] <TB1> INFO: invalid XOR eye diagram: 0
[16:01:21.879] <TB1> INFO: frame (failed synchr.): 0
[16:01:21.879] <TB1> INFO: idle data (no TBM trl): 0
[16:01:21.879] <TB1> INFO: no data (only TBM hdr): 0
[16:01:21.879] <TB1> INFO: TBM errors: 0
[16:01:21.879] <TB1> INFO: flawed TBM headers: 0
[16:01:21.879] <TB1> INFO: flawed TBM trailers: 0
[16:01:21.879] <TB1> INFO: event ID mismatches: 0
[16:01:21.879] <TB1> INFO: ROC errors: 0
[16:01:21.879] <TB1> INFO: missing ROC header(s): 0
[16:01:21.879] <TB1> INFO: misplaced readback start: 0
[16:01:21.879] <TB1> INFO: Pixel decoding errors: 0
[16:01:21.879] <TB1> INFO: pixel data incomplete: 0
[16:01:21.879] <TB1> INFO: pixel address: 0
[16:01:21.879] <TB1> INFO: pulse height fill bit: 0
[16:01:21.879] <TB1> INFO: buffer corruption: 0
[16:01:22.649] <TB1> INFO: ######################################################################
[16:01:22.649] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[16:01:22.649] <TB1> INFO: ######################################################################
[16:01:22.886] <TB1> INFO: Expecting 41600 events.
[16:01:26.551] <TB1> INFO: 41600 events read in total (3074ms).
[16:01:26.553] <TB1> INFO: Test took 3903ms.
[16:01:27.042] <TB1> INFO: Expecting 41600 events.
[16:01:30.590] <TB1> INFO: 41600 events read in total (2956ms).
[16:01:30.591] <TB1> INFO: Test took 3835ms.
[16:01:30.883] <TB1> INFO: Expecting 41600 events.
[16:01:34.428] <TB1> INFO: 41600 events read in total (2953ms).
[16:01:34.429] <TB1> INFO: Test took 3812ms.
[16:01:34.719] <TB1> INFO: Expecting 41600 events.
[16:01:38.248] <TB1> INFO: 41600 events read in total (2937ms).
[16:01:38.249] <TB1> INFO: Test took 3795ms.
[16:01:38.562] <TB1> INFO: Expecting 41600 events.
[16:01:42.090] <TB1> INFO: 41600 events read in total (2937ms).
[16:01:42.091] <TB1> INFO: Test took 3818ms.
[16:01:42.379] <TB1> INFO: Expecting 41600 events.
[16:01:46.038] <TB1> INFO: 41600 events read in total (3067ms).
[16:01:46.038] <TB1> INFO: Test took 3923ms.
[16:01:46.327] <TB1> INFO: Expecting 41600 events.
[16:01:49.966] <TB1> INFO: 41600 events read in total (3047ms).
[16:01:49.967] <TB1> INFO: Test took 3905ms.
[16:01:50.255] <TB1> INFO: Expecting 41600 events.
[16:01:53.798] <TB1> INFO: 41600 events read in total (2951ms).
[16:01:53.798] <TB1> INFO: Test took 3807ms.
[16:01:54.088] <TB1> INFO: Expecting 41600 events.
[16:01:57.615] <TB1> INFO: 41600 events read in total (2936ms).
[16:01:57.616] <TB1> INFO: Test took 3793ms.
[16:01:57.908] <TB1> INFO: Expecting 41600 events.
[16:02:01.445] <TB1> INFO: 41600 events read in total (2945ms).
[16:02:01.446] <TB1> INFO: Test took 3803ms.
[16:02:01.739] <TB1> INFO: Expecting 41600 events.
[16:02:05.515] <TB1> INFO: 41600 events read in total (3185ms).
[16:02:05.516] <TB1> INFO: Test took 4046ms.
[16:02:05.806] <TB1> INFO: Expecting 41600 events.
[16:02:09.365] <TB1> INFO: 41600 events read in total (2968ms).
[16:02:09.366] <TB1> INFO: Test took 3825ms.
[16:02:09.658] <TB1> INFO: Expecting 41600 events.
[16:02:13.259] <TB1> INFO: 41600 events read in total (3009ms).
[16:02:13.260] <TB1> INFO: Test took 3867ms.
[16:02:13.549] <TB1> INFO: Expecting 41600 events.
[16:02:17.074] <TB1> INFO: 41600 events read in total (2933ms).
[16:02:17.074] <TB1> INFO: Test took 3790ms.
[16:02:17.366] <TB1> INFO: Expecting 41600 events.
[16:02:20.879] <TB1> INFO: 41600 events read in total (2921ms).
[16:02:20.880] <TB1> INFO: Test took 3779ms.
[16:02:21.181] <TB1> INFO: Expecting 41600 events.
[16:02:24.706] <TB1> INFO: 41600 events read in total (2934ms).
[16:02:24.707] <TB1> INFO: Test took 3803ms.
[16:02:25.009] <TB1> INFO: Expecting 41600 events.
[16:02:28.512] <TB1> INFO: 41600 events read in total (2911ms).
[16:02:28.513] <TB1> INFO: Test took 3779ms.
[16:02:28.803] <TB1> INFO: Expecting 41600 events.
[16:02:32.328] <TB1> INFO: 41600 events read in total (2933ms).
[16:02:32.329] <TB1> INFO: Test took 3791ms.
[16:02:32.617] <TB1> INFO: Expecting 41600 events.
[16:02:36.141] <TB1> INFO: 41600 events read in total (2932ms).
[16:02:36.142] <TB1> INFO: Test took 3789ms.
[16:02:36.486] <TB1> INFO: Expecting 41600 events.
[16:02:40.035] <TB1> INFO: 41600 events read in total (2958ms).
[16:02:40.036] <TB1> INFO: Test took 3866ms.
[16:02:40.328] <TB1> INFO: Expecting 41600 events.
[16:02:43.899] <TB1> INFO: 41600 events read in total (2979ms).
[16:02:43.900] <TB1> INFO: Test took 3837ms.
[16:02:44.189] <TB1> INFO: Expecting 41600 events.
[16:02:47.787] <TB1> INFO: 41600 events read in total (3006ms).
[16:02:47.788] <TB1> INFO: Test took 3863ms.
[16:02:48.078] <TB1> INFO: Expecting 41600 events.
[16:02:51.662] <TB1> INFO: 41600 events read in total (2992ms).
[16:02:51.663] <TB1> INFO: Test took 3850ms.
[16:02:51.954] <TB1> INFO: Expecting 41600 events.
[16:02:55.539] <TB1> INFO: 41600 events read in total (2993ms).
[16:02:55.540] <TB1> INFO: Test took 3852ms.
[16:02:55.835] <TB1> INFO: Expecting 41600 events.
[16:02:59.452] <TB1> INFO: 41600 events read in total (3025ms).
[16:02:59.452] <TB1> INFO: Test took 3883ms.
[16:02:59.742] <TB1> INFO: Expecting 41600 events.
[16:03:03.314] <TB1> INFO: 41600 events read in total (2980ms).
[16:03:03.314] <TB1> INFO: Test took 3838ms.
[16:03:03.603] <TB1> INFO: Expecting 41600 events.
[16:03:07.155] <TB1> INFO: 41600 events read in total (2960ms).
[16:03:07.156] <TB1> INFO: Test took 3818ms.
[16:03:07.445] <TB1> INFO: Expecting 41600 events.
[16:03:10.999] <TB1> INFO: 41600 events read in total (2962ms).
[16:03:10.000] <TB1> INFO: Test took 3820ms.
[16:03:11.290] <TB1> INFO: Expecting 41600 events.
[16:03:14.923] <TB1> INFO: 41600 events read in total (3042ms).
[16:03:14.924] <TB1> INFO: Test took 3900ms.
[16:03:15.214] <TB1> INFO: Expecting 41600 events.
[16:03:18.905] <TB1> INFO: 41600 events read in total (3100ms).
[16:03:18.906] <TB1> INFO: Test took 3958ms.
[16:03:19.198] <TB1> INFO: Expecting 2560 events.
[16:03:20.084] <TB1> INFO: 2560 events read in total (295ms).
[16:03:20.085] <TB1> INFO: Test took 1164ms.
[16:03:20.391] <TB1> INFO: Expecting 2560 events.
[16:03:21.277] <TB1> INFO: 2560 events read in total (294ms).
[16:03:21.277] <TB1> INFO: Test took 1192ms.
[16:03:21.586] <TB1> INFO: Expecting 2560 events.
[16:03:22.479] <TB1> INFO: 2560 events read in total (301ms).
[16:03:22.480] <TB1> INFO: Test took 1202ms.
[16:03:22.788] <TB1> INFO: Expecting 2560 events.
[16:03:23.674] <TB1> INFO: 2560 events read in total (294ms).
[16:03:23.674] <TB1> INFO: Test took 1193ms.
[16:03:23.984] <TB1> INFO: Expecting 2560 events.
[16:03:24.862] <TB1> INFO: 2560 events read in total (287ms).
[16:03:24.863] <TB1> INFO: Test took 1188ms.
[16:03:25.171] <TB1> INFO: Expecting 2560 events.
[16:03:26.058] <TB1> INFO: 2560 events read in total (295ms).
[16:03:26.059] <TB1> INFO: Test took 1196ms.
[16:03:26.366] <TB1> INFO: Expecting 2560 events.
[16:03:27.246] <TB1> INFO: 2560 events read in total (288ms).
[16:03:27.246] <TB1> INFO: Test took 1187ms.
[16:03:27.555] <TB1> INFO: Expecting 2560 events.
[16:03:28.439] <TB1> INFO: 2560 events read in total (293ms).
[16:03:28.440] <TB1> INFO: Test took 1194ms.
[16:03:28.748] <TB1> INFO: Expecting 2560 events.
[16:03:29.634] <TB1> INFO: 2560 events read in total (295ms).
[16:03:29.634] <TB1> INFO: Test took 1194ms.
[16:03:29.942] <TB1> INFO: Expecting 2560 events.
[16:03:30.832] <TB1> INFO: 2560 events read in total (298ms).
[16:03:30.832] <TB1> INFO: Test took 1197ms.
[16:03:31.140] <TB1> INFO: Expecting 2560 events.
[16:03:32.032] <TB1> INFO: 2560 events read in total (300ms).
[16:03:32.032] <TB1> INFO: Test took 1199ms.
[16:03:32.340] <TB1> INFO: Expecting 2560 events.
[16:03:33.226] <TB1> INFO: 2560 events read in total (294ms).
[16:03:33.226] <TB1> INFO: Test took 1194ms.
[16:03:33.535] <TB1> INFO: Expecting 2560 events.
[16:03:34.431] <TB1> INFO: 2560 events read in total (304ms).
[16:03:34.431] <TB1> INFO: Test took 1205ms.
[16:03:34.738] <TB1> INFO: Expecting 2560 events.
[16:03:35.621] <TB1> INFO: 2560 events read in total (291ms).
[16:03:35.622] <TB1> INFO: Test took 1190ms.
[16:03:35.930] <TB1> INFO: Expecting 2560 events.
[16:03:36.821] <TB1> INFO: 2560 events read in total (300ms).
[16:03:36.821] <TB1> INFO: Test took 1199ms.
[16:03:37.129] <TB1> INFO: Expecting 2560 events.
[16:03:38.024] <TB1> INFO: 2560 events read in total (303ms).
[16:03:38.024] <TB1> INFO: Test took 1202ms.
[16:03:38.028] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:03:38.332] <TB1> INFO: Expecting 655360 events.
[16:03:53.184] <TB1> INFO: 655360 events read in total (14260ms).
[16:03:53.196] <TB1> INFO: Expecting 655360 events.
[16:04:07.831] <TB1> INFO: 655360 events read in total (14232ms).
[16:04:07.847] <TB1> INFO: Expecting 655360 events.
[16:04:22.454] <TB1> INFO: 655360 events read in total (14204ms).
[16:04:22.474] <TB1> INFO: Expecting 655360 events.
[16:04:37.049] <TB1> INFO: 655360 events read in total (14172ms).
[16:04:37.074] <TB1> INFO: Expecting 655360 events.
[16:04:51.640] <TB1> INFO: 655360 events read in total (14163ms).
[16:04:51.669] <TB1> INFO: Expecting 655360 events.
[16:05:06.407] <TB1> INFO: 655360 events read in total (14335ms).
[16:05:06.443] <TB1> INFO: Expecting 655360 events.
[16:05:21.230] <TB1> INFO: 655360 events read in total (14385ms).
[16:05:21.268] <TB1> INFO: Expecting 655360 events.
[16:05:35.962] <TB1> INFO: 655360 events read in total (14290ms).
[16:05:36.004] <TB1> INFO: Expecting 655360 events.
[16:05:50.507] <TB1> INFO: 655360 events read in total (14100ms).
[16:05:50.553] <TB1> INFO: Expecting 655360 events.
[16:06:05.161] <TB1> INFO: 655360 events read in total (14205ms).
[16:06:05.214] <TB1> INFO: Expecting 655360 events.
[16:06:19.691] <TB1> INFO: 655360 events read in total (14074ms).
[16:06:19.761] <TB1> INFO: Expecting 655360 events.
[16:06:34.234] <TB1> INFO: 655360 events read in total (14070ms).
[16:06:34.310] <TB1> INFO: Expecting 655360 events.
[16:06:49.046] <TB1> INFO: 655360 events read in total (14333ms).
[16:06:49.194] <TB1> INFO: Expecting 655360 events.
[16:07:03.789] <TB1> INFO: 655360 events read in total (14192ms).
[16:07:03.974] <TB1> INFO: Expecting 655360 events.
[16:07:18.489] <TB1> INFO: 655360 events read in total (14112ms).
[16:07:18.578] <TB1> INFO: Expecting 655360 events.
[16:07:33.119] <TB1> INFO: 655360 events read in total (14138ms).
[16:07:33.275] <TB1> INFO: Test took 235247ms.
[16:07:33.376] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:07:33.628] <TB1> INFO: Expecting 655360 events.
[16:07:48.363] <TB1> INFO: 655360 events read in total (14143ms).
[16:07:48.375] <TB1> INFO: Expecting 655360 events.
[16:08:03.068] <TB1> INFO: 655360 events read in total (14290ms).
[16:08:03.084] <TB1> INFO: Expecting 655360 events.
[16:08:17.632] <TB1> INFO: 655360 events read in total (14145ms).
[16:08:17.652] <TB1> INFO: Expecting 655360 events.
[16:08:32.280] <TB1> INFO: 655360 events read in total (14224ms).
[16:08:32.312] <TB1> INFO: Expecting 655360 events.
[16:08:47.028] <TB1> INFO: 655360 events read in total (14313ms).
[16:08:47.067] <TB1> INFO: Expecting 655360 events.
[16:09:01.841] <TB1> INFO: 655360 events read in total (14371ms).
[16:09:01.875] <TB1> INFO: Expecting 655360 events.
[16:09:16.658] <TB1> INFO: 655360 events read in total (14379ms).
[16:09:16.738] <TB1> INFO: Expecting 655360 events.
[16:09:31.473] <TB1> INFO: 655360 events read in total (14332ms).
[16:09:31.515] <TB1> INFO: Expecting 655360 events.
[16:09:46.007] <TB1> INFO: 655360 events read in total (14089ms).
[16:09:46.054] <TB1> INFO: Expecting 655360 events.
[16:10:00.317] <TB1> INFO: 655360 events read in total (13859ms).
[16:10:00.368] <TB1> INFO: Expecting 655360 events.
[16:10:14.929] <TB1> INFO: 655360 events read in total (14158ms).
[16:10:15.137] <TB1> INFO: Expecting 655360 events.
[16:10:29.456] <TB1> INFO: 655360 events read in total (13915ms).
[16:10:29.530] <TB1> INFO: Expecting 655360 events.
[16:10:44.003] <TB1> INFO: 655360 events read in total (14070ms).
[16:10:44.080] <TB1> INFO: Expecting 655360 events.
[16:10:58.584] <TB1> INFO: 655360 events read in total (14101ms).
[16:10:58.690] <TB1> INFO: Expecting 655360 events.
[16:11:13.331] <TB1> INFO: 655360 events read in total (14238ms).
[16:11:13.426] <TB1> INFO: Expecting 655360 events.
[16:11:28.008] <TB1> INFO: 655360 events read in total (14179ms).
[16:11:28.126] <TB1> INFO: Test took 234750ms.
[16:11:28.300] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.306] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[16:11:28.312] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[16:11:28.317] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[16:11:28.323] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[16:11:28.329] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.335] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.340] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.346] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.352] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[16:11:28.358] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[16:11:28.363] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.369] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.375] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.381] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.387] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[16:11:28.392] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[16:11:28.398] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[16:11:28.404] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[16:11:28.410] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[16:11:28.415] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[16:11:28.421] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[16:11:28.427] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.432] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[16:11:28.438] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.444] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.450] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[16:11:28.456] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.462] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.467] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.473] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[16:11:28.479] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[16:11:28.485] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[16:11:28.490] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[16:11:28.496] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[16:11:28.502] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[16:11:28.508] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[16:11:28.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C0.dat
[16:11:28.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C1.dat
[16:11:28.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C2.dat
[16:11:28.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C3.dat
[16:11:28.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C4.dat
[16:11:28.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C5.dat
[16:11:28.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C6.dat
[16:11:28.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C7.dat
[16:11:28.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C8.dat
[16:11:28.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C9.dat
[16:11:28.545] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C10.dat
[16:11:28.545] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C11.dat
[16:11:28.545] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C12.dat
[16:11:28.545] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C13.dat
[16:11:28.545] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C14.dat
[16:11:28.545] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//dacParameters35_C15.dat
[16:11:28.832] <TB1> INFO: Expecting 41600 events.
[16:11:31.975] <TB1> INFO: 41600 events read in total (2552ms).
[16:11:31.976] <TB1> INFO: Test took 3428ms.
[16:11:32.427] <TB1> INFO: Expecting 41600 events.
[16:11:35.548] <TB1> INFO: 41600 events read in total (2529ms).
[16:11:35.550] <TB1> INFO: Test took 3361ms.
[16:11:36.047] <TB1> INFO: Expecting 41600 events.
[16:11:39.212] <TB1> INFO: 41600 events read in total (2573ms).
[16:11:39.212] <TB1> INFO: Test took 3445ms.
[16:11:39.434] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:39.523] <TB1> INFO: Expecting 2560 events.
[16:11:40.410] <TB1> INFO: 2560 events read in total (295ms).
[16:11:40.410] <TB1> INFO: Test took 976ms.
[16:11:40.413] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:40.718] <TB1> INFO: Expecting 2560 events.
[16:11:41.604] <TB1> INFO: 2560 events read in total (294ms).
[16:11:41.605] <TB1> INFO: Test took 1192ms.
[16:11:41.607] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:41.914] <TB1> INFO: Expecting 2560 events.
[16:11:42.809] <TB1> INFO: 2560 events read in total (302ms).
[16:11:42.809] <TB1> INFO: Test took 1202ms.
[16:11:42.812] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:43.117] <TB1> INFO: Expecting 2560 events.
[16:11:44.004] <TB1> INFO: 2560 events read in total (295ms).
[16:11:44.005] <TB1> INFO: Test took 1194ms.
[16:11:44.007] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:44.313] <TB1> INFO: Expecting 2560 events.
[16:11:45.207] <TB1> INFO: 2560 events read in total (302ms).
[16:11:45.207] <TB1> INFO: Test took 1200ms.
[16:11:45.212] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:45.515] <TB1> INFO: Expecting 2560 events.
[16:11:46.411] <TB1> INFO: 2560 events read in total (304ms).
[16:11:46.412] <TB1> INFO: Test took 1200ms.
[16:11:46.415] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:46.720] <TB1> INFO: Expecting 2560 events.
[16:11:47.606] <TB1> INFO: 2560 events read in total (294ms).
[16:11:47.607] <TB1> INFO: Test took 1192ms.
[16:11:47.609] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:47.916] <TB1> INFO: Expecting 2560 events.
[16:11:48.814] <TB1> INFO: 2560 events read in total (306ms).
[16:11:48.814] <TB1> INFO: Test took 1205ms.
[16:11:48.817] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:49.122] <TB1> INFO: Expecting 2560 events.
[16:11:50.012] <TB1> INFO: 2560 events read in total (299ms).
[16:11:50.013] <TB1> INFO: Test took 1196ms.
[16:11:50.016] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:50.320] <TB1> INFO: Expecting 2560 events.
[16:11:51.201] <TB1> INFO: 2560 events read in total (289ms).
[16:11:51.201] <TB1> INFO: Test took 1185ms.
[16:11:51.204] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:51.510] <TB1> INFO: Expecting 2560 events.
[16:11:52.396] <TB1> INFO: 2560 events read in total (295ms).
[16:11:52.397] <TB1> INFO: Test took 1193ms.
[16:11:52.399] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:52.705] <TB1> INFO: Expecting 2560 events.
[16:11:53.586] <TB1> INFO: 2560 events read in total (289ms).
[16:11:53.586] <TB1> INFO: Test took 1187ms.
[16:11:53.589] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:53.895] <TB1> INFO: Expecting 2560 events.
[16:11:54.779] <TB1> INFO: 2560 events read in total (293ms).
[16:11:54.779] <TB1> INFO: Test took 1190ms.
[16:11:54.782] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:55.086] <TB1> INFO: Expecting 2560 events.
[16:11:55.973] <TB1> INFO: 2560 events read in total (295ms).
[16:11:55.974] <TB1> INFO: Test took 1192ms.
[16:11:55.977] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:56.282] <TB1> INFO: Expecting 2560 events.
[16:11:57.172] <TB1> INFO: 2560 events read in total (298ms).
[16:11:57.173] <TB1> INFO: Test took 1196ms.
[16:11:57.176] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:57.481] <TB1> INFO: Expecting 2560 events.
[16:11:58.373] <TB1> INFO: 2560 events read in total (300ms).
[16:11:58.373] <TB1> INFO: Test took 1197ms.
[16:11:58.376] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:58.682] <TB1> INFO: Expecting 2560 events.
[16:11:59.572] <TB1> INFO: 2560 events read in total (299ms).
[16:11:59.573] <TB1> INFO: Test took 1197ms.
[16:11:59.576] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:11:59.879] <TB1> INFO: Expecting 2560 events.
[16:12:00.771] <TB1> INFO: 2560 events read in total (300ms).
[16:12:00.772] <TB1> INFO: Test took 1196ms.
[16:12:00.774] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:01.080] <TB1> INFO: Expecting 2560 events.
[16:12:01.971] <TB1> INFO: 2560 events read in total (299ms).
[16:12:01.972] <TB1> INFO: Test took 1198ms.
[16:12:01.975] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:02.279] <TB1> INFO: Expecting 2560 events.
[16:12:03.168] <TB1> INFO: 2560 events read in total (297ms).
[16:12:03.168] <TB1> INFO: Test took 1193ms.
[16:12:03.171] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:03.476] <TB1> INFO: Expecting 2560 events.
[16:12:04.358] <TB1> INFO: 2560 events read in total (290ms).
[16:12:04.359] <TB1> INFO: Test took 1189ms.
[16:12:04.361] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:04.668] <TB1> INFO: Expecting 2560 events.
[16:12:05.555] <TB1> INFO: 2560 events read in total (296ms).
[16:12:05.556] <TB1> INFO: Test took 1196ms.
[16:12:05.560] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:05.863] <TB1> INFO: Expecting 2560 events.
[16:12:06.745] <TB1> INFO: 2560 events read in total (290ms).
[16:12:06.745] <TB1> INFO: Test took 1186ms.
[16:12:06.749] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:07.053] <TB1> INFO: Expecting 2560 events.
[16:12:07.941] <TB1> INFO: 2560 events read in total (296ms).
[16:12:07.941] <TB1> INFO: Test took 1193ms.
[16:12:07.944] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:08.250] <TB1> INFO: Expecting 2560 events.
[16:12:09.139] <TB1> INFO: 2560 events read in total (297ms).
[16:12:09.139] <TB1> INFO: Test took 1195ms.
[16:12:09.142] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:09.447] <TB1> INFO: Expecting 2560 events.
[16:12:10.339] <TB1> INFO: 2560 events read in total (300ms).
[16:12:10.340] <TB1> INFO: Test took 1199ms.
[16:12:10.343] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:10.648] <TB1> INFO: Expecting 2560 events.
[16:12:11.541] <TB1> INFO: 2560 events read in total (301ms).
[16:12:11.542] <TB1> INFO: Test took 1200ms.
[16:12:11.544] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:11.851] <TB1> INFO: Expecting 2560 events.
[16:12:12.748] <TB1> INFO: 2560 events read in total (305ms).
[16:12:12.748] <TB1> INFO: Test took 1204ms.
[16:12:12.750] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:13.057] <TB1> INFO: Expecting 2560 events.
[16:12:13.950] <TB1> INFO: 2560 events read in total (301ms).
[16:12:13.951] <TB1> INFO: Test took 1201ms.
[16:12:13.953] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:14.259] <TB1> INFO: Expecting 2560 events.
[16:12:15.151] <TB1> INFO: 2560 events read in total (300ms).
[16:12:15.152] <TB1> INFO: Test took 1199ms.
[16:12:15.155] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:15.459] <TB1> INFO: Expecting 2560 events.
[16:12:16.349] <TB1> INFO: 2560 events read in total (298ms).
[16:12:16.349] <TB1> INFO: Test took 1194ms.
[16:12:16.351] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:12:16.658] <TB1> INFO: Expecting 2560 events.
[16:12:17.548] <TB1> INFO: 2560 events read in total (298ms).
[16:12:17.548] <TB1> INFO: Test took 1197ms.
[16:12:18.028] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 655 seconds
[16:12:18.028] <TB1> INFO: PH scale (per ROC): 46 49 46 70 50 61 46 50 58 48 46 66 45 54 48 48
[16:12:18.028] <TB1> INFO: PH offset (per ROC): 99 93 109 113 102 108 105 91 112 87 98 113 97 139 97 104
[16:12:18.035] <TB1> INFO: Decoding statistics:
[16:12:18.035] <TB1> INFO: General information:
[16:12:18.035] <TB1> INFO: 16bit words read: 127890
[16:12:18.035] <TB1> INFO: valid events total: 20480
[16:12:18.035] <TB1> INFO: empty events: 17975
[16:12:18.035] <TB1> INFO: valid events with pixels: 2505
[16:12:18.035] <TB1> INFO: valid pixel hits: 2505
[16:12:18.035] <TB1> INFO: Event errors: 0
[16:12:18.035] <TB1> INFO: start marker: 0
[16:12:18.035] <TB1> INFO: stop marker: 0
[16:12:18.035] <TB1> INFO: overflow: 0
[16:12:18.035] <TB1> INFO: invalid 5bit words: 0
[16:12:18.035] <TB1> INFO: invalid XOR eye diagram: 0
[16:12:18.035] <TB1> INFO: frame (failed synchr.): 0
[16:12:18.035] <TB1> INFO: idle data (no TBM trl): 0
[16:12:18.035] <TB1> INFO: no data (only TBM hdr): 0
[16:12:18.035] <TB1> INFO: TBM errors: 0
[16:12:18.035] <TB1> INFO: flawed TBM headers: 0
[16:12:18.035] <TB1> INFO: flawed TBM trailers: 0
[16:12:18.035] <TB1> INFO: event ID mismatches: 0
[16:12:18.035] <TB1> INFO: ROC errors: 0
[16:12:18.035] <TB1> INFO: missing ROC header(s): 0
[16:12:18.035] <TB1> INFO: misplaced readback start: 0
[16:12:18.035] <TB1> INFO: Pixel decoding errors: 0
[16:12:18.035] <TB1> INFO: pixel data incomplete: 0
[16:12:18.035] <TB1> INFO: pixel address: 0
[16:12:18.035] <TB1> INFO: pulse height fill bit: 0
[16:12:18.035] <TB1> INFO: buffer corruption: 0
[16:12:18.190] <TB1> INFO: ######################################################################
[16:12:18.190] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[16:12:18.190] <TB1> INFO: ######################################################################
[16:12:18.205] <TB1> INFO: scanning low vcal = 10
[16:12:18.485] <TB1> INFO: Expecting 41600 events.
[16:12:22.075] <TB1> INFO: 41600 events read in total (2998ms).
[16:12:22.075] <TB1> INFO: Test took 3870ms.
[16:12:22.077] <TB1> INFO: scanning low vcal = 20
[16:12:22.372] <TB1> INFO: Expecting 41600 events.
[16:12:25.953] <TB1> INFO: 41600 events read in total (2989ms).
[16:12:25.953] <TB1> INFO: Test took 3876ms.
[16:12:25.955] <TB1> INFO: scanning low vcal = 30
[16:12:26.246] <TB1> INFO: Expecting 41600 events.
[16:12:29.893] <TB1> INFO: 41600 events read in total (3056ms).
[16:12:29.894] <TB1> INFO: Test took 3939ms.
[16:12:29.897] <TB1> INFO: scanning low vcal = 40
[16:12:30.178] <TB1> INFO: Expecting 41600 events.
[16:12:34.133] <TB1> INFO: 41600 events read in total (3363ms).
[16:12:34.135] <TB1> INFO: Test took 4238ms.
[16:12:34.138] <TB1> INFO: scanning low vcal = 50
[16:12:34.430] <TB1> INFO: Expecting 41600 events.
[16:12:38.407] <TB1> INFO: 41600 events read in total (3385ms).
[16:12:38.407] <TB1> INFO: Test took 4269ms.
[16:12:38.411] <TB1> INFO: scanning low vcal = 60
[16:12:38.688] <TB1> INFO: Expecting 41600 events.
[16:12:42.675] <TB1> INFO: 41600 events read in total (3396ms).
[16:12:42.676] <TB1> INFO: Test took 4265ms.
[16:12:42.679] <TB1> INFO: scanning low vcal = 70
[16:12:42.957] <TB1> INFO: Expecting 41600 events.
[16:12:47.022] <TB1> INFO: 41600 events read in total (3473ms).
[16:12:47.026] <TB1> INFO: Test took 4347ms.
[16:12:47.030] <TB1> INFO: scanning low vcal = 80
[16:12:47.327] <TB1> INFO: Expecting 41600 events.
[16:12:51.305] <TB1> INFO: 41600 events read in total (3386ms).
[16:12:51.305] <TB1> INFO: Test took 4275ms.
[16:12:51.310] <TB1> INFO: scanning low vcal = 90
[16:12:51.585] <TB1> INFO: Expecting 41600 events.
[16:12:55.593] <TB1> INFO: 41600 events read in total (3416ms).
[16:12:55.593] <TB1> INFO: Test took 4282ms.
[16:12:55.597] <TB1> INFO: scanning low vcal = 100
[16:12:55.874] <TB1> INFO: Expecting 41600 events.
[16:12:59.840] <TB1> INFO: 41600 events read in total (3375ms).
[16:12:59.841] <TB1> INFO: Test took 4243ms.
[16:12:59.844] <TB1> INFO: scanning low vcal = 110
[16:13:00.121] <TB1> INFO: Expecting 41600 events.
[16:13:04.118] <TB1> INFO: 41600 events read in total (3406ms).
[16:13:04.119] <TB1> INFO: Test took 4274ms.
[16:13:04.122] <TB1> INFO: scanning low vcal = 120
[16:13:04.399] <TB1> INFO: Expecting 41600 events.
[16:13:08.418] <TB1> INFO: 41600 events read in total (3427ms).
[16:13:08.419] <TB1> INFO: Test took 4297ms.
[16:13:08.422] <TB1> INFO: scanning low vcal = 130
[16:13:08.699] <TB1> INFO: Expecting 41600 events.
[16:13:12.686] <TB1> INFO: 41600 events read in total (3396ms).
[16:13:12.687] <TB1> INFO: Test took 4265ms.
[16:13:12.690] <TB1> INFO: scanning low vcal = 140
[16:13:12.967] <TB1> INFO: Expecting 41600 events.
[16:13:17.017] <TB1> INFO: 41600 events read in total (3458ms).
[16:13:17.018] <TB1> INFO: Test took 4328ms.
[16:13:17.021] <TB1> INFO: scanning low vcal = 150
[16:13:17.298] <TB1> INFO: Expecting 41600 events.
[16:13:21.308] <TB1> INFO: 41600 events read in total (3418ms).
[16:13:21.309] <TB1> INFO: Test took 4288ms.
[16:13:21.312] <TB1> INFO: scanning low vcal = 160
[16:13:21.609] <TB1> INFO: Expecting 41600 events.
[16:13:25.632] <TB1> INFO: 41600 events read in total (3431ms).
[16:13:25.633] <TB1> INFO: Test took 4320ms.
[16:13:25.636] <TB1> INFO: scanning low vcal = 170
[16:13:25.913] <TB1> INFO: Expecting 41600 events.
[16:13:29.943] <TB1> INFO: 41600 events read in total (3438ms).
[16:13:29.944] <TB1> INFO: Test took 4308ms.
[16:13:29.949] <TB1> INFO: scanning low vcal = 180
[16:13:30.224] <TB1> INFO: Expecting 41600 events.
[16:13:34.246] <TB1> INFO: 41600 events read in total (3430ms).
[16:13:34.247] <TB1> INFO: Test took 4297ms.
[16:13:34.250] <TB1> INFO: scanning low vcal = 190
[16:13:34.527] <TB1> INFO: Expecting 41600 events.
[16:13:38.555] <TB1> INFO: 41600 events read in total (3437ms).
[16:13:38.556] <TB1> INFO: Test took 4306ms.
[16:13:38.560] <TB1> INFO: scanning low vcal = 200
[16:13:38.837] <TB1> INFO: Expecting 41600 events.
[16:13:42.858] <TB1> INFO: 41600 events read in total (3429ms).
[16:13:42.859] <TB1> INFO: Test took 4299ms.
[16:13:42.862] <TB1> INFO: scanning low vcal = 210
[16:13:43.140] <TB1> INFO: Expecting 41600 events.
[16:13:47.151] <TB1> INFO: 41600 events read in total (3420ms).
[16:13:47.153] <TB1> INFO: Test took 4290ms.
[16:13:47.156] <TB1> INFO: scanning low vcal = 220
[16:13:47.434] <TB1> INFO: Expecting 41600 events.
[16:13:51.469] <TB1> INFO: 41600 events read in total (3443ms).
[16:13:51.470] <TB1> INFO: Test took 4314ms.
[16:13:51.473] <TB1> INFO: scanning low vcal = 230
[16:13:51.750] <TB1> INFO: Expecting 41600 events.
[16:13:55.744] <TB1> INFO: 41600 events read in total (3403ms).
[16:13:55.745] <TB1> INFO: Test took 4272ms.
[16:13:55.748] <TB1> INFO: scanning low vcal = 240
[16:13:56.025] <TB1> INFO: Expecting 41600 events.
[16:13:59.988] <TB1> INFO: 41600 events read in total (3371ms).
[16:13:59.989] <TB1> INFO: Test took 4240ms.
[16:13:59.992] <TB1> INFO: scanning low vcal = 250
[16:14:00.275] <TB1> INFO: Expecting 41600 events.
[16:14:04.245] <TB1> INFO: 41600 events read in total (3378ms).
[16:14:04.246] <TB1> INFO: Test took 4254ms.
[16:14:04.250] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[16:14:04.526] <TB1> INFO: Expecting 41600 events.
[16:14:08.489] <TB1> INFO: 41600 events read in total (3371ms).
[16:14:08.491] <TB1> INFO: Test took 4240ms.
[16:14:08.495] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[16:14:08.771] <TB1> INFO: Expecting 41600 events.
[16:14:12.717] <TB1> INFO: 41600 events read in total (3355ms).
[16:14:12.718] <TB1> INFO: Test took 4223ms.
[16:14:12.721] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[16:14:12.998] <TB1> INFO: Expecting 41600 events.
[16:14:16.957] <TB1> INFO: 41600 events read in total (3365ms).
[16:14:16.958] <TB1> INFO: Test took 4237ms.
[16:14:16.961] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[16:14:17.237] <TB1> INFO: Expecting 41600 events.
[16:14:21.178] <TB1> INFO: 41600 events read in total (3349ms).
[16:14:21.179] <TB1> INFO: Test took 4218ms.
[16:14:21.182] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[16:14:21.459] <TB1> INFO: Expecting 41600 events.
[16:14:25.401] <TB1> INFO: 41600 events read in total (3350ms).
[16:14:25.401] <TB1> INFO: Test took 4219ms.
[16:14:25.854] <TB1> INFO: PixTestGainPedestal::measure() done
[16:14:59.530] <TB1> INFO: PixTestGainPedestal::fit() done
[16:14:59.530] <TB1> INFO: non-linearity mean: 0.926 0.917 0.936 0.985 0.919 0.940 0.923 0.922 0.976 0.935 0.899 0.977 0.932 0.971 0.920 0.895
[16:14:59.530] <TB1> INFO: non-linearity RMS: 0.066 0.097 0.038 0.005 0.093 0.061 0.119 0.090 0.006 0.084 0.111 0.009 0.155 0.006 0.155 0.088
[16:14:59.530] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[16:14:59.543] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[16:14:59.556] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[16:14:59.570] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[16:14:59.583] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[16:14:59.596] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[16:14:59.609] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[16:14:59.621] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[16:14:59.634] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[16:14:59.647] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[16:14:59.660] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[16:14:59.673] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[16:14:59.687] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[16:14:59.699] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[16:14:59.712] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[16:14:59.725] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1010_FullQualification_2016-10-17_13h57m_1476705426//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[16:14:59.738] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 161 seconds
[16:14:59.738] <TB1> INFO: Decoding statistics:
[16:14:59.738] <TB1> INFO: General information:
[16:14:59.738] <TB1> INFO: 16bit words read: 3327938
[16:14:59.738] <TB1> INFO: valid events total: 332800
[16:14:59.738] <TB1> INFO: empty events: 0
[16:14:59.738] <TB1> INFO: valid events with pixels: 332800
[16:14:59.738] <TB1> INFO: valid pixel hits: 665569
[16:14:59.738] <TB1> INFO: Event errors: 0
[16:14:59.738] <TB1> INFO: start marker: 0
[16:14:59.738] <TB1> INFO: stop marker: 0
[16:14:59.738] <TB1> INFO: overflow: 0
[16:14:59.738] <TB1> INFO: invalid 5bit words: 0
[16:14:59.738] <TB1> INFO: invalid XOR eye diagram: 0
[16:14:59.738] <TB1> INFO: frame (failed synchr.): 0
[16:14:59.738] <TB1> INFO: idle data (no TBM trl): 0
[16:14:59.738] <TB1> INFO: no data (only TBM hdr): 0
[16:14:59.738] <TB1> INFO: TBM errors: 0
[16:14:59.738] <TB1> INFO: flawed TBM headers: 0
[16:14:59.738] <TB1> INFO: flawed TBM trailers: 0
[16:14:59.738] <TB1> INFO: event ID mismatches: 0
[16:14:59.738] <TB1> INFO: ROC errors: 0
[16:14:59.738] <TB1> INFO: missing ROC header(s): 0
[16:14:59.738] <TB1> INFO: misplaced readback start: 0
[16:14:59.738] <TB1> INFO: Pixel decoding errors: 0
[16:14:59.738] <TB1> INFO: pixel data incomplete: 0
[16:14:59.738] <TB1> INFO: pixel address: 0
[16:14:59.738] <TB1> INFO: pulse height fill bit: 0
[16:14:59.738] <TB1> INFO: buffer corruption: 0
[16:14:59.754] <TB1> INFO: Decoding statistics:
[16:14:59.754] <TB1> INFO: General information:
[16:14:59.754] <TB1> INFO: 16bit words read: 3457364
[16:14:59.754] <TB1> INFO: valid events total: 353536
[16:14:59.754] <TB1> INFO: empty events: 18231
[16:14:59.754] <TB1> INFO: valid events with pixels: 335305
[16:14:59.754] <TB1> INFO: valid pixel hits: 668074
[16:14:59.754] <TB1> INFO: Event errors: 0
[16:14:59.754] <TB1> INFO: start marker: 0
[16:14:59.754] <TB1> INFO: stop marker: 0
[16:14:59.754] <TB1> INFO: overflow: 0
[16:14:59.754] <TB1> INFO: invalid 5bit words: 0
[16:14:59.754] <TB1> INFO: invalid XOR eye diagram: 0
[16:14:59.754] <TB1> INFO: frame (failed synchr.): 0
[16:14:59.754] <TB1> INFO: idle data (no TBM trl): 0
[16:14:59.754] <TB1> INFO: no data (only TBM hdr): 0
[16:14:59.754] <TB1> INFO: TBM errors: 0
[16:14:59.754] <TB1> INFO: flawed TBM headers: 0
[16:14:59.754] <TB1> INFO: flawed TBM trailers: 0
[16:14:59.754] <TB1> INFO: event ID mismatches: 0
[16:14:59.754] <TB1> INFO: ROC errors: 0
[16:14:59.754] <TB1> INFO: missing ROC header(s): 0
[16:14:59.754] <TB1> INFO: misplaced readback start: 0
[16:14:59.754] <TB1> INFO: Pixel decoding errors: 0
[16:14:59.754] <TB1> INFO: pixel data incomplete: 0
[16:14:59.754] <TB1> INFO: pixel address: 0
[16:14:59.754] <TB1> INFO: pulse height fill bit: 0
[16:14:59.754] <TB1> INFO: buffer corruption: 0
[16:14:59.754] <TB1> INFO: enter test to run
[16:14:59.754] <TB1> INFO: test: exit no parameter change
[16:14:59.875] <TB1> QUIET: Connection to board 154 closed.
[16:14:59.875] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud