Test Date: 2016-10-24 11:34
Analysis date: 2016-10-24 16:16
Logfile
LogfileView
[14:03:33.918] <TB0> INFO: *** Welcome to pxar ***
[14:03:33.918] <TB0> INFO: *** Today: 2016/10/24
[14:03:33.923] <TB0> INFO: *** Version: c8ba-dirty
[14:03:33.923] <TB0> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C15.dat
[14:03:33.924] <TB0> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//tbmParameters_C1b.dat
[14:03:33.924] <TB0> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//defaultMaskFile.dat
[14:03:33.924] <TB0> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters_C15.dat
[14:03:33.984] <TB0> INFO: clk: 4
[14:03:33.984] <TB0> INFO: ctr: 4
[14:03:33.984] <TB0> INFO: sda: 19
[14:03:33.984] <TB0> INFO: tin: 9
[14:03:33.984] <TB0> INFO: level: 15
[14:03:33.984] <TB0> INFO: triggerdelay: 0
[14:03:33.984] <TB0> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[14:03:33.984] <TB0> INFO: Log level: INFO
[14:03:33.992] <TB0> INFO: Found DTB DTB_WRQ4OZ
[14:03:33.002] <TB0> QUIET: Connection to board DTB_WRQ4OZ opened.
[14:03:34.004] <TB0> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 71
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WRQ4OZ
MAC address: 40D855118047
Hostname: pixelDTB071
Comment:
------------------------------------------------------
[14:03:34.006] <TB0> INFO: RPC call hashes of host and DTB match: 486171790
[14:03:35.495] <TB0> INFO: DUT info:
[14:03:35.495] <TB0> INFO: The DUT currently contains the following objects:
[14:03:35.495] <TB0> INFO: 4 TBM Cores tbm10c (4 ON)
[14:03:35.495] <TB0> INFO: TBM Core alpha (0): 7 registers set
[14:03:35.495] <TB0> INFO: TBM Core beta (1): 7 registers set
[14:03:35.495] <TB0> INFO: TBM Core alpha (2): 7 registers set
[14:03:35.495] <TB0> INFO: TBM Core beta (3): 7 registers set
[14:03:35.495] <TB0> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[14:03:35.495] <TB0> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.495] <TB0> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:35.896] <TB0> INFO: enter 'restricted' command line mode
[14:03:35.896] <TB0> INFO: enter test to run
[14:03:35.896] <TB0> INFO: test: pretest no parameter change
[14:03:35.896] <TB0> INFO: running: pretest
[14:03:35.900] <TB0> INFO: ######################################################################
[14:03:35.900] <TB0> INFO: PixTestPretest::doTest()
[14:03:35.900] <TB0> INFO: ######################################################################
[14:03:35.901] <TB0> INFO: ----------------------------------------------------------------------
[14:03:35.901] <TB0> INFO: PixTestPretest::programROC()
[14:03:35.901] <TB0> INFO: ----------------------------------------------------------------------
[14:03:53.916] <TB0> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[14:03:53.916] <TB0> INFO: IA differences per ROC: 16.9 20.1 17.7 18.5 21.7 20.1 16.9 20.1 19.3 16.9 19.3 16.9 20.1 19.3 18.5 16.9
[14:03:53.973] <TB0> INFO: ----------------------------------------------------------------------
[14:03:53.973] <TB0> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[14:03:53.973] <TB0> INFO: ----------------------------------------------------------------------
[14:04:15.255] <TB0> INFO: PixTestPretest::setVana() done, Module Ia 384.3 mA = 24.0187 mA/ROC
[14:04:15.255] <TB0> INFO: i(loss) [mA/ROC]: 19.3 19.3 18.5 18.5 19.3 19.3 19.3 19.3 18.5 19.3 18.5 19.3 18.5 18.5 18.5 20.1
[14:04:15.291] <TB0> INFO: ----------------------------------------------------------------------
[14:04:15.291] <TB0> INFO: PixTestPretest::findTiming()
[14:04:15.291] <TB0> INFO: ----------------------------------------------------------------------
[14:04:15.291] <TB0> INFO: PixTestCmd::init()
[14:04:15.853] <TB0> WARNING: Not unmasking DUT, not setting Calibrate bits!

[14:04:47.795] <TB0> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[14:04:47.795] <TB0> INFO: (success/tries = 100/100), width = 4
[14:04:49.300] <TB0> INFO: ----------------------------------------------------------------------
[14:04:49.300] <TB0> INFO: PixTestPretest::findWorkingPixel()
[14:04:49.300] <TB0> INFO: ----------------------------------------------------------------------
[14:04:49.395] <TB0> INFO: Expecting 231680 events.
[14:04:59.347] <TB0> INFO: 231680 events read in total (9360ms).
[14:04:59.355] <TB0> INFO: Test took 10050ms.
[14:04:59.609] <TB0> INFO: Found working pixel in all ROCs: col/row = 12/22
[14:04:59.644] <TB0> INFO: ----------------------------------------------------------------------
[14:04:59.644] <TB0> INFO: PixTestPretest::setVthrCompCalDel()
[14:04:59.644] <TB0> INFO: ----------------------------------------------------------------------
[14:04:59.739] <TB0> INFO: Expecting 231680 events.
[14:05:09.563] <TB0> INFO: 231680 events read in total (9232ms).
[14:05:09.573] <TB0> INFO: Test took 9924ms.
[14:05:09.839] <TB0> INFO: PixTestPretest::setVthrCompCalDel() done
[14:05:09.839] <TB0> INFO: CalDel: 96 96 89 84 98 102 88 81 101 88 87 93 97 107 80 79
[14:05:09.839] <TB0> INFO: VthrComp: 51 51 52 61 52 52 52 51 52 51 51 51 51 51 51 51
[14:05:09.843] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C0.dat
[14:05:09.843] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C1.dat
[14:05:09.843] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C2.dat
[14:05:09.843] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C3.dat
[14:05:09.843] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C4.dat
[14:05:09.844] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C5.dat
[14:05:09.844] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C6.dat
[14:05:09.844] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C7.dat
[14:05:09.844] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C8.dat
[14:05:09.845] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C9.dat
[14:05:09.845] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C10.dat
[14:05:09.845] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C11.dat
[14:05:09.845] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C12.dat
[14:05:09.845] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C13.dat
[14:05:09.845] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C14.dat
[14:05:09.846] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters_C15.dat
[14:05:09.846] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//tbmParameters_C0a.dat
[14:05:09.846] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//tbmParameters_C0b.dat
[14:05:09.846] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//tbmParameters_C1a.dat
[14:05:09.846] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//tbmParameters_C1b.dat
[14:05:09.846] <TB0> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[14:05:09.899] <TB0> INFO: enter test to run
[14:05:09.900] <TB0> INFO: test: FullTest no parameter change
[14:05:09.900] <TB0> INFO: running: fulltest
[14:05:09.900] <TB0> INFO: ######################################################################
[14:05:09.900] <TB0> INFO: PixTestFullTest::doTest()
[14:05:09.900] <TB0> INFO: ######################################################################
[14:05:09.901] <TB0> INFO: ######################################################################
[14:05:09.901] <TB0> INFO: PixTestAlive::doTest()
[14:05:09.901] <TB0> INFO: ######################################################################
[14:05:09.902] <TB0> INFO: ----------------------------------------------------------------------
[14:05:09.902] <TB0> 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:05:09.902] <TB0> INFO: ----------------------------------------------------------------------
[14:05:10.143] <TB0> INFO: Expecting 41600 events.
[14:05:13.666] <TB0> INFO: 41600 events read in total (2931ms).
[14:05:13.667] <TB0> INFO: Test took 3764ms.
[14:05:13.899] <TB0> INFO: PixTestAlive::aliveTest() done
[14:05:13.899] <TB0> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[14:05:13.901] <TB0> INFO: ----------------------------------------------------------------------
[14:05:13.901] <TB0> 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:05:13.901] <TB0> INFO: ----------------------------------------------------------------------
[14:05:14.143] <TB0> INFO: Expecting 41600 events.
[14:05:17.086] <TB0> INFO: 41600 events read in total (2351ms).
[14:05:17.086] <TB0> INFO: Test took 3183ms.
[14:05:17.087] <TB0> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[14:05:17.324] <TB0> INFO: PixTestAlive::maskTest() done
[14:05:17.324] <TB0> 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:05:17.326] <TB0> INFO: ----------------------------------------------------------------------
[14:05:17.326] <TB0> 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:05:17.326] <TB0> INFO: ----------------------------------------------------------------------
[14:05:17.570] <TB0> INFO: Expecting 41600 events.
[14:05:21.093] <TB0> INFO: 41600 events read in total (2932ms).
[14:05:21.094] <TB0> INFO: Test took 3766ms.
[14:05:21.328] <TB0> INFO: PixTestAlive::addressDecodingTest() done
[14:05:21.328] <TB0> 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:05:21.329] <TB0> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[14:05:21.329] <TB0> INFO: Decoding statistics:
[14:05:21.329] <TB0> INFO: General information:
[14:05:21.329] <TB0> INFO: 16bit words read: 0
[14:05:21.329] <TB0> INFO: valid events total: 0
[14:05:21.329] <TB0> INFO: empty events: 0
[14:05:21.329] <TB0> INFO: valid events with pixels: 0
[14:05:21.329] <TB0> INFO: valid pixel hits: 0
[14:05:21.329] <TB0> INFO: Event errors: 0
[14:05:21.329] <TB0> INFO: start marker: 0
[14:05:21.329] <TB0> INFO: stop marker: 0
[14:05:21.329] <TB0> INFO: overflow: 0
[14:05:21.329] <TB0> INFO: invalid 5bit words: 0
[14:05:21.329] <TB0> INFO: invalid XOR eye diagram: 0
[14:05:21.329] <TB0> INFO: frame (failed synchr.): 0
[14:05:21.329] <TB0> INFO: idle data (no TBM trl): 0
[14:05:21.329] <TB0> INFO: no data (only TBM hdr): 0
[14:05:21.329] <TB0> INFO: TBM errors: 0
[14:05:21.329] <TB0> INFO: flawed TBM headers: 0
[14:05:21.329] <TB0> INFO: flawed TBM trailers: 0
[14:05:21.329] <TB0> INFO: event ID mismatches: 0
[14:05:21.329] <TB0> INFO: ROC errors: 0
[14:05:21.329] <TB0> INFO: missing ROC header(s): 0
[14:05:21.329] <TB0> INFO: misplaced readback start: 0
[14:05:21.329] <TB0> INFO: Pixel decoding errors: 0
[14:05:21.329] <TB0> INFO: pixel data incomplete: 0
[14:05:21.329] <TB0> INFO: pixel address: 0
[14:05:21.329] <TB0> INFO: pulse height fill bit: 0
[14:05:21.329] <TB0> INFO: buffer corruption: 0
[14:05:21.338] <TB0> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C15.dat
[14:05:21.339] <TB0> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr_C15.dat
[14:05:21.339] <TB0> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[14:05:21.339] <TB0> INFO: ######################################################################
[14:05:21.339] <TB0> INFO: PixTestReadback::doTest()
[14:05:21.339] <TB0> INFO: ######################################################################
[14:05:21.339] <TB0> INFO: ----------------------------------------------------------------------
[14:05:21.340] <TB0> INFO: PixTestReadback::CalibrateVd()
[14:05:21.340] <TB0> INFO: ----------------------------------------------------------------------
[14:05:31.310] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C0.dat
[14:05:31.310] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C1.dat
[14:05:31.310] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C2.dat
[14:05:31.310] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C3.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C4.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C5.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C6.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C7.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C8.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C9.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C10.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C11.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C12.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C13.dat
[14:05:31.311] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C14.dat
[14:05:31.312] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C15.dat
[14:05:31.342] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[14:05:31.342] <TB0> INFO: ----------------------------------------------------------------------
[14:05:31.342] <TB0> INFO: PixTestReadback::CalibrateVa()
[14:05:31.342] <TB0> INFO: ----------------------------------------------------------------------
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C0.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C1.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C2.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C3.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C4.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C5.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C6.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C7.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C8.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C9.dat
[14:05:41.265] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C10.dat
[14:05:41.266] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C11.dat
[14:05:41.266] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C12.dat
[14:05:41.266] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C13.dat
[14:05:41.266] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C14.dat
[14:05:41.266] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C15.dat
[14:05:41.295] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[14:05:41.295] <TB0> INFO: ----------------------------------------------------------------------
[14:05:41.295] <TB0> INFO: PixTestReadback::readbackVbg()
[14:05:41.296] <TB0> INFO: ----------------------------------------------------------------------
[14:05:48.961] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[14:05:48.961] <TB0> INFO: ----------------------------------------------------------------------
[14:05:48.961] <TB0> INFO: PixTestReadback::getCalibratedVbg()
[14:05:48.961] <TB0> INFO: ----------------------------------------------------------------------
[14:05:48.961] <TB0> INFO: Vbg will be calibrated using Vd calibration
[14:05:48.961] <TB0> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 152.7calibrated Vbg = 1.18763 :::*/*/*/*/
[14:05:48.961] <TB0> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 150calibrated Vbg = 1.18661 :::*/*/*/*/
[14:05:48.961] <TB0> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 154.6calibrated Vbg = 1.18415 :::*/*/*/*/
[14:05:48.961] <TB0> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 161.4calibrated Vbg = 1.17898 :::*/*/*/*/
[14:05:48.961] <TB0> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 150calibrated Vbg = 1.17908 :::*/*/*/*/
[14:05:48.961] <TB0> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 172calibrated Vbg = 1.1866 :::*/*/*/*/
[14:05:48.961] <TB0> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 156.1calibrated Vbg = 1.19001 :::*/*/*/*/
[14:05:48.962] <TB0> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 158.5calibrated Vbg = 1.18361 :::*/*/*/*/
[14:05:48.962] <TB0> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 160.5calibrated Vbg = 1.1779 :::*/*/*/*/
[14:05:48.962] <TB0> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 154.3calibrated Vbg = 1.18038 :::*/*/*/*/
[14:05:48.962] <TB0> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 161.6calibrated Vbg = 1.17295 :::*/*/*/*/
[14:05:48.962] <TB0> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 149.2calibrated Vbg = 1.16978 :::*/*/*/*/
[14:05:48.962] <TB0> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 160.6calibrated Vbg = 1.17602 :::*/*/*/*/
[14:05:48.962] <TB0> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 151.8calibrated Vbg = 1.19049 :::*/*/*/*/
[14:05:48.962] <TB0> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 159.6calibrated Vbg = 1.18383 :::*/*/*/*/
[14:05:48.962] <TB0> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 149.2calibrated Vbg = 1.17541 :::*/*/*/*/
[14:05:48.965] <TB0> INFO: ----------------------------------------------------------------------
[14:05:48.965] <TB0> INFO: PixTestReadback::CalibrateIa()
[14:05:48.965] <TB0> INFO: ----------------------------------------------------------------------
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C0.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C1.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C2.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C3.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C4.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C5.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C6.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C7.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C8.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C9.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C10.dat
[14:08:29.819] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C11.dat
[14:08:29.820] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C12.dat
[14:08:29.820] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C13.dat
[14:08:29.820] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C14.dat
[14:08:29.820] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//readbackCal_C15.dat
[14:08:29.848] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[14:08:29.851] <TB0> INFO: PixTestReadback::doTest() done
[14:08:29.851] <TB0> INFO: Decoding statistics:
[14:08:29.851] <TB0> INFO: General information:
[14:08:29.851] <TB0> INFO: 16bit words read: 1536
[14:08:29.851] <TB0> INFO: valid events total: 256
[14:08:29.851] <TB0> INFO: empty events: 256
[14:08:29.851] <TB0> INFO: valid events with pixels: 0
[14:08:29.851] <TB0> INFO: valid pixel hits: 0
[14:08:29.851] <TB0> INFO: Event errors: 0
[14:08:29.851] <TB0> INFO: start marker: 0
[14:08:29.851] <TB0> INFO: stop marker: 0
[14:08:29.851] <TB0> INFO: overflow: 0
[14:08:29.851] <TB0> INFO: invalid 5bit words: 0
[14:08:29.851] <TB0> INFO: invalid XOR eye diagram: 0
[14:08:29.851] <TB0> INFO: frame (failed synchr.): 0
[14:08:29.851] <TB0> INFO: idle data (no TBM trl): 0
[14:08:29.851] <TB0> INFO: no data (only TBM hdr): 0
[14:08:29.851] <TB0> INFO: TBM errors: 0
[14:08:29.851] <TB0> INFO: flawed TBM headers: 0
[14:08:29.851] <TB0> INFO: flawed TBM trailers: 0
[14:08:29.851] <TB0> INFO: event ID mismatches: 0
[14:08:29.851] <TB0> INFO: ROC errors: 0
[14:08:29.851] <TB0> INFO: missing ROC header(s): 0
[14:08:29.851] <TB0> INFO: misplaced readback start: 0
[14:08:29.851] <TB0> INFO: Pixel decoding errors: 0
[14:08:29.851] <TB0> INFO: pixel data incomplete: 0
[14:08:29.851] <TB0> INFO: pixel address: 0
[14:08:29.851] <TB0> INFO: pulse height fill bit: 0
[14:08:29.851] <TB0> INFO: buffer corruption: 0
[14:08:29.902] <TB0> INFO: ######################################################################
[14:08:29.902] <TB0> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[14:08:29.902] <TB0> INFO: ######################################################################
[14:08:29.906] <TB0> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[14:08:29.924] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[14:08:29.924] <TB0> INFO: run 1 of 1
[14:08:30.160] <TB0> INFO: Expecting 3120000 events.
[14:09:02.037] <TB0> INFO: 681605 events read in total (31285ms).
[14:09:14.470] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (6) != TBM ID (129)

[14:09:14.609] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 6 6 129 6 6 6 6 6

[14:09:14.609] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (7)

[14:09:14.609] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:09:14.609] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00a 8000 4181 266 29ef 4181 266 29ef e022 c000

[14:09:14.609] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a004 80b1 4300 266 29ef 4300 266 29ef e022 c000

[14:09:14.609] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a005 80c0 4180 266 29ef 4180 266 29ef e022 c000

[14:09:14.609] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 29ef 4300 266 29ef e022 c000

[14:09:14.609] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a007 8040 4300 266 29ef 4301 266 29ef e022 c000

[14:09:14.609] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a008 80b1 4180 266 29ef 4181 266 29ef e022 c000

[14:09:14.609] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a009 80c0 4181 266 29ef 4181 266 29ef e022 c000

[14:09:32.433] <TB0> INFO: 1358005 events read in total (61681ms).
[14:09:44.798] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (54) != TBM ID (129)

[14:09:44.937] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 54 54 129 54 54 54 54 54

[14:09:44.937] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (55)

[14:09:44.940] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:09:44.940] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03a 8000 4301 4cc 25ef 4380 4cc 25ef e022 c000

[14:09:44.940] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a034 80b1 4300 4cc 25ef 4380 4cc 25ef e022 c000

[14:09:44.940] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a035 80c0 4300 4cc 25ef 4300 4cc 25ef e022 c000

[14:09:44.940] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 25ef 4300 4cc 25ef e022 c000

[14:09:44.940] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a037 8040 4300 4cc 25ef 4301 4cc 25ef e022 c000

[14:09:44.940] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a038 80b1 4300 4cc 25ef 4301 4cc 25ef e022 c000

[14:09:44.940] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a039 80c0 4301 4cc 25ef 4300 4cc 25ef e022 c000

[14:10:02.689] <TB0> INFO: 2031100 events read in total (91937ms).
[14:10:15.038] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (125) != TBM ID (129)

[14:10:15.174] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 125 125 129 125 125 125 125 125

[14:10:15.175] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (126)

[14:10:15.175] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:10:15.175] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 e022 c000

[14:10:15.176] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07b 8040 4181 4180 e022 c000

[14:10:15.176] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07c 80b1 4180 4180 e022 c000

[14:10:15.176] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 e022 c000

[14:10:15.176] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07e 8000 4180 4380 e022 c000

[14:10:15.176] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07f 8040 4303 4301 e022 c000

[14:10:15.176] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a080 80b1 4180 4380 e022 c000

[14:10:15.179] <TB0> WARNING: Channel 0 ROC 1: Readback start marker after 32 readouts!

[14:10:15.179] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:10:15.179] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a090 80b1 4300 4300 e022 c000

[14:10:15.179] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08a 8000 4300 4300 e022 c000

[14:10:15.179] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08b 8040 4301 4301 e022 c000

[14:10:15.179] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08c 80b1 4300 4300 e022 c000

[14:10:15.179] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08d 80c0 4301 4302 e022 c000

[14:10:15.179] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08e 8000 4180 4180 e022 c000

[14:10:15.179] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a08f 8040 4182 4181 e022 c000

[14:10:32.968] <TB0> INFO: 2703295 events read in total (122216ms).
[14:10:40.731] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (64) != TBM ID (129)

[14:10:40.873] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 64 64 129 64 64 64 64 64

[14:10:40.873] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (65)

[14:10:40.873] <TB0> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[14:10:40.873] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a044 80b1 4180 4380 e022 c000

[14:10:40.873] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03e 8000 4180 4300 e022 c000

[14:10:40.873] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03f 8040 4182 4181 e022 c000

[14:10:40.873] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 e022 c000

[14:10:40.873] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a041 80c0 4181 4181 e022 c000

[14:10:40.873] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a042 8000 4300 4380 e022 c000

[14:10:40.873] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a043 8040 4180 4180 e022 c000

[14:10:52.055] <TB0> INFO: 3120000 events read in total (141303ms).
[14:10:52.116] <TB0> INFO: Test took 142193ms.
[14:11:14.196] <TB0> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 164 seconds
[14:11:14.196] <TB0> INFO: number of dead bumps (per ROC): 0 1 0 2 0 0 0 0 0 0 0 0 0 0 1 0
[14:11:14.196] <TB0> INFO: separation cut (per ROC): 107 116 101 123 126 111 102 121 106 106 120 124 104 105 104 110
[14:11:14.196] <TB0> INFO: Decoding statistics:
[14:11:14.196] <TB0> INFO: General information:
[14:11:14.196] <TB0> INFO: 16bit words read: 0
[14:11:14.196] <TB0> INFO: valid events total: 0
[14:11:14.196] <TB0> INFO: empty events: 0
[14:11:14.196] <TB0> INFO: valid events with pixels: 0
[14:11:14.196] <TB0> INFO: valid pixel hits: 0
[14:11:14.196] <TB0> INFO: Event errors: 0
[14:11:14.196] <TB0> INFO: start marker: 0
[14:11:14.196] <TB0> INFO: stop marker: 0
[14:11:14.196] <TB0> INFO: overflow: 0
[14:11:14.196] <TB0> INFO: invalid 5bit words: 0
[14:11:14.196] <TB0> INFO: invalid XOR eye diagram: 0
[14:11:14.196] <TB0> INFO: frame (failed synchr.): 0
[14:11:14.196] <TB0> INFO: idle data (no TBM trl): 0
[14:11:14.196] <TB0> INFO: no data (only TBM hdr): 0
[14:11:14.196] <TB0> INFO: TBM errors: 0
[14:11:14.196] <TB0> INFO: flawed TBM headers: 0
[14:11:14.196] <TB0> INFO: flawed TBM trailers: 0
[14:11:14.196] <TB0> INFO: event ID mismatches: 0
[14:11:14.196] <TB0> INFO: ROC errors: 0
[14:11:14.196] <TB0> INFO: missing ROC header(s): 0
[14:11:14.196] <TB0> INFO: misplaced readback start: 0
[14:11:14.196] <TB0> INFO: Pixel decoding errors: 0
[14:11:14.196] <TB0> INFO: pixel data incomplete: 0
[14:11:14.197] <TB0> INFO: pixel address: 0
[14:11:14.197] <TB0> INFO: pulse height fill bit: 0
[14:11:14.197] <TB0> INFO: buffer corruption: 0
[14:11:14.242] <TB0> INFO: ######################################################################
[14:11:14.242] <TB0> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:11:14.242] <TB0> INFO: ######################################################################
[14:11:14.242] <TB0> INFO: ----------------------------------------------------------------------
[14:11:14.242] <TB0> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:11:14.242] <TB0> INFO: ----------------------------------------------------------------------
[14:11:14.243] <TB0> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[14:11:14.258] <TB0> INFO: dacScan split into 1 runs with ntrig = 50
[14:11:14.259] <TB0> INFO: run 1 of 1
[14:11:14.499] <TB0> INFO: Expecting 36608000 events.
[14:11:38.974] <TB0> INFO: 696400 events read in total (23883ms).
[14:12:01.629] <TB0> INFO: 1373550 events read in total (46538ms).
[14:12:24.768] <TB0> INFO: 2055250 events read in total (69677ms).
[14:12:47.864] <TB0> INFO: 2733400 events read in total (92773ms).
[14:13:10.775] <TB0> INFO: 3412550 events read in total (115684ms).
[14:13:33.520] <TB0> INFO: 4089300 events read in total (138429ms).
[14:13:56.772] <TB0> INFO: 4769600 events read in total (161681ms).
[14:14:19.776] <TB0> INFO: 5449450 events read in total (184685ms).
[14:14:42.968] <TB0> INFO: 6130300 events read in total (207877ms).
[14:15:06.260] <TB0> INFO: 6808100 events read in total (231169ms).
[14:15:29.384] <TB0> INFO: 7484850 events read in total (254293ms).
[14:15:52.568] <TB0> INFO: 8160750 events read in total (277477ms).
[14:16:16.078] <TB0> INFO: 8840350 events read in total (300987ms).
[14:16:39.555] <TB0> INFO: 9520050 events read in total (324464ms).
[14:17:02.909] <TB0> INFO: 10198500 events read in total (347818ms).
[14:17:26.284] <TB0> INFO: 10876200 events read in total (371193ms).
[14:17:49.377] <TB0> INFO: 11553250 events read in total (394286ms).
[14:18:12.715] <TB0> INFO: 12231000 events read in total (417624ms).
[14:18:35.934] <TB0> INFO: 12907150 events read in total (440843ms).
[14:18:59.219] <TB0> INFO: 13583600 events read in total (464128ms).
[14:19:22.243] <TB0> INFO: 14258750 events read in total (487152ms).
[14:19:45.255] <TB0> INFO: 14932400 events read in total (510164ms).
[14:20:08.145] <TB0> INFO: 15606500 events read in total (533054ms).
[14:20:31.187] <TB0> INFO: 16283400 events read in total (556096ms).
[14:20:54.499] <TB0> INFO: 16956950 events read in total (579408ms).
[14:21:17.701] <TB0> INFO: 17632650 events read in total (602610ms).
[14:21:40.701] <TB0> INFO: 18304800 events read in total (625610ms).
[14:22:03.719] <TB0> INFO: 18978750 events read in total (648628ms).
[14:22:26.817] <TB0> INFO: 19649300 events read in total (671726ms).
[14:22:50.055] <TB0> INFO: 20320800 events read in total (694964ms).
[14:23:13.047] <TB0> INFO: 20992200 events read in total (717956ms).
[14:23:35.990] <TB0> INFO: 21664000 events read in total (740899ms).
[14:23:59.351] <TB0> INFO: 22335300 events read in total (764260ms).
[14:24:22.294] <TB0> INFO: 23007800 events read in total (787203ms).
[14:24:45.153] <TB0> INFO: 23679100 events read in total (810062ms).
[14:25:08.150] <TB0> INFO: 24348850 events read in total (833059ms).
[14:25:31.283] <TB0> INFO: 25020300 events read in total (856192ms).
[14:25:54.170] <TB0> INFO: 25690350 events read in total (879079ms).
[14:26:16.927] <TB0> INFO: 26360450 events read in total (901836ms).
[14:26:39.835] <TB0> INFO: 27029800 events read in total (924744ms).
[14:27:02.917] <TB0> INFO: 27698200 events read in total (947826ms).
[14:27:26.044] <TB0> INFO: 28365600 events read in total (970953ms).
[14:27:49.124] <TB0> INFO: 29034200 events read in total (994033ms).
[14:28:11.870] <TB0> INFO: 29699400 events read in total (1016779ms).
[14:28:35.269] <TB0> INFO: 30366050 events read in total (1040178ms).
[14:28:58.104] <TB0> INFO: 31031400 events read in total (1063013ms).
[14:29:20.999] <TB0> INFO: 31699800 events read in total (1085908ms).
[14:29:44.137] <TB0> INFO: 32366700 events read in total (1109046ms).
[14:30:07.208] <TB0> INFO: 33034850 events read in total (1132117ms).
[14:30:30.320] <TB0> INFO: 33702800 events read in total (1155229ms).
[14:30:53.367] <TB0> INFO: 34373850 events read in total (1178276ms).
[14:31:16.583] <TB0> INFO: 35042450 events read in total (1201492ms).
[14:31:39.421] <TB0> INFO: 35714600 events read in total (1224330ms).
[14:32:02.652] <TB0> INFO: 36393700 events read in total (1247561ms).
[14:32:10.015] <TB0> INFO: 36608000 events read in total (1254924ms).
[14:32:10.107] <TB0> INFO: Test took 1255848ms.
[14:32:10.567] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:12.450] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:14.352] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:15.957] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:17.967] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:19.905] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:21.640] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:23.697] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:25.567] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:27.501] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:29.237] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:31.121] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:33.358] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:35.300] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:37.442] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:39.514] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[14:32:41.648] <TB0> INFO: PixTestScurves::scurves() done
[14:32:41.648] <TB0> INFO: Vcal mean: 120.04 125.35 119.53 132.65 132.38 129.68 122.58 136.79 119.23 128.41 120.40 116.07 123.96 124.95 115.83 119.42
[14:32:41.648] <TB0> INFO: Vcal RMS: 6.07 6.12 6.90 8.19 6.32 6.21 6.26 6.18 5.97 6.88 6.51 5.79 5.93 7.11 5.20 5.26
[14:32:41.648] <TB0> INFO: PixTestScurves::fullTest() done, duration: 1287 seconds
[14:32:41.648] <TB0> INFO: Decoding statistics:
[14:32:41.648] <TB0> INFO: General information:
[14:32:41.648] <TB0> INFO: 16bit words read: 0
[14:32:41.648] <TB0> INFO: valid events total: 0
[14:32:41.648] <TB0> INFO: empty events: 0
[14:32:41.648] <TB0> INFO: valid events with pixels: 0
[14:32:41.648] <TB0> INFO: valid pixel hits: 0
[14:32:41.648] <TB0> INFO: Event errors: 0
[14:32:41.648] <TB0> INFO: start marker: 0
[14:32:41.648] <TB0> INFO: stop marker: 0
[14:32:41.648] <TB0> INFO: overflow: 0
[14:32:41.648] <TB0> INFO: invalid 5bit words: 0
[14:32:41.648] <TB0> INFO: invalid XOR eye diagram: 0
[14:32:41.648] <TB0> INFO: frame (failed synchr.): 0
[14:32:41.648] <TB0> INFO: idle data (no TBM trl): 0
[14:32:41.648] <TB0> INFO: no data (only TBM hdr): 0
[14:32:41.648] <TB0> INFO: TBM errors: 0
[14:32:41.648] <TB0> INFO: flawed TBM headers: 0
[14:32:41.648] <TB0> INFO: flawed TBM trailers: 0
[14:32:41.648] <TB0> INFO: event ID mismatches: 0
[14:32:41.648] <TB0> INFO: ROC errors: 0
[14:32:41.648] <TB0> INFO: missing ROC header(s): 0
[14:32:41.648] <TB0> INFO: misplaced readback start: 0
[14:32:41.648] <TB0> INFO: Pixel decoding errors: 0
[14:32:41.648] <TB0> INFO: pixel data incomplete: 0
[14:32:41.648] <TB0> INFO: pixel address: 0
[14:32:41.648] <TB0> INFO: pulse height fill bit: 0
[14:32:41.648] <TB0> INFO: buffer corruption: 0
[14:32:41.735] <TB0> INFO: ######################################################################
[14:32:41.735] <TB0> INFO: PixTestTrim::doTest()
[14:32:41.735] <TB0> INFO: ######################################################################
[14:32:41.737] <TB0> INFO: ----------------------------------------------------------------------
[14:32:41.737] <TB0> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[14:32:41.737] <TB0> INFO: ----------------------------------------------------------------------
[14:32:41.809] <TB0> INFO: ---> VthrComp thr map (minimal VthrComp)
[14:32:41.809] <TB0> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[14:32:41.823] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[14:32:41.823] <TB0> INFO: run 1 of 1
[14:32:42.154] <TB0> INFO: Expecting 5025280 events.
[14:33:12.778] <TB0> INFO: 829440 events read in total (30017ms).
[14:33:42.829] <TB0> INFO: 1656576 events read in total (60068ms).
[14:34:12.890] <TB0> INFO: 2482120 events read in total (90129ms).
[14:34:43.032] <TB0> INFO: 3304080 events read in total (120271ms).
[14:35:13.120] <TB0> INFO: 4121688 events read in total (150359ms).
[14:35:43.156] <TB0> INFO: 4939528 events read in total (180395ms).
[14:35:46.670] <TB0> INFO: 5025280 events read in total (183909ms).
[14:35:46.722] <TB0> INFO: Test took 184900ms.
[14:36:05.139] <TB0> INFO: ROC 0 VthrComp = 122
[14:36:05.140] <TB0> INFO: ROC 1 VthrComp = 124
[14:36:05.140] <TB0> INFO: ROC 2 VthrComp = 112
[14:36:05.140] <TB0> INFO: ROC 3 VthrComp = 131
[14:36:05.140] <TB0> INFO: ROC 4 VthrComp = 131
[14:36:05.140] <TB0> INFO: ROC 5 VthrComp = 124
[14:36:05.140] <TB0> INFO: ROC 6 VthrComp = 113
[14:36:05.140] <TB0> INFO: ROC 7 VthrComp = 131
[14:36:05.141] <TB0> INFO: ROC 8 VthrComp = 117
[14:36:05.141] <TB0> INFO: ROC 9 VthrComp = 122
[14:36:05.141] <TB0> INFO: ROC 10 VthrComp = 125
[14:36:05.141] <TB0> INFO: ROC 11 VthrComp = 120
[14:36:05.141] <TB0> INFO: ROC 12 VthrComp = 119
[14:36:05.141] <TB0> INFO: ROC 13 VthrComp = 113
[14:36:05.141] <TB0> INFO: ROC 14 VthrComp = 119
[14:36:05.141] <TB0> INFO: ROC 15 VthrComp = 126
[14:36:05.469] <TB0> INFO: Expecting 41600 events.
[14:36:09.283] <TB0> INFO: 41600 events read in total (3223ms).
[14:36:09.284] <TB0> INFO: Test took 4140ms.
[14:36:09.294] <TB0> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[14:36:09.294] <TB0> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[14:36:09.306] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[14:36:09.306] <TB0> INFO: run 1 of 1
[14:36:09.590] <TB0> INFO: Expecting 5025280 events.
[14:36:35.830] <TB0> INFO: 589344 events read in total (25648ms).
[14:37:01.872] <TB0> INFO: 1178288 events read in total (51690ms).
[14:37:27.373] <TB0> INFO: 1767664 events read in total (77191ms).
[14:37:53.323] <TB0> INFO: 2355880 events read in total (103141ms).
[14:38:19.167] <TB0> INFO: 2942544 events read in total (128985ms).
[14:38:44.596] <TB0> INFO: 3528392 events read in total (154414ms).
[14:39:10.241] <TB0> INFO: 4113040 events read in total (180059ms).
[14:39:35.627] <TB0> INFO: 4697112 events read in total (205445ms).
[14:39:49.997] <TB0> INFO: 5025280 events read in total (219815ms).
[14:39:50.084] <TB0> INFO: Test took 220778ms.
[14:40:17.605] <TB0> INFO: roc 0 with ID = 0 has maximal Vcal 60.9335 for pixel 22/1 mean/min/max = 46.435/31.8115/61.0584
[14:40:17.605] <TB0> INFO: roc 1 with ID = 1 has maximal Vcal 61.5943 for pixel 0/58 mean/min/max = 46.9405/32.2093/61.6717
[14:40:17.605] <TB0> INFO: roc 2 with ID = 2 has maximal Vcal 62.8339 for pixel 3/9 mean/min/max = 48.041/33.2479/62.8341
[14:40:17.606] <TB0> INFO: roc 3 with ID = 3 has maximal Vcal 66.3231 for pixel 18/56 mean/min/max = 49.0104/30.9855/67.0354
[14:40:17.606] <TB0> INFO: roc 4 with ID = 4 has maximal Vcal 64.4433 for pixel 0/20 mean/min/max = 49.2153/33.9871/64.4435
[14:40:17.607] <TB0> INFO: roc 5 with ID = 5 has maximal Vcal 59.9663 for pixel 51/53 mean/min/max = 46.2907/32.4663/60.115
[14:40:17.607] <TB0> INFO: roc 6 with ID = 6 has maximal Vcal 65.5188 for pixel 45/7 mean/min/max = 49.2995/32.9807/65.6183
[14:40:17.608] <TB0> INFO: roc 7 with ID = 7 has maximal Vcal 61.8471 for pixel 1/0 mean/min/max = 47.608/33.2146/62.0014
[14:40:17.608] <TB0> INFO: roc 8 with ID = 8 has maximal Vcal 60.8455 for pixel 0/1 mean/min/max = 46.3847/31.7886/60.9808
[14:40:17.608] <TB0> INFO: roc 9 with ID = 9 has maximal Vcal 64.7812 for pixel 10/11 mean/min/max = 48.6967/32.4868/64.9066
[14:40:17.609] <TB0> INFO: roc 10 with ID = 10 has maximal Vcal 60.8972 for pixel 13/2 mean/min/max = 45.938/30.6153/61.2606
[14:40:17.609] <TB0> INFO: roc 11 with ID = 11 has maximal Vcal 61.9887 for pixel 1/0 mean/min/max = 47.4941/32.9488/62.0393
[14:40:17.610] <TB0> INFO: roc 12 with ID = 12 has maximal Vcal 60.6455 for pixel 21/0 mean/min/max = 46.584/32.4134/60.7547
[14:40:17.610] <TB0> INFO: roc 13 with ID = 13 has maximal Vcal 64.3369 for pixel 14/70 mean/min/max = 48.7054/32.7578/64.653
[14:40:17.611] <TB0> INFO: roc 14 with ID = 14 has maximal Vcal 58.7929 for pixel 4/2 mean/min/max = 45.3106/31.4901/59.1311
[14:40:17.611] <TB0> INFO: roc 15 with ID = 15 has maximal Vcal 58.1853 for pixel 1/2 mean/min/max = 44.8136/31.2138/58.4134
[14:40:17.612] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:40:17.702] <TB0> INFO: Expecting 411648 events.
[14:40:27.353] <TB0> INFO: 411648 events read in total (9055ms).
[14:40:27.362] <TB0> INFO: Expecting 411648 events.
[14:40:36.808] <TB0> INFO: 411648 events read in total (9043ms).
[14:40:36.820] <TB0> INFO: Expecting 411648 events.
[14:40:46.253] <TB0> INFO: 411648 events read in total (9030ms).
[14:40:46.266] <TB0> INFO: Expecting 411648 events.
[14:40:55.756] <TB0> INFO: 411648 events read in total (9075ms).
[14:40:55.772] <TB0> INFO: Expecting 411648 events.
[14:41:05.238] <TB0> INFO: 411648 events read in total (9063ms).
[14:41:05.256] <TB0> INFO: Expecting 411648 events.
[14:41:14.675] <TB0> INFO: 411648 events read in total (9016ms).
[14:41:14.701] <TB0> INFO: Expecting 411648 events.
[14:41:24.124] <TB0> INFO: 411648 events read in total (9020ms).
[14:41:24.153] <TB0> INFO: Expecting 411648 events.
[14:41:33.485] <TB0> INFO: 411648 events read in total (8928ms).
[14:41:33.509] <TB0> INFO: Expecting 411648 events.
[14:41:42.786] <TB0> INFO: 411648 events read in total (8873ms).
[14:41:42.815] <TB0> INFO: Expecting 411648 events.
[14:41:52.195] <TB0> INFO: 411648 events read in total (8977ms).
[14:41:52.226] <TB0> INFO: Expecting 411648 events.
[14:42:01.745] <TB0> INFO: 411648 events read in total (9116ms).
[14:42:01.788] <TB0> INFO: Expecting 411648 events.
[14:42:11.215] <TB0> INFO: 411648 events read in total (9024ms).
[14:42:11.255] <TB0> INFO: Expecting 411648 events.
[14:42:20.700] <TB0> INFO: 411648 events read in total (9042ms).
[14:42:20.738] <TB0> INFO: Expecting 411648 events.
[14:42:30.132] <TB0> INFO: 411648 events read in total (8991ms).
[14:42:30.172] <TB0> INFO: Expecting 411648 events.
[14:42:39.716] <TB0> INFO: 411648 events read in total (9141ms).
[14:42:39.762] <TB0> INFO: Expecting 411648 events.
[14:42:49.339] <TB0> INFO: 411648 events read in total (9174ms).
[14:42:49.387] <TB0> INFO: Test took 151775ms.
[14:42:49.993] <TB0> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[14:42:50.005] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[14:42:50.005] <TB0> INFO: run 1 of 1
[14:42:50.244] <TB0> INFO: Expecting 5025280 events.
[14:43:16.891] <TB0> INFO: 590504 events read in total (26056ms).
[14:43:42.948] <TB0> INFO: 1178720 events read in total (52113ms).
[14:44:09.012] <TB0> INFO: 1765832 events read in total (78177ms).
[14:44:35.003] <TB0> INFO: 2352904 events read in total (104168ms).
[14:45:01.130] <TB0> INFO: 2940024 events read in total (130295ms).
[14:45:27.471] <TB0> INFO: 3531136 events read in total (156636ms).
[14:45:53.412] <TB0> INFO: 4119992 events read in total (182577ms).
[14:46:19.474] <TB0> INFO: 4711904 events read in total (208640ms).
[14:46:33.384] <TB0> INFO: 5025280 events read in total (222549ms).
[14:46:33.516] <TB0> INFO: Test took 223511ms.
[14:46:59.067] <TB0> INFO: ---> TrimStepCorr4 extremal thresholds: 7.031263 .. 147.114153
[14:46:59.340] <TB0> INFO: Expecting 208000 events.
[14:47:09.326] <TB0> INFO: 208000 events read in total (9394ms).
[14:47:09.328] <TB0> INFO: Test took 10259ms.
[14:47:09.375] <TB0> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 7 .. 157 (-1/-1) hits flags = 528 (plus default)
[14:47:09.388] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[14:47:09.388] <TB0> INFO: run 1 of 1
[14:47:09.666] <TB0> INFO: Expecting 5025280 events.
[14:47:36.051] <TB0> INFO: 576416 events read in total (25793ms).
[14:48:01.787] <TB0> INFO: 1152376 events read in total (51529ms).
[14:48:27.401] <TB0> INFO: 1727960 events read in total (77143ms).
[14:48:52.943] <TB0> INFO: 2303928 events read in total (102685ms).
[14:49:18.574] <TB0> INFO: 2879896 events read in total (128316ms).
[14:49:44.327] <TB0> INFO: 3455464 events read in total (154069ms).
[14:50:09.809] <TB0> INFO: 4030296 events read in total (179551ms).
[14:50:35.544] <TB0> INFO: 4604600 events read in total (205286ms).
[14:50:54.409] <TB0> INFO: 5025280 events read in total (224151ms).
[14:50:54.543] <TB0> INFO: Test took 225156ms.
[14:51:22.092] <TB0> INFO: ---> TrimStepCorr2 extremal thresholds: 26.351046 .. 47.122463
[14:51:22.382] <TB0> INFO: Expecting 208000 events.
[14:51:32.320] <TB0> INFO: 208000 events read in total (9347ms).
[14:51:32.321] <TB0> INFO: Test took 10229ms.
[14:51:32.374] <TB0> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 57 (-1/-1) hits flags = 528 (plus default)
[14:51:32.388] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[14:51:32.388] <TB0> INFO: run 1 of 1
[14:51:32.666] <TB0> INFO: Expecting 1397760 events.
[14:52:00.750] <TB0> INFO: 656928 events read in total (27492ms).
[14:52:27.941] <TB0> INFO: 1311360 events read in total (54684ms).
[14:52:31.973] <TB0> INFO: 1397760 events read in total (58715ms).
[14:52:32.005] <TB0> INFO: Test took 59618ms.
[14:52:48.145] <TB0> INFO: ---> TrimStepCorr1a extremal thresholds: 27.918744 .. 50.465285
[14:52:48.411] <TB0> INFO: Expecting 208000 events.
[14:52:58.778] <TB0> INFO: 208000 events read in total (9775ms).
[14:52:58.778] <TB0> INFO: Test took 10631ms.
[14:52:58.827] <TB0> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 17 .. 60 (-1/-1) hits flags = 528 (plus default)
[14:52:58.840] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[14:52:58.840] <TB0> INFO: run 1 of 1
[14:52:59.118] <TB0> INFO: Expecting 1464320 events.
[14:53:27.304] <TB0> INFO: 642368 events read in total (27594ms).
[14:53:54.965] <TB0> INFO: 1283688 events read in total (55255ms).
[14:54:03.315] <TB0> INFO: 1464320 events read in total (63605ms).
[14:54:03.353] <TB0> INFO: Test took 64513ms.
[14:54:17.493] <TB0> INFO: ---> TrimStepCorr1b extremal thresholds: 26.689918 .. 54.074023
[14:54:17.736] <TB0> INFO: Expecting 208000 events.
[14:54:27.713] <TB0> INFO: 208000 events read in total (9386ms).
[14:54:27.715] <TB0> INFO: Test took 10220ms.
[14:54:27.786] <TB0> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 16 .. 64 (-1/-1) hits flags = 528 (plus default)
[14:54:27.800] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[14:54:27.800] <TB0> INFO: run 1 of 1
[14:54:28.080] <TB0> INFO: Expecting 1630720 events.
[14:54:55.832] <TB0> INFO: 634656 events read in total (27160ms).
[14:55:22.921] <TB0> INFO: 1269576 events read in total (54249ms).
[14:55:38.586] <TB0> INFO: 1630720 events read in total (69914ms).
[14:55:38.620] <TB0> INFO: Test took 70820ms.
[14:55:54.127] <TB0> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[14:55:54.127] <TB0> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[14:55:54.141] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[14:55:54.141] <TB0> INFO: run 1 of 1
[14:55:54.470] <TB0> INFO: Expecting 1364480 events.
[14:56:22.841] <TB0> INFO: 667776 events read in total (27779ms).
[14:56:51.026] <TB0> INFO: 1335680 events read in total (55965ms).
[14:56:52.629] <TB0> INFO: 1364480 events read in total (57568ms).
[14:56:52.662] <TB0> INFO: Test took 58521ms.
[14:57:06.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C0.dat
[14:57:06.882] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C1.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C2.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C3.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C4.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C5.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C6.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C7.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C8.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C9.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C10.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C11.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C12.dat
[14:57:06.883] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C13.dat
[14:57:06.884] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C14.dat
[14:57:06.884] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C15.dat
[14:57:06.884] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C0.dat
[14:57:06.890] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C1.dat
[14:57:06.895] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C2.dat
[14:57:06.900] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C3.dat
[14:57:06.905] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C4.dat
[14:57:06.910] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C5.dat
[14:57:06.915] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C6.dat
[14:57:06.919] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C7.dat
[14:57:06.924] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C8.dat
[14:57:06.929] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C9.dat
[14:57:06.933] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C10.dat
[14:57:06.938] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C11.dat
[14:57:06.943] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C12.dat
[14:57:06.948] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C13.dat
[14:57:06.953] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C14.dat
[14:57:06.957] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//trimParameters35_C15.dat
[14:57:06.962] <TB0> INFO: PixTestTrim::trimTest() done
[14:57:06.962] <TB0> INFO: vtrim: 134 123 115 132 139 104 139 124 111 127 144 129 110 122 119 123
[14:57:06.962] <TB0> INFO: vthrcomp: 122 124 112 131 131 124 113 131 117 122 125 120 119 113 119 126
[14:57:06.962] <TB0> INFO: vcal mean: 35.06 35.03 35.16 35.60 35.17 35.04 36.85 35.14 35.01 36.22 34.95 35.07 35.08 35.12 34.95 34.98
[14:57:06.962] <TB0> INFO: vcal RMS: 1.13 1.21 1.25 1.81 1.29 1.14 2.80 1.27 1.15 2.35 1.26 1.17 1.23 1.37 1.14 1.07
[14:57:06.962] <TB0> INFO: bits mean: 9.78 9.24 9.33 9.48 8.20 9.29 10.15 9.05 8.91 9.80 10.31 9.09 9.26 9.19 9.57 9.63
[14:57:06.962] <TB0> INFO: bits RMS: 2.58 2.76 2.51 2.75 2.79 2.76 2.52 2.74 3.04 2.63 2.48 2.74 2.87 2.66 2.81 2.86
[14:57:06.970] <TB0> INFO: ----------------------------------------------------------------------
[14:57:06.970] <TB0> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[14:57:06.970] <TB0> INFO: ----------------------------------------------------------------------
[14:57:06.972] <TB0> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[14:57:06.983] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[14:57:06.983] <TB0> INFO: run 1 of 1
[14:57:07.220] <TB0> INFO: Expecting 4160000 events.
[14:57:39.978] <TB0> INFO: 765655 events read in total (32166ms).
[14:58:11.947] <TB0> INFO: 1526835 events read in total (64135ms).
[14:58:44.112] <TB0> INFO: 2282890 events read in total (96301ms).
[14:59:16.379] <TB0> INFO: 3035890 events read in total (128567ms).
[14:59:48.338] <TB0> INFO: 3784145 events read in total (160526ms).
[15:00:05.062] <TB0> INFO: 4160000 events read in total (177250ms).
[15:00:05.133] <TB0> INFO: Test took 178150ms.
[15:00:34.072] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 233 (-1/-1) hits flags = 528 (plus default)
[15:00:34.085] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[15:00:34.085] <TB0> INFO: run 1 of 1
[15:00:34.327] <TB0> INFO: Expecting 4867200 events.
[15:01:05.847] <TB0> INFO: 701890 events read in total (30928ms).
[15:01:36.585] <TB0> INFO: 1401265 events read in total (61666ms).
[15:02:07.105] <TB0> INFO: 2098175 events read in total (92186ms).
[15:02:37.823] <TB0> INFO: 2792830 events read in total (122904ms).
[15:03:08.440] <TB0> INFO: 3484885 events read in total (153521ms).
[15:03:38.915] <TB0> INFO: 4173150 events read in total (183996ms).
[15:04:09.527] <TB0> INFO: 4865025 events read in total (214608ms).
[15:04:10.056] <TB0> INFO: 4867200 events read in total (215137ms).
[15:04:10.175] <TB0> INFO: Test took 216090ms.
[15:04:41.333] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 231 (-1/-1) hits flags = 528 (plus default)
[15:04:41.346] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[15:04:41.346] <TB0> INFO: run 1 of 1
[15:04:41.584] <TB0> INFO: Expecting 4825600 events.
[15:05:13.166] <TB0> INFO: 704100 events read in total (30990ms).
[15:05:43.877] <TB0> INFO: 1405785 events read in total (61701ms).
[15:06:14.405] <TB0> INFO: 2105025 events read in total (92229ms).
[15:06:45.293] <TB0> INFO: 2801810 events read in total (123117ms).
[15:07:16.030] <TB0> INFO: 3495500 events read in total (153854ms).
[15:07:47.040] <TB0> INFO: 4186170 events read in total (184864ms).
[15:08:15.883] <TB0> INFO: 4825600 events read in total (213707ms).
[15:08:16.006] <TB0> INFO: Test took 214659ms.
[15:08:47.588] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 228 (-1/-1) hits flags = 528 (plus default)
[15:08:47.601] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[15:08:47.601] <TB0> INFO: run 1 of 1
[15:08:47.838] <TB0> INFO: Expecting 4763200 events.
[15:09:19.117] <TB0> INFO: 707290 events read in total (30687ms).
[15:09:50.114] <TB0> INFO: 1411735 events read in total (61684ms).
[15:10:21.196] <TB0> INFO: 2114205 events read in total (92766ms).
[15:10:51.406] <TB0> INFO: 2813950 events read in total (122976ms).
[15:11:22.194] <TB0> INFO: 3510990 events read in total (153764ms).
[15:11:53.291] <TB0> INFO: 4204415 events read in total (184861ms).
[15:12:19.015] <TB0> INFO: 4763200 events read in total (210585ms).
[15:12:19.204] <TB0> INFO: Test took 211602ms.
[15:12:49.212] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 230 (-1/-1) hits flags = 528 (plus default)
[15:12:49.226] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[15:12:49.226] <TB0> INFO: run 1 of 1
[15:12:49.464] <TB0> INFO: Expecting 4804800 events.
[15:13:20.981] <TB0> INFO: 705425 events read in total (30925ms).
[15:13:51.732] <TB0> INFO: 1408215 events read in total (61676ms).
[15:14:22.671] <TB0> INFO: 2108470 events read in total (92615ms).
[15:14:53.447] <TB0> INFO: 2806460 events read in total (123391ms).
[15:15:24.667] <TB0> INFO: 3501415 events read in total (154611ms).
[15:15:55.697] <TB0> INFO: 4193190 events read in total (185641ms).
[15:16:23.153] <TB0> INFO: 4804800 events read in total (213097ms).
[15:16:23.335] <TB0> INFO: Test took 214108ms.
[15:16:49.771] <TB0> INFO: PixTestTrim::trimBitTest() done
[15:16:49.772] <TB0> INFO: PixTestTrim::doTest() done, duration: 2648 seconds
[15:16:49.772] <TB0> INFO: Decoding statistics:
[15:16:49.772] <TB0> INFO: General information:
[15:16:49.772] <TB0> INFO: 16bit words read: 0
[15:16:49.772] <TB0> INFO: valid events total: 0
[15:16:49.772] <TB0> INFO: empty events: 0
[15:16:49.772] <TB0> INFO: valid events with pixels: 0
[15:16:49.772] <TB0> INFO: valid pixel hits: 0
[15:16:49.772] <TB0> INFO: Event errors: 0
[15:16:49.772] <TB0> INFO: start marker: 0
[15:16:49.772] <TB0> INFO: stop marker: 0
[15:16:49.772] <TB0> INFO: overflow: 0
[15:16:49.772] <TB0> INFO: invalid 5bit words: 0
[15:16:49.772] <TB0> INFO: invalid XOR eye diagram: 0
[15:16:49.772] <TB0> INFO: frame (failed synchr.): 0
[15:16:49.772] <TB0> INFO: idle data (no TBM trl): 0
[15:16:49.772] <TB0> INFO: no data (only TBM hdr): 0
[15:16:49.772] <TB0> INFO: TBM errors: 0
[15:16:49.772] <TB0> INFO: flawed TBM headers: 0
[15:16:49.772] <TB0> INFO: flawed TBM trailers: 0
[15:16:49.772] <TB0> INFO: event ID mismatches: 0
[15:16:49.772] <TB0> INFO: ROC errors: 0
[15:16:49.772] <TB0> INFO: missing ROC header(s): 0
[15:16:49.772] <TB0> INFO: misplaced readback start: 0
[15:16:49.772] <TB0> INFO: Pixel decoding errors: 0
[15:16:49.772] <TB0> INFO: pixel data incomplete: 0
[15:16:49.772] <TB0> INFO: pixel address: 0
[15:16:49.772] <TB0> INFO: pulse height fill bit: 0
[15:16:49.772] <TB0> INFO: buffer corruption: 0
[15:16:50.405] <TB0> INFO: ######################################################################
[15:16:50.405] <TB0> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[15:16:50.405] <TB0> INFO: ######################################################################
[15:16:50.684] <TB0> INFO: Expecting 41600 events.
[15:16:54.214] <TB0> INFO: 41600 events read in total (2938ms).
[15:16:54.215] <TB0> INFO: Test took 3809ms.
[15:16:54.658] <TB0> INFO: Expecting 41600 events.
[15:16:58.267] <TB0> INFO: 41600 events read in total (3017ms).
[15:16:58.269] <TB0> INFO: Test took 3851ms.
[15:16:58.558] <TB0> INFO: Expecting 41600 events.
[15:17:02.095] <TB0> INFO: 41600 events read in total (2945ms).
[15:17:02.096] <TB0> INFO: Test took 3803ms.
[15:17:02.434] <TB0> INFO: Expecting 41600 events.
[15:17:05.960] <TB0> INFO: 41600 events read in total (2935ms).
[15:17:05.961] <TB0> INFO: Test took 3840ms.
[15:17:06.253] <TB0> INFO: Expecting 41600 events.
[15:17:09.810] <TB0> INFO: 41600 events read in total (2965ms).
[15:17:09.811] <TB0> INFO: Test took 3823ms.
[15:17:10.099] <TB0> INFO: Expecting 41600 events.
[15:17:13.615] <TB0> INFO: 41600 events read in total (2924ms).
[15:17:13.616] <TB0> INFO: Test took 3781ms.
[15:17:13.905] <TB0> INFO: Expecting 41600 events.
[15:17:17.430] <TB0> INFO: 41600 events read in total (2933ms).
[15:17:17.430] <TB0> INFO: Test took 3790ms.
[15:17:17.723] <TB0> INFO: Expecting 41600 events.
[15:17:21.244] <TB0> INFO: 41600 events read in total (2930ms).
[15:17:21.245] <TB0> INFO: Test took 3787ms.
[15:17:21.545] <TB0> INFO: Expecting 41600 events.
[15:17:25.122] <TB0> INFO: 41600 events read in total (2985ms).
[15:17:25.123] <TB0> INFO: Test took 3854ms.
[15:17:25.412] <TB0> INFO: Expecting 41600 events.
[15:17:29.017] <TB0> INFO: 41600 events read in total (3014ms).
[15:17:29.018] <TB0> INFO: Test took 3871ms.
[15:17:29.309] <TB0> INFO: Expecting 41600 events.
[15:17:32.924] <TB0> INFO: 41600 events read in total (3023ms).
[15:17:32.925] <TB0> INFO: Test took 3883ms.
[15:17:33.214] <TB0> INFO: Expecting 41600 events.
[15:17:36.741] <TB0> INFO: 41600 events read in total (2935ms).
[15:17:36.742] <TB0> INFO: Test took 3793ms.
[15:17:37.031] <TB0> INFO: Expecting 41600 events.
[15:17:40.611] <TB0> INFO: 41600 events read in total (2988ms).
[15:17:40.611] <TB0> INFO: Test took 3845ms.
[15:17:40.901] <TB0> INFO: Expecting 41600 events.
[15:17:44.443] <TB0> INFO: 41600 events read in total (2950ms).
[15:17:44.444] <TB0> INFO: Test took 3808ms.
[15:17:44.733] <TB0> INFO: Expecting 41600 events.
[15:17:48.349] <TB0> INFO: 41600 events read in total (3024ms).
[15:17:48.350] <TB0> INFO: Test took 3882ms.
[15:17:48.639] <TB0> INFO: Expecting 41600 events.
[15:17:52.241] <TB0> INFO: 41600 events read in total (3010ms).
[15:17:52.242] <TB0> INFO: Test took 3868ms.
[15:17:52.531] <TB0> INFO: Expecting 41600 events.
[15:17:56.053] <TB0> INFO: 41600 events read in total (2930ms).
[15:17:56.053] <TB0> INFO: Test took 3787ms.
[15:17:56.343] <TB0> INFO: Expecting 41600 events.
[15:17:59.869] <TB0> INFO: 41600 events read in total (2935ms).
[15:17:59.870] <TB0> INFO: Test took 3792ms.
[15:18:00.161] <TB0> INFO: Expecting 41600 events.
[15:18:03.767] <TB0> INFO: 41600 events read in total (3015ms).
[15:18:03.768] <TB0> INFO: Test took 3873ms.
[15:18:04.057] <TB0> INFO: Expecting 41600 events.
[15:18:07.564] <TB0> INFO: 41600 events read in total (2915ms).
[15:18:07.565] <TB0> INFO: Test took 3773ms.
[15:18:07.856] <TB0> INFO: Expecting 41600 events.
[15:18:11.356] <TB0> INFO: 41600 events read in total (2909ms).
[15:18:11.357] <TB0> INFO: Test took 3767ms.
[15:18:11.648] <TB0> INFO: Expecting 41600 events.
[15:18:15.166] <TB0> INFO: 41600 events read in total (2927ms).
[15:18:15.167] <TB0> INFO: Test took 3784ms.
[15:18:15.456] <TB0> INFO: Expecting 41600 events.
[15:18:19.004] <TB0> INFO: 41600 events read in total (2956ms).
[15:18:19.004] <TB0> INFO: Test took 3813ms.
[15:18:19.294] <TB0> INFO: Expecting 41600 events.
[15:18:22.815] <TB0> INFO: 41600 events read in total (2929ms).
[15:18:22.816] <TB0> INFO: Test took 3787ms.
[15:18:23.106] <TB0> INFO: Expecting 41600 events.
[15:18:26.683] <TB0> INFO: 41600 events read in total (2985ms).
[15:18:26.684] <TB0> INFO: Test took 3843ms.
[15:18:26.974] <TB0> INFO: Expecting 41600 events.
[15:18:30.536] <TB0> INFO: 41600 events read in total (2971ms).
[15:18:30.537] <TB0> INFO: Test took 3829ms.
[15:18:30.827] <TB0> INFO: Expecting 41600 events.
[15:18:34.399] <TB0> INFO: 41600 events read in total (2980ms).
[15:18:34.400] <TB0> INFO: Test took 3838ms.
[15:18:34.689] <TB0> INFO: Expecting 41600 events.
[15:18:38.213] <TB0> INFO: 41600 events read in total (2932ms).
[15:18:38.213] <TB0> INFO: Test took 3789ms.
[15:18:38.507] <TB0> INFO: Expecting 41600 events.
[15:18:42.015] <TB0> INFO: 41600 events read in total (2916ms).
[15:18:42.015] <TB0> INFO: Test took 3773ms.
[15:18:42.306] <TB0> INFO: Expecting 2560 events.
[15:18:43.190] <TB0> INFO: 2560 events read in total (293ms).
[15:18:43.190] <TB0> INFO: Test took 1162ms.
[15:18:43.498] <TB0> INFO: Expecting 2560 events.
[15:18:44.385] <TB0> INFO: 2560 events read in total (295ms).
[15:18:44.385] <TB0> INFO: Test took 1195ms.
[15:18:44.693] <TB0> INFO: Expecting 2560 events.
[15:18:45.584] <TB0> INFO: 2560 events read in total (299ms).
[15:18:45.584] <TB0> INFO: Test took 1199ms.
[15:18:45.892] <TB0> INFO: Expecting 2560 events.
[15:18:46.779] <TB0> INFO: 2560 events read in total (295ms).
[15:18:46.779] <TB0> INFO: Test took 1195ms.
[15:18:47.086] <TB0> INFO: Expecting 2560 events.
[15:18:47.972] <TB0> INFO: 2560 events read in total (294ms).
[15:18:47.973] <TB0> INFO: Test took 1193ms.
[15:18:48.281] <TB0> INFO: Expecting 2560 events.
[15:18:49.166] <TB0> INFO: 2560 events read in total (293ms).
[15:18:49.167] <TB0> INFO: Test took 1193ms.
[15:18:49.475] <TB0> INFO: Expecting 2560 events.
[15:18:50.359] <TB0> INFO: 2560 events read in total (292ms).
[15:18:50.359] <TB0> INFO: Test took 1192ms.
[15:18:50.668] <TB0> INFO: Expecting 2560 events.
[15:18:51.556] <TB0> INFO: 2560 events read in total (297ms).
[15:18:51.556] <TB0> INFO: Test took 1197ms.
[15:18:51.863] <TB0> INFO: Expecting 2560 events.
[15:18:52.751] <TB0> INFO: 2560 events read in total (296ms).
[15:18:52.751] <TB0> INFO: Test took 1194ms.
[15:18:53.058] <TB0> INFO: Expecting 2560 events.
[15:18:53.947] <TB0> INFO: 2560 events read in total (297ms).
[15:18:53.947] <TB0> INFO: Test took 1195ms.
[15:18:54.254] <TB0> INFO: Expecting 2560 events.
[15:18:55.142] <TB0> INFO: 2560 events read in total (296ms).
[15:18:55.142] <TB0> INFO: Test took 1194ms.
[15:18:55.449] <TB0> INFO: Expecting 2560 events.
[15:18:56.336] <TB0> INFO: 2560 events read in total (295ms).
[15:18:56.336] <TB0> INFO: Test took 1194ms.
[15:18:56.643] <TB0> INFO: Expecting 2560 events.
[15:18:57.532] <TB0> INFO: 2560 events read in total (297ms).
[15:18:57.532] <TB0> INFO: Test took 1196ms.
[15:18:57.840] <TB0> INFO: Expecting 2560 events.
[15:18:58.722] <TB0> INFO: 2560 events read in total (290ms).
[15:18:58.722] <TB0> INFO: Test took 1190ms.
[15:18:59.031] <TB0> INFO: Expecting 2560 events.
[15:18:59.915] <TB0> INFO: 2560 events read in total (293ms).
[15:18:59.915] <TB0> INFO: Test took 1192ms.
[15:19:00.223] <TB0> INFO: Expecting 2560 events.
[15:19:01.108] <TB0> INFO: 2560 events read in total (293ms).
[15:19:01.108] <TB0> INFO: Test took 1192ms.
[15:19:01.112] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:19:01.417] <TB0> INFO: Expecting 655360 events.
[15:19:16.157] <TB0> INFO: 655360 events read in total (14148ms).
[15:19:16.175] <TB0> INFO: Expecting 655360 events.
[15:19:30.657] <TB0> INFO: 655360 events read in total (14079ms).
[15:19:30.676] <TB0> INFO: Expecting 655360 events.
[15:19:45.159] <TB0> INFO: 655360 events read in total (14080ms).
[15:19:45.184] <TB0> INFO: Expecting 655360 events.
[15:19:59.677] <TB0> INFO: 655360 events read in total (14090ms).
[15:19:59.703] <TB0> INFO: Expecting 655360 events.
[15:20:14.302] <TB0> INFO: 655360 events read in total (14196ms).
[15:20:14.333] <TB0> INFO: Expecting 655360 events.
[15:20:28.843] <TB0> INFO: 655360 events read in total (14107ms).
[15:20:28.885] <TB0> INFO: Expecting 655360 events.
[15:20:43.589] <TB0> INFO: 655360 events read in total (14301ms).
[15:20:43.637] <TB0> INFO: Expecting 655360 events.
[15:20:58.210] <TB0> INFO: 655360 events read in total (14170ms).
[15:20:58.257] <TB0> INFO: Expecting 655360 events.
[15:21:12.968] <TB0> INFO: 655360 events read in total (14308ms).
[15:21:13.050] <TB0> INFO: Expecting 655360 events.
[15:21:27.586] <TB0> INFO: 655360 events read in total (14133ms).
[15:21:27.729] <TB0> INFO: Expecting 655360 events.
[15:21:42.270] <TB0> INFO: 655360 events read in total (14138ms).
[15:21:42.369] <TB0> INFO: Expecting 655360 events.
[15:21:56.914] <TB0> INFO: 655360 events read in total (14142ms).
[15:21:56.992] <TB0> INFO: Expecting 655360 events.
[15:22:11.509] <TB0> INFO: 655360 events read in total (14114ms).
[15:22:11.735] <TB0> INFO: Expecting 655360 events.
[15:22:26.336] <TB0> INFO: 655360 events read in total (14198ms).
[15:22:26.430] <TB0> INFO: Expecting 655360 events.
[15:22:41.007] <TB0> INFO: 655360 events read in total (14174ms).
[15:22:41.098] <TB0> INFO: Expecting 655360 events.
[15:22:55.622] <TB0> INFO: 655360 events read in total (14121ms).
[15:22:55.812] <TB0> INFO: Test took 234700ms.
[15:22:55.912] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:22:56.167] <TB0> INFO: Expecting 655360 events.
[15:23:10.945] <TB0> INFO: 655360 events read in total (14186ms).
[15:23:10.960] <TB0> INFO: Expecting 655360 events.
[15:23:25.502] <TB0> INFO: 655360 events read in total (14139ms).
[15:23:25.521] <TB0> INFO: Expecting 655360 events.
[15:23:40.176] <TB0> INFO: 655360 events read in total (14252ms).
[15:23:40.204] <TB0> INFO: Expecting 655360 events.
[15:23:54.658] <TB0> INFO: 655360 events read in total (14050ms).
[15:23:54.694] <TB0> INFO: Expecting 655360 events.
[15:24:09.251] <TB0> INFO: 655360 events read in total (14154ms).
[15:24:09.287] <TB0> INFO: Expecting 655360 events.
[15:24:23.497] <TB0> INFO: 655360 events read in total (13807ms).
[15:24:23.531] <TB0> INFO: Expecting 655360 events.
[15:24:37.961] <TB0> INFO: 655360 events read in total (14027ms).
[15:24:37.003] <TB0> INFO: Expecting 655360 events.
[15:24:52.487] <TB0> INFO: 655360 events read in total (14081ms).
[15:24:52.531] <TB0> INFO: Expecting 655360 events.
[15:25:07.058] <TB0> INFO: 655360 events read in total (14124ms).
[15:25:07.171] <TB0> INFO: Expecting 655360 events.
[15:25:21.834] <TB0> INFO: 655360 events read in total (14260ms).
[15:25:21.899] <TB0> INFO: Expecting 655360 events.
[15:25:36.538] <TB0> INFO: 655360 events read in total (14236ms).
[15:25:36.681] <TB0> INFO: Expecting 655360 events.
[15:25:51.448] <TB0> INFO: 655360 events read in total (14364ms).
[15:25:51.529] <TB0> INFO: Expecting 655360 events.
[15:26:06.571] <TB0> INFO: 655360 events read in total (14639ms).
[15:26:06.652] <TB0> INFO: Expecting 655360 events.
[15:26:21.582] <TB0> INFO: 655360 events read in total (14527ms).
[15:26:21.668] <TB0> INFO: Expecting 655360 events.
[15:26:36.593] <TB0> INFO: 655360 events read in total (14521ms).
[15:26:36.686] <TB0> INFO: Expecting 655360 events.
[15:26:51.724] <TB0> INFO: 655360 events read in total (14635ms).
[15:26:51.825] <TB0> INFO: Test took 235913ms.
[15:26:51.003] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.009] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[15:26:52.015] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[15:26:52.020] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[15:26:52.026] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[15:26:52.032] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[15:26:52.038] <TB0> INFO: safety margin for low PH: adding 6, margin is now 26
[15:26:52.043] <TB0> INFO: safety margin for low PH: adding 7, margin is now 27
[15:26:52.049] <TB0> INFO: safety margin for low PH: adding 8, margin is now 28
[15:26:52.055] <TB0> INFO: safety margin for low PH: adding 9, margin is now 29
[15:26:52.061] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.066] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[15:26:52.072] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.078] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.083] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.089] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[15:26:52.095] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[15:26:52.106] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[15:26:52.117] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[15:26:52.127] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[15:26:52.138] <TB0> INFO: safety margin for low PH: adding 6, margin is now 26
[15:26:52.148] <TB0> INFO: safety margin for low PH: adding 7, margin is now 27
[15:26:52.159] <TB0> INFO: safety margin for low PH: adding 8, margin is now 28
[15:26:52.169] <TB0> INFO: safety margin for low PH: adding 9, margin is now 29
[15:26:52.180] <TB0> INFO: safety margin for low PH: adding 10, margin is now 30
[15:26:52.190] <TB0> INFO: safety margin for low PH: adding 11, margin is now 31
[15:26:52.201] <TB0> INFO: safety margin for low PH: adding 12, margin is now 32
[15:26:52.212] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.222] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[15:26:52.232] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[15:26:52.242] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[15:26:52.252] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[15:26:52.262] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[15:26:52.271] <TB0> INFO: safety margin for low PH: adding 6, margin is now 26
[15:26:52.282] <TB0> INFO: safety margin for low PH: adding 7, margin is now 27
[15:26:52.291] <TB0> INFO: safety margin for low PH: adding 8, margin is now 28
[15:26:52.301] <TB0> INFO: safety margin for low PH: adding 9, margin is now 29
[15:26:52.311] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.321] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.331] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.341] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.351] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.361] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[15:26:52.370] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[15:26:52.380] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[15:26:52.390] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.400] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[15:26:52.410] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.420] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.430] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.439] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[15:26:52.479] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C0.dat
[15:26:52.479] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C1.dat
[15:26:52.480] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C2.dat
[15:26:52.480] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C3.dat
[15:26:52.480] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C4.dat
[15:26:52.480] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C5.dat
[15:26:52.480] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C6.dat
[15:26:52.481] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C7.dat
[15:26:52.481] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C8.dat
[15:26:52.481] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C9.dat
[15:26:52.481] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C10.dat
[15:26:52.481] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C11.dat
[15:26:52.481] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C12.dat
[15:26:52.482] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C13.dat
[15:26:52.482] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C14.dat
[15:26:52.482] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//dacParameters35_C15.dat
[15:26:52.725] <TB0> INFO: Expecting 41600 events.
[15:26:55.859] <TB0> INFO: 41600 events read in total (2542ms).
[15:26:55.859] <TB0> INFO: Test took 3374ms.
[15:26:56.316] <TB0> INFO: Expecting 41600 events.
[15:26:59.391] <TB0> INFO: 41600 events read in total (2483ms).
[15:26:59.392] <TB0> INFO: Test took 3318ms.
[15:26:59.843] <TB0> INFO: Expecting 41600 events.
[15:27:03.047] <TB0> INFO: 41600 events read in total (2612ms).
[15:27:03.047] <TB0> INFO: Test took 3442ms.
[15:27:03.263] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:03.352] <TB0> INFO: Expecting 2560 events.
[15:27:04.244] <TB0> INFO: 2560 events read in total (300ms).
[15:27:04.244] <TB0> INFO: Test took 981ms.
[15:27:04.246] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:04.553] <TB0> INFO: Expecting 2560 events.
[15:27:05.438] <TB0> INFO: 2560 events read in total (294ms).
[15:27:05.438] <TB0> INFO: Test took 1192ms.
[15:27:05.441] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:05.746] <TB0> INFO: Expecting 2560 events.
[15:27:06.643] <TB0> INFO: 2560 events read in total (305ms).
[15:27:06.643] <TB0> INFO: Test took 1202ms.
[15:27:06.646] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:06.952] <TB0> INFO: Expecting 2560 events.
[15:27:07.842] <TB0> INFO: 2560 events read in total (298ms).
[15:27:07.842] <TB0> INFO: Test took 1196ms.
[15:27:07.844] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:08.149] <TB0> INFO: Expecting 2560 events.
[15:27:09.038] <TB0> INFO: 2560 events read in total (297ms).
[15:27:09.038] <TB0> INFO: Test took 1194ms.
[15:27:09.041] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:09.346] <TB0> INFO: Expecting 2560 events.
[15:27:10.240] <TB0> INFO: 2560 events read in total (302ms).
[15:27:10.240] <TB0> INFO: Test took 1199ms.
[15:27:10.243] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:10.549] <TB0> INFO: Expecting 2560 events.
[15:27:11.443] <TB0> INFO: 2560 events read in total (302ms).
[15:27:11.443] <TB0> INFO: Test took 1200ms.
[15:27:11.445] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:11.751] <TB0> INFO: Expecting 2560 events.
[15:27:12.637] <TB0> INFO: 2560 events read in total (294ms).
[15:27:12.637] <TB0> INFO: Test took 1192ms.
[15:27:12.640] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:12.945] <TB0> INFO: Expecting 2560 events.
[15:27:13.833] <TB0> INFO: 2560 events read in total (296ms).
[15:27:13.833] <TB0> INFO: Test took 1193ms.
[15:27:13.835] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:14.142] <TB0> INFO: Expecting 2560 events.
[15:27:15.033] <TB0> INFO: 2560 events read in total (299ms).
[15:27:15.033] <TB0> INFO: Test took 1198ms.
[15:27:15.037] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:15.341] <TB0> INFO: Expecting 2560 events.
[15:27:16.229] <TB0> INFO: 2560 events read in total (296ms).
[15:27:16.230] <TB0> INFO: Test took 1193ms.
[15:27:16.232] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:16.537] <TB0> INFO: Expecting 2560 events.
[15:27:17.422] <TB0> INFO: 2560 events read in total (293ms).
[15:27:17.423] <TB0> INFO: Test took 1191ms.
[15:27:17.426] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:17.731] <TB0> INFO: Expecting 2560 events.
[15:27:18.618] <TB0> INFO: 2560 events read in total (295ms).
[15:27:18.619] <TB0> INFO: Test took 1193ms.
[15:27:18.621] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:18.927] <TB0> INFO: Expecting 2560 events.
[15:27:19.816] <TB0> INFO: 2560 events read in total (297ms).
[15:27:19.817] <TB0> INFO: Test took 1196ms.
[15:27:19.820] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:20.124] <TB0> INFO: Expecting 2560 events.
[15:27:21.003] <TB0> INFO: 2560 events read in total (287ms).
[15:27:21.005] <TB0> INFO: Test took 1185ms.
[15:27:21.008] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:21.313] <TB0> INFO: Expecting 2560 events.
[15:27:22.202] <TB0> INFO: 2560 events read in total (297ms).
[15:27:22.202] <TB0> INFO: Test took 1194ms.
[15:27:22.206] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:22.510] <TB0> INFO: Expecting 2560 events.
[15:27:23.403] <TB0> INFO: 2560 events read in total (301ms).
[15:27:23.403] <TB0> INFO: Test took 1197ms.
[15:27:23.406] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:23.712] <TB0> INFO: Expecting 2560 events.
[15:27:24.596] <TB0> INFO: 2560 events read in total (292ms).
[15:27:24.596] <TB0> INFO: Test took 1191ms.
[15:27:24.601] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:24.904] <TB0> INFO: Expecting 2560 events.
[15:27:25.791] <TB0> INFO: 2560 events read in total (295ms).
[15:27:25.791] <TB0> INFO: Test took 1190ms.
[15:27:25.793] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:26.101] <TB0> INFO: Expecting 2560 events.
[15:27:26.982] <TB0> INFO: 2560 events read in total (289ms).
[15:27:26.982] <TB0> INFO: Test took 1189ms.
[15:27:26.985] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:27.291] <TB0> INFO: Expecting 2560 events.
[15:27:28.183] <TB0> INFO: 2560 events read in total (300ms).
[15:27:28.184] <TB0> INFO: Test took 1199ms.
[15:27:28.187] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:28.493] <TB0> INFO: Expecting 2560 events.
[15:27:29.384] <TB0> INFO: 2560 events read in total (299ms).
[15:27:29.384] <TB0> INFO: Test took 1197ms.
[15:27:29.388] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:29.691] <TB0> INFO: Expecting 2560 events.
[15:27:30.580] <TB0> INFO: 2560 events read in total (297ms).
[15:27:30.580] <TB0> INFO: Test took 1192ms.
[15:27:30.583] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:30.888] <TB0> INFO: Expecting 2560 events.
[15:27:31.781] <TB0> INFO: 2560 events read in total (301ms).
[15:27:31.781] <TB0> INFO: Test took 1198ms.
[15:27:31.784] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:32.089] <TB0> INFO: Expecting 2560 events.
[15:27:32.980] <TB0> INFO: 2560 events read in total (299ms).
[15:27:32.981] <TB0> INFO: Test took 1197ms.
[15:27:32.983] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:33.290] <TB0> INFO: Expecting 2560 events.
[15:27:34.175] <TB0> INFO: 2560 events read in total (294ms).
[15:27:34.176] <TB0> INFO: Test took 1193ms.
[15:27:34.179] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:34.484] <TB0> INFO: Expecting 2560 events.
[15:27:35.378] <TB0> INFO: 2560 events read in total (302ms).
[15:27:35.378] <TB0> INFO: Test took 1200ms.
[15:27:35.381] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:35.687] <TB0> INFO: Expecting 2560 events.
[15:27:36.581] <TB0> INFO: 2560 events read in total (302ms).
[15:27:36.582] <TB0> INFO: Test took 1201ms.
[15:27:36.584] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:36.890] <TB0> INFO: Expecting 2560 events.
[15:27:37.781] <TB0> INFO: 2560 events read in total (299ms).
[15:27:37.781] <TB0> INFO: Test took 1197ms.
[15:27:37.784] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:38.090] <TB0> INFO: Expecting 2560 events.
[15:27:38.976] <TB0> INFO: 2560 events read in total (295ms).
[15:27:38.977] <TB0> INFO: Test took 1193ms.
[15:27:38.980] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:39.285] <TB0> INFO: Expecting 2560 events.
[15:27:40.179] <TB0> INFO: 2560 events read in total (302ms).
[15:27:40.179] <TB0> INFO: Test took 1199ms.
[15:27:40.184] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:27:40.488] <TB0> INFO: Expecting 2560 events.
[15:27:41.382] <TB0> INFO: 2560 events read in total (302ms).
[15:27:41.383] <TB0> INFO: Test took 1199ms.
[15:27:41.858] <TB0> INFO: PixTestPhOptimization::doTest() done, duration: 651 seconds
[15:27:41.858] <TB0> INFO: PH scale (per ROC): 42 50 51 48 41 33 37 39 40 54 35 50 33 30 49 43
[15:27:41.858] <TB0> INFO: PH offset (per ROC): 112 109 124 108 112 91 103 109 99 123 110 125 106 102 108 107
[15:27:41.868] <TB0> INFO: Decoding statistics:
[15:27:41.868] <TB0> INFO: General information:
[15:27:41.868] <TB0> INFO: 16bit words read: 127872
[15:27:41.868] <TB0> INFO: valid events total: 20480
[15:27:41.868] <TB0> INFO: empty events: 17984
[15:27:41.868] <TB0> INFO: valid events with pixels: 2496
[15:27:41.868] <TB0> INFO: valid pixel hits: 2496
[15:27:41.868] <TB0> INFO: Event errors: 0
[15:27:41.868] <TB0> INFO: start marker: 0
[15:27:41.868] <TB0> INFO: stop marker: 0
[15:27:41.868] <TB0> INFO: overflow: 0
[15:27:41.868] <TB0> INFO: invalid 5bit words: 0
[15:27:41.868] <TB0> INFO: invalid XOR eye diagram: 0
[15:27:41.868] <TB0> INFO: frame (failed synchr.): 0
[15:27:41.868] <TB0> INFO: idle data (no TBM trl): 0
[15:27:41.868] <TB0> INFO: no data (only TBM hdr): 0
[15:27:41.868] <TB0> INFO: TBM errors: 0
[15:27:41.868] <TB0> INFO: flawed TBM headers: 0
[15:27:41.868] <TB0> INFO: flawed TBM trailers: 0
[15:27:41.868] <TB0> INFO: event ID mismatches: 0
[15:27:41.868] <TB0> INFO: ROC errors: 0
[15:27:41.868] <TB0> INFO: missing ROC header(s): 0
[15:27:41.868] <TB0> INFO: misplaced readback start: 0
[15:27:41.868] <TB0> INFO: Pixel decoding errors: 0
[15:27:41.868] <TB0> INFO: pixel data incomplete: 0
[15:27:41.868] <TB0> INFO: pixel address: 0
[15:27:41.868] <TB0> INFO: pulse height fill bit: 0
[15:27:41.868] <TB0> INFO: buffer corruption: 0
[15:27:42.032] <TB0> INFO: ######################################################################
[15:27:42.032] <TB0> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[15:27:42.032] <TB0> INFO: ######################################################################
[15:27:42.047] <TB0> INFO: scanning low vcal = 10
[15:27:42.283] <TB0> INFO: Expecting 41600 events.
[15:27:45.839] <TB0> INFO: 41600 events read in total (2965ms).
[15:27:45.839] <TB0> INFO: Test took 3792ms.
[15:27:45.841] <TB0> INFO: scanning low vcal = 20
[15:27:46.138] <TB0> INFO: Expecting 41600 events.
[15:27:49.699] <TB0> INFO: 41600 events read in total (2970ms).
[15:27:49.699] <TB0> INFO: Test took 3858ms.
[15:27:49.701] <TB0> INFO: scanning low vcal = 30
[15:27:50.025] <TB0> INFO: Expecting 41600 events.
[15:27:53.652] <TB0> INFO: 41600 events read in total (3035ms).
[15:27:53.653] <TB0> INFO: Test took 3952ms.
[15:27:53.656] <TB0> INFO: scanning low vcal = 40
[15:27:53.936] <TB0> INFO: Expecting 41600 events.
[15:27:57.839] <TB0> INFO: 41600 events read in total (3311ms).
[15:27:57.840] <TB0> INFO: Test took 4184ms.
[15:27:57.843] <TB0> INFO: scanning low vcal = 50
[15:27:58.122] <TB0> INFO: Expecting 41600 events.
[15:28:02.064] <TB0> INFO: 41600 events read in total (3351ms).
[15:28:02.065] <TB0> INFO: Test took 4222ms.
[15:28:02.068] <TB0> INFO: scanning low vcal = 60
[15:28:02.345] <TB0> INFO: Expecting 41600 events.
[15:28:06.310] <TB0> INFO: 41600 events read in total (3374ms).
[15:28:06.311] <TB0> INFO: Test took 4243ms.
[15:28:06.314] <TB0> INFO: scanning low vcal = 70
[15:28:06.590] <TB0> INFO: Expecting 41600 events.
[15:28:10.532] <TB0> INFO: 41600 events read in total (3350ms).
[15:28:10.533] <TB0> INFO: Test took 4219ms.
[15:28:10.537] <TB0> INFO: scanning low vcal = 80
[15:28:10.813] <TB0> INFO: Expecting 41600 events.
[15:28:14.750] <TB0> INFO: 41600 events read in total (3346ms).
[15:28:14.751] <TB0> INFO: Test took 4214ms.
[15:28:14.754] <TB0> INFO: scanning low vcal = 90
[15:28:15.030] <TB0> INFO: Expecting 41600 events.
[15:28:19.041] <TB0> INFO: 41600 events read in total (3419ms).
[15:28:19.042] <TB0> INFO: Test took 4288ms.
[15:28:19.045] <TB0> INFO: scanning low vcal = 100
[15:28:19.321] <TB0> INFO: Expecting 41600 events.
[15:28:23.322] <TB0> INFO: 41600 events read in total (3409ms).
[15:28:23.322] <TB0> INFO: Test took 4277ms.
[15:28:23.325] <TB0> INFO: scanning low vcal = 110
[15:28:23.602] <TB0> INFO: Expecting 41600 events.
[15:28:27.603] <TB0> INFO: 41600 events read in total (3409ms).
[15:28:27.604] <TB0> INFO: Test took 4278ms.
[15:28:27.606] <TB0> INFO: scanning low vcal = 120
[15:28:27.883] <TB0> INFO: Expecting 41600 events.
[15:28:31.912] <TB0> INFO: 41600 events read in total (3437ms).
[15:28:31.913] <TB0> INFO: Test took 4306ms.
[15:28:31.916] <TB0> INFO: scanning low vcal = 130
[15:28:32.193] <TB0> INFO: Expecting 41600 events.
[15:28:36.161] <TB0> INFO: 41600 events read in total (3376ms).
[15:28:36.162] <TB0> INFO: Test took 4245ms.
[15:28:36.165] <TB0> INFO: scanning low vcal = 140
[15:28:36.441] <TB0> INFO: Expecting 41600 events.
[15:28:40.428] <TB0> INFO: 41600 events read in total (3395ms).
[15:28:40.429] <TB0> INFO: Test took 4264ms.
[15:28:40.432] <TB0> INFO: scanning low vcal = 150
[15:28:40.708] <TB0> INFO: Expecting 41600 events.
[15:28:44.702] <TB0> INFO: 41600 events read in total (3402ms).
[15:28:44.703] <TB0> INFO: Test took 4271ms.
[15:28:44.705] <TB0> INFO: scanning low vcal = 160
[15:28:44.982] <TB0> INFO: Expecting 41600 events.
[15:28:49.053] <TB0> INFO: 41600 events read in total (3480ms).
[15:28:49.054] <TB0> INFO: Test took 4348ms.
[15:28:49.058] <TB0> INFO: scanning low vcal = 170
[15:28:49.334] <TB0> INFO: Expecting 41600 events.
[15:28:53.340] <TB0> INFO: 41600 events read in total (3414ms).
[15:28:53.341] <TB0> INFO: Test took 4283ms.
[15:28:53.347] <TB0> INFO: scanning low vcal = 180
[15:28:53.620] <TB0> INFO: Expecting 41600 events.
[15:28:57.690] <TB0> INFO: 41600 events read in total (3478ms).
[15:28:57.691] <TB0> INFO: Test took 4343ms.
[15:28:57.695] <TB0> INFO: scanning low vcal = 190
[15:28:57.986] <TB0> INFO: Expecting 41600 events.
[15:29:02.042] <TB0> INFO: 41600 events read in total (3465ms).
[15:29:02.043] <TB0> INFO: Test took 4348ms.
[15:29:02.046] <TB0> INFO: scanning low vcal = 200
[15:29:02.372] <TB0> INFO: Expecting 41600 events.
[15:29:06.363] <TB0> INFO: 41600 events read in total (3400ms).
[15:29:06.364] <TB0> INFO: Test took 4318ms.
[15:29:06.368] <TB0> INFO: scanning low vcal = 210
[15:29:06.683] <TB0> INFO: Expecting 41600 events.
[15:29:10.806] <TB0> INFO: 41600 events read in total (3532ms).
[15:29:10.807] <TB0> INFO: Test took 4439ms.
[15:29:10.811] <TB0> INFO: scanning low vcal = 220
[15:29:11.087] <TB0> INFO: Expecting 41600 events.
[15:29:15.095] <TB0> INFO: 41600 events read in total (3416ms).
[15:29:15.096] <TB0> INFO: Test took 4285ms.
[15:29:15.099] <TB0> INFO: scanning low vcal = 230
[15:29:15.376] <TB0> INFO: Expecting 41600 events.
[15:29:19.414] <TB0> INFO: 41600 events read in total (3447ms).
[15:29:19.415] <TB0> INFO: Test took 4315ms.
[15:29:19.418] <TB0> INFO: scanning low vcal = 240
[15:29:19.694] <TB0> INFO: Expecting 41600 events.
[15:29:23.650] <TB0> INFO: 41600 events read in total (3364ms).
[15:29:23.651] <TB0> INFO: Test took 4233ms.
[15:29:23.654] <TB0> INFO: scanning low vcal = 250
[15:29:23.931] <TB0> INFO: Expecting 41600 events.
[15:29:27.887] <TB0> INFO: 41600 events read in total (3364ms).
[15:29:27.888] <TB0> INFO: Test took 4234ms.
[15:29:27.892] <TB0> INFO: scanning high vcal = 30 (= 210 in low range)
[15:29:28.168] <TB0> INFO: Expecting 41600 events.
[15:29:32.141] <TB0> INFO: 41600 events read in total (3381ms).
[15:29:32.142] <TB0> INFO: Test took 4250ms.
[15:29:32.145] <TB0> INFO: scanning high vcal = 50 (= 350 in low range)
[15:29:32.422] <TB0> INFO: Expecting 41600 events.
[15:29:36.378] <TB0> INFO: 41600 events read in total (3365ms).
[15:29:36.379] <TB0> INFO: Test took 4234ms.
[15:29:36.382] <TB0> INFO: scanning high vcal = 70 (= 490 in low range)
[15:29:36.659] <TB0> INFO: Expecting 41600 events.
[15:29:40.616] <TB0> INFO: 41600 events read in total (3365ms).
[15:29:40.616] <TB0> INFO: Test took 4234ms.
[15:29:40.620] <TB0> INFO: scanning high vcal = 90 (= 630 in low range)
[15:29:40.896] <TB0> INFO: Expecting 41600 events.
[15:29:44.850] <TB0> INFO: 41600 events read in total (3362ms).
[15:29:44.851] <TB0> INFO: Test took 4231ms.
[15:29:44.854] <TB0> INFO: scanning high vcal = 200 (= 1400 in low range)
[15:29:45.131] <TB0> INFO: Expecting 41600 events.
[15:29:49.076] <TB0> INFO: 41600 events read in total (3353ms).
[15:29:49.077] <TB0> INFO: Test took 4223ms.
[15:29:49.494] <TB0> INFO: PixTestGainPedestal::measure() done
[15:30:22.397] <TB0> INFO: PixTestGainPedestal::fit() done
[15:30:22.397] <TB0> INFO: non-linearity mean: 0.966 0.978 0.983 0.958 0.958 0.958 0.945 0.963 0.944 0.987 0.901 0.982 0.934 1.030 0.956 0.936
[15:30:22.397] <TB0> INFO: non-linearity RMS: 0.015 0.006 0.003 0.039 0.041 0.170 0.085 0.048 0.061 0.003 0.137 0.003 0.170 0.157 0.047 0.069
[15:30:22.397] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C0.dat
[15:30:22.411] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C1.dat
[15:30:22.424] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C2.dat
[15:30:22.437] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C3.dat
[15:30:22.451] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C4.dat
[15:30:22.465] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C5.dat
[15:30:22.478] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C6.dat
[15:30:22.491] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C7.dat
[15:30:22.505] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C8.dat
[15:30:22.518] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C9.dat
[15:30:22.532] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C10.dat
[15:30:22.545] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C11.dat
[15:30:22.558] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C12.dat
[15:30:22.572] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C13.dat
[15:30:22.585] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C14.dat
[15:30:22.599] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1052_FullQualification_2016-10-24_11h34m_1477301645//003_Fulltest_p17//phCalibrationFitErr35_C15.dat
[15:30:22.612] <TB0> INFO: PixTestGainPedestal::fullTest() done, duration: 160 seconds
[15:30:22.612] <TB0> INFO: Decoding statistics:
[15:30:22.612] <TB0> INFO: General information:
[15:30:22.612] <TB0> INFO: 16bit words read: 3257824
[15:30:22.612] <TB0> INFO: valid events total: 332800
[15:30:22.612] <TB0> INFO: empty events: 1130
[15:30:22.612] <TB0> INFO: valid events with pixels: 331670
[15:30:22.612] <TB0> INFO: valid pixel hits: 630512
[15:30:22.612] <TB0> INFO: Event errors: 0
[15:30:22.612] <TB0> INFO: start marker: 0
[15:30:22.612] <TB0> INFO: stop marker: 0
[15:30:22.612] <TB0> INFO: overflow: 0
[15:30:22.612] <TB0> INFO: invalid 5bit words: 0
[15:30:22.612] <TB0> INFO: invalid XOR eye diagram: 0
[15:30:22.612] <TB0> INFO: frame (failed synchr.): 0
[15:30:22.612] <TB0> INFO: idle data (no TBM trl): 0
[15:30:22.612] <TB0> INFO: no data (only TBM hdr): 0
[15:30:22.612] <TB0> INFO: TBM errors: 0
[15:30:22.612] <TB0> INFO: flawed TBM headers: 0
[15:30:22.612] <TB0> INFO: flawed TBM trailers: 0
[15:30:22.612] <TB0> INFO: event ID mismatches: 0
[15:30:22.612] <TB0> INFO: ROC errors: 0
[15:30:22.612] <TB0> INFO: missing ROC header(s): 0
[15:30:22.612] <TB0> INFO: misplaced readback start: 0
[15:30:22.612] <TB0> INFO: Pixel decoding errors: 0
[15:30:22.612] <TB0> INFO: pixel data incomplete: 0
[15:30:22.612] <TB0> INFO: pixel address: 0
[15:30:22.612] <TB0> INFO: pulse height fill bit: 0
[15:30:22.612] <TB0> INFO: buffer corruption: 0
[15:30:22.629] <TB0> INFO: Decoding statistics:
[15:30:22.629] <TB0> INFO: General information:
[15:30:22.629] <TB0> INFO: 16bit words read: 3387232
[15:30:22.629] <TB0> INFO: valid events total: 353536
[15:30:22.629] <TB0> INFO: empty events: 19370
[15:30:22.629] <TB0> INFO: valid events with pixels: 334166
[15:30:22.629] <TB0> INFO: valid pixel hits: 633008
[15:30:22.629] <TB0> INFO: Event errors: 0
[15:30:22.629] <TB0> INFO: start marker: 0
[15:30:22.629] <TB0> INFO: stop marker: 0
[15:30:22.629] <TB0> INFO: overflow: 0
[15:30:22.629] <TB0> INFO: invalid 5bit words: 0
[15:30:22.629] <TB0> INFO: invalid XOR eye diagram: 0
[15:30:22.629] <TB0> INFO: frame (failed synchr.): 0
[15:30:22.629] <TB0> INFO: idle data (no TBM trl): 0
[15:30:22.629] <TB0> INFO: no data (only TBM hdr): 0
[15:30:22.629] <TB0> INFO: TBM errors: 0
[15:30:22.629] <TB0> INFO: flawed TBM headers: 0
[15:30:22.630] <TB0> INFO: flawed TBM trailers: 0
[15:30:22.630] <TB0> INFO: event ID mismatches: 0
[15:30:22.630] <TB0> INFO: ROC errors: 0
[15:30:22.630] <TB0> INFO: missing ROC header(s): 0
[15:30:22.630] <TB0> INFO: misplaced readback start: 0
[15:30:22.630] <TB0> INFO: Pixel decoding errors: 0
[15:30:22.630] <TB0> INFO: pixel data incomplete: 0
[15:30:22.630] <TB0> INFO: pixel address: 0
[15:30:22.630] <TB0> INFO: pulse height fill bit: 0
[15:30:22.630] <TB0> INFO: buffer corruption: 0
[15:30:22.630] <TB0> INFO: enter test to run
[15:30:22.630] <TB0> INFO: test: exit no parameter change
[15:30:22.754] <TB0> QUIET: Connection to board 71 closed.
[15:30:22.755] <TB0> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud