Test Date: 2016-10-22 10:41
Analysis date: 2016-10-24 09:43
Logfile
LogfileView
[13:07:48.551] <TB0> INFO: *** Welcome to pxar ***
[13:07:48.551] <TB0> INFO: *** Today: 2016/10/22
[13:07:48.557] <TB0> INFO: *** Version: c8ba-dirty
[13:07:48.557] <TB0> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C15.dat
[13:07:48.557] <TB0> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//tbmParameters_C1b.dat
[13:07:48.557] <TB0> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//defaultMaskFile.dat
[13:07:48.557] <TB0> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters_C15.dat
[13:07:48.616] <TB0> INFO: clk: 4
[13:07:48.616] <TB0> INFO: ctr: 4
[13:07:48.616] <TB0> INFO: sda: 19
[13:07:48.616] <TB0> INFO: tin: 9
[13:07:48.616] <TB0> INFO: level: 15
[13:07:48.616] <TB0> INFO: triggerdelay: 0
[13:07:48.616] <TB0> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[13:07:48.616] <TB0> INFO: Log level: INFO
[13:07:48.625] <TB0> INFO: Found DTB DTB_WRQ4OZ
[13:07:48.635] <TB0> QUIET: Connection to board DTB_WRQ4OZ opened.
[13:07:48.637] <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:
------------------------------------------------------
[13:07:48.639] <TB0> INFO: RPC call hashes of host and DTB match: 486171790
[13:07:50.124] <TB0> INFO: DUT info:
[13:07:50.124] <TB0> INFO: The DUT currently contains the following objects:
[13:07:50.124] <TB0> INFO: 4 TBM Cores tbm10c (4 ON)
[13:07:50.124] <TB0> INFO: TBM Core alpha (0): 7 registers set
[13:07:50.124] <TB0> INFO: TBM Core beta (1): 7 registers set
[13:07:50.124] <TB0> INFO: TBM Core alpha (2): 7 registers set
[13:07:50.124] <TB0> INFO: TBM Core beta (3): 7 registers set
[13:07:50.124] <TB0> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[13:07:50.124] <TB0> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.124] <TB0> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:07:50.525] <TB0> INFO: enter 'restricted' command line mode
[13:07:50.525] <TB0> INFO: enter test to run
[13:07:50.525] <TB0> INFO: test: pretest no parameter change
[13:07:50.525] <TB0> INFO: running: pretest
[13:07:50.530] <TB0> INFO: ######################################################################
[13:07:50.530] <TB0> INFO: PixTestPretest::doTest()
[13:07:50.530] <TB0> INFO: ######################################################################
[13:07:50.531] <TB0> INFO: ----------------------------------------------------------------------
[13:07:50.531] <TB0> INFO: PixTestPretest::programROC()
[13:07:50.531] <TB0> INFO: ----------------------------------------------------------------------
[13:08:08.544] <TB0> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[13:08:08.544] <TB0> INFO: IA differences per ROC: 20.9 20.1 20.9 20.1 19.3 19.3 21.7 18.5 20.9 20.1 20.9 17.7 19.3 19.3 19.3 18.5
[13:08:08.612] <TB0> INFO: ----------------------------------------------------------------------
[13:08:08.612] <TB0> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[13:08:08.612] <TB0> INFO: ----------------------------------------------------------------------
[13:08:16.601] <TB0> INFO: PixTestPretest::setVana() done, Module Ia 381.9 mA = 23.8688 mA/ROC
[13:08:16.601] <TB0> INFO: i(loss) [mA/ROC]: 18.5 18.5 18.5 19.3 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5 18.5
[13:08:16.632] <TB0> INFO: ----------------------------------------------------------------------
[13:08:16.632] <TB0> INFO: PixTestPretest::findTiming()
[13:08:16.632] <TB0> INFO: ----------------------------------------------------------------------
[13:08:16.632] <TB0> INFO: PixTestCmd::init()
[13:08:17.191] <TB0> WARNING: Not unmasking DUT, not setting Calibrate bits!

[13:08:49.177] <TB0> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[13:08:49.177] <TB0> INFO: (success/tries = 100/100), width = 4
[13:08:50.685] <TB0> INFO: ----------------------------------------------------------------------
[13:08:50.686] <TB0> INFO: PixTestPretest::findWorkingPixel()
[13:08:50.686] <TB0> INFO: ----------------------------------------------------------------------
[13:08:50.779] <TB0> INFO: Expecting 231680 events.
[13:09:00.840] <TB0> INFO: 231680 events read in total (9469ms).
[13:09:00.847] <TB0> INFO: Test took 10158ms.
[13:09:01.096] <TB0> INFO: Found working pixel in all ROCs: col/row = 12/22
[13:09:01.131] <TB0> INFO: ----------------------------------------------------------------------
[13:09:01.131] <TB0> INFO: PixTestPretest::setVthrCompCalDel()
[13:09:01.131] <TB0> INFO: ----------------------------------------------------------------------
[13:09:01.226] <TB0> INFO: Expecting 231680 events.
[13:09:11.207] <TB0> INFO: 231680 events read in total (9390ms).
[13:09:11.218] <TB0> INFO: Test took 10082ms.
[13:09:11.485] <TB0> INFO: PixTestPretest::setVthrCompCalDel() done
[13:09:11.485] <TB0> INFO: CalDel: 82 86 107 86 101 101 83 85 88 86 93 90 73 97 86 96
[13:09:11.485] <TB0> INFO: VthrComp: 52 53 52 51 51 52 51 52 53 51 51 56 51 51 51 51
[13:09:11.489] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C0.dat
[13:09:11.489] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C1.dat
[13:09:11.489] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C2.dat
[13:09:11.490] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C3.dat
[13:09:11.490] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C4.dat
[13:09:11.490] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C5.dat
[13:09:11.490] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C6.dat
[13:09:11.491] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C7.dat
[13:09:11.491] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C8.dat
[13:09:11.491] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C9.dat
[13:09:11.491] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C10.dat
[13:09:11.491] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C11.dat
[13:09:11.491] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C12.dat
[13:09:11.491] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C13.dat
[13:09:11.491] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C14.dat
[13:09:11.492] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters_C15.dat
[13:09:11.492] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//tbmParameters_C0a.dat
[13:09:11.492] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//tbmParameters_C0b.dat
[13:09:11.492] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//tbmParameters_C1a.dat
[13:09:11.492] <TB0> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//tbmParameters_C1b.dat
[13:09:11.492] <TB0> INFO: PixTestPretest::doTest() done, duration: 80 seconds
[13:09:11.545] <TB0> INFO: enter test to run
[13:09:11.545] <TB0> INFO: test: FullTest no parameter change
[13:09:11.545] <TB0> INFO: running: fulltest
[13:09:11.545] <TB0> INFO: ######################################################################
[13:09:11.545] <TB0> INFO: PixTestFullTest::doTest()
[13:09:11.545] <TB0> INFO: ######################################################################
[13:09:11.546] <TB0> INFO: ######################################################################
[13:09:11.546] <TB0> INFO: PixTestAlive::doTest()
[13:09:11.546] <TB0> INFO: ######################################################################
[13:09:11.548] <TB0> INFO: ----------------------------------------------------------------------
[13:09:11.548] <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)
[13:09:11.548] <TB0> INFO: ----------------------------------------------------------------------
[13:09:11.789] <TB0> INFO: Expecting 41600 events.
[13:09:15.350] <TB0> INFO: 41600 events read in total (2970ms).
[13:09:15.351] <TB0> INFO: Test took 3802ms.
[13:09:15.585] <TB0> INFO: PixTestAlive::aliveTest() done
[13:09:15.585] <TB0> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:09:15.587] <TB0> INFO: ----------------------------------------------------------------------
[13:09:15.587] <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)
[13:09:15.587] <TB0> INFO: ----------------------------------------------------------------------
[13:09:15.829] <TB0> INFO: Expecting 41600 events.
[13:09:18.796] <TB0> INFO: 41600 events read in total (2375ms).
[13:09:18.796] <TB0> INFO: Test took 3207ms.
[13:09:18.796] <TB0> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[13:09:19.041] <TB0> INFO: PixTestAlive::maskTest() done
[13:09:19.042] <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
[13:09:19.043] <TB0> INFO: ----------------------------------------------------------------------
[13:09:19.043] <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)
[13:09:19.043] <TB0> INFO: ----------------------------------------------------------------------
[13:09:19.286] <TB0> INFO: Expecting 41600 events.
[13:09:22.831] <TB0> INFO: 41600 events read in total (2953ms).
[13:09:22.832] <TB0> INFO: Test took 3785ms.
[13:09:23.063] <TB0> INFO: PixTestAlive::addressDecodingTest() done
[13:09:23.063] <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
[13:09:23.064] <TB0> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[13:09:23.064] <TB0> INFO: Decoding statistics:
[13:09:23.064] <TB0> INFO: General information:
[13:09:23.064] <TB0> INFO: 16bit words read: 0
[13:09:23.064] <TB0> INFO: valid events total: 0
[13:09:23.064] <TB0> INFO: empty events: 0
[13:09:23.064] <TB0> INFO: valid events with pixels: 0
[13:09:23.064] <TB0> INFO: valid pixel hits: 0
[13:09:23.064] <TB0> INFO: Event errors: 0
[13:09:23.064] <TB0> INFO: start marker: 0
[13:09:23.064] <TB0> INFO: stop marker: 0
[13:09:23.064] <TB0> INFO: overflow: 0
[13:09:23.064] <TB0> INFO: invalid 5bit words: 0
[13:09:23.064] <TB0> INFO: invalid XOR eye diagram: 0
[13:09:23.064] <TB0> INFO: frame (failed synchr.): 0
[13:09:23.064] <TB0> INFO: idle data (no TBM trl): 0
[13:09:23.064] <TB0> INFO: no data (only TBM hdr): 0
[13:09:23.064] <TB0> INFO: TBM errors: 0
[13:09:23.064] <TB0> INFO: flawed TBM headers: 0
[13:09:23.064] <TB0> INFO: flawed TBM trailers: 0
[13:09:23.064] <TB0> INFO: event ID mismatches: 0
[13:09:23.064] <TB0> INFO: ROC errors: 0
[13:09:23.064] <TB0> INFO: missing ROC header(s): 0
[13:09:23.064] <TB0> INFO: misplaced readback start: 0
[13:09:23.064] <TB0> INFO: Pixel decoding errors: 0
[13:09:23.064] <TB0> INFO: pixel data incomplete: 0
[13:09:23.064] <TB0> INFO: pixel address: 0
[13:09:23.064] <TB0> INFO: pulse height fill bit: 0
[13:09:23.064] <TB0> INFO: buffer corruption: 0
[13:09:23.072] <TB0> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C15.dat
[13:09:23.072] <TB0> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr_C15.dat
[13:09:23.072] <TB0> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[13:09:23.072] <TB0> INFO: ######################################################################
[13:09:23.072] <TB0> INFO: PixTestReadback::doTest()
[13:09:23.072] <TB0> INFO: ######################################################################
[13:09:23.072] <TB0> INFO: ----------------------------------------------------------------------
[13:09:23.072] <TB0> INFO: PixTestReadback::CalibrateVd()
[13:09:23.072] <TB0> INFO: ----------------------------------------------------------------------
[13:09:33.037] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C0.dat
[13:09:33.037] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C1.dat
[13:09:33.037] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C2.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C3.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C4.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C5.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C6.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C7.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C8.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C9.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C10.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C11.dat
[13:09:33.038] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C12.dat
[13:09:33.039] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C13.dat
[13:09:33.039] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C14.dat
[13:09:33.039] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C15.dat
[13:09:33.069] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[13:09:33.069] <TB0> INFO: ----------------------------------------------------------------------
[13:09:33.069] <TB0> INFO: PixTestReadback::CalibrateVa()
[13:09:33.069] <TB0> INFO: ----------------------------------------------------------------------
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C0.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C1.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C2.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C3.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C4.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C5.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C6.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C7.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C8.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C9.dat
[13:09:42.984] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C10.dat
[13:09:42.985] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C11.dat
[13:09:42.985] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C12.dat
[13:09:42.985] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C13.dat
[13:09:42.985] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C14.dat
[13:09:42.985] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C15.dat
[13:09:43.012] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[13:09:43.012] <TB0> INFO: ----------------------------------------------------------------------
[13:09:43.012] <TB0> INFO: PixTestReadback::readbackVbg()
[13:09:43.012] <TB0> INFO: ----------------------------------------------------------------------
[13:09:50.677] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[13:09:50.677] <TB0> INFO: ----------------------------------------------------------------------
[13:09:50.678] <TB0> INFO: PixTestReadback::getCalibratedVbg()
[13:09:50.678] <TB0> INFO: ----------------------------------------------------------------------
[13:09:50.678] <TB0> INFO: Vbg will be calibrated using Vd calibration
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 160.5calibrated Vbg = 1.18975 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 155.9calibrated Vbg = 1.186 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 159.7calibrated Vbg = 1.18897 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 157.9calibrated Vbg = 1.18254 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 153.3calibrated Vbg = 1.18349 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 155.2calibrated Vbg = 1.18704 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 147.9calibrated Vbg = 1.19056 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 157.7calibrated Vbg = 1.19109 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 157.5calibrated Vbg = 1.18203 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 154.4calibrated Vbg = 1.1795 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 151calibrated Vbg = 1.17238 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 159.7calibrated Vbg = 1.16863 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 154.8calibrated Vbg = 1.17674 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 154.3calibrated Vbg = 1.18566 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 153.5calibrated Vbg = 1.18736 :::*/*/*/*/
[13:09:50.678] <TB0> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 163.4calibrated Vbg = 1.18368 :::*/*/*/*/
[13:09:50.681] <TB0> INFO: ----------------------------------------------------------------------
[13:09:50.681] <TB0> INFO: PixTestReadback::CalibrateIa()
[13:09:50.681] <TB0> INFO: ----------------------------------------------------------------------
[13:12:31.521] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C0.dat
[13:12:31.521] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C1.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C2.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C3.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C4.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C5.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C6.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C7.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C8.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C9.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C10.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C11.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C12.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C13.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C14.dat
[13:12:31.522] <TB0> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//readbackCal_C15.dat
[13:12:31.558] <TB0> INFO: PixTestPattern:: pg_setup set to default.
[13:12:31.560] <TB0> INFO: PixTestReadback::doTest() done
[13:12:31.561] <TB0> INFO: Decoding statistics:
[13:12:31.561] <TB0> INFO: General information:
[13:12:31.561] <TB0> INFO: 16bit words read: 1536
[13:12:31.561] <TB0> INFO: valid events total: 256
[13:12:31.561] <TB0> INFO: empty events: 256
[13:12:31.561] <TB0> INFO: valid events with pixels: 0
[13:12:31.561] <TB0> INFO: valid pixel hits: 0
[13:12:31.561] <TB0> INFO: Event errors: 0
[13:12:31.561] <TB0> INFO: start marker: 0
[13:12:31.561] <TB0> INFO: stop marker: 0
[13:12:31.561] <TB0> INFO: overflow: 0
[13:12:31.561] <TB0> INFO: invalid 5bit words: 0
[13:12:31.561] <TB0> INFO: invalid XOR eye diagram: 0
[13:12:31.561] <TB0> INFO: frame (failed synchr.): 0
[13:12:31.561] <TB0> INFO: idle data (no TBM trl): 0
[13:12:31.561] <TB0> INFO: no data (only TBM hdr): 0
[13:12:31.561] <TB0> INFO: TBM errors: 0
[13:12:31.561] <TB0> INFO: flawed TBM headers: 0
[13:12:31.561] <TB0> INFO: flawed TBM trailers: 0
[13:12:31.561] <TB0> INFO: event ID mismatches: 0
[13:12:31.561] <TB0> INFO: ROC errors: 0
[13:12:31.561] <TB0> INFO: missing ROC header(s): 0
[13:12:31.561] <TB0> INFO: misplaced readback start: 0
[13:12:31.561] <TB0> INFO: Pixel decoding errors: 0
[13:12:31.561] <TB0> INFO: pixel data incomplete: 0
[13:12:31.561] <TB0> INFO: pixel address: 0
[13:12:31.561] <TB0> INFO: pulse height fill bit: 0
[13:12:31.561] <TB0> INFO: buffer corruption: 0
[13:12:31.610] <TB0> INFO: ######################################################################
[13:12:31.610] <TB0> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[13:12:31.610] <TB0> INFO: ######################################################################
[13:12:31.613] <TB0> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[13:12:31.626] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[13:12:31.626] <TB0> INFO: run 1 of 1
[13:12:31.868] <TB0> INFO: Expecting 3120000 events.
[13:13:03.772] <TB0> INFO: 666145 events read in total (31312ms).
[13:13:15.967] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (162) != TBM ID (129)

[13:13:16.105] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 162 162 129 162 162 162 162 162

[13:13:16.105] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (163)

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

[13:13:16.106] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a6 8000 4600 4600 e022 c000

[13:13:16.106] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a0 80b1 4200 4600 e022 c000

[13:13:16.106] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a1 80c0 4601 4601 e022 c000

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

[13:13:16.106] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a3 8040 4600 4601 e022 c000

[13:13:16.106] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a4 80b1 4600 4600 e022 c000

[13:13:16.106] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a5 80c0 4600 4600 e022 c000

[13:13:33.882] <TB0> INFO: 1330230 events read in total (61422ms).
[13:13:46.041] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (183) != TBM ID (129)

[13:13:46.177] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 183 183 129 183 183 183 183 183

[13:13:46.177] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (184)

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

[13:13:46.177] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bb 8040 4301 4c2 2bef 4301 4c2 2bef e022 c000

[13:13:46.177] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b5 80c0 4600 4c2 2bef 4600 4c2 2bef e022 c000

[13:13:46.177] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b6 8000 4600 4c2 2bef 4600 4c2 2bef e022 c000

[13:13:46.177] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4301 4301 2bef 4600 4c2 2bef e022 c000

[13:13:46.177] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b8 80b1 4600 4c2 2bef 4600 4c2 2bef e022 c000

[13:13:46.177] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b9 80c0 4201 4c2 2bef 4601 4c2 2bef e022 c000

[13:13:46.177] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ba 8000 4600 4c2 2bef 4600 4c2 2bef e022 c000

[13:14:04.326] <TB0> INFO: 1992005 events read in total (91866ms).
[13:14:16.469] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (198) != TBM ID (129)

[13:14:16.609] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 198 198 129 198 198 198 198 198

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

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

[13:14:16.610] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ca 8000 4300 4700 e022 c000

[13:14:16.610] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c4 80b1 4200 4200 e022 c000

[13:14:16.610] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c5 80c0 4200 4600 e022 c000

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

[13:14:16.610] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c7 8040 4300 4300 e022 c000

[13:14:16.610] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c8 80b1 4601 4601 e022 c000

[13:14:16.610] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c9 80c0 4200 4200 e022 c000

[13:14:34.515] <TB0> INFO: 2652345 events read in total (122055ms).
[13:14:43.191] <TB0> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (58) != TBM ID (129)

[13:14:43.327] <TB0> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 58 58 129 58 58 58 58 58

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

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

[13:14:43.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03e 8000 4601 4601 e022 c000

[13:14:43.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a038 80b1 4600 4600 e022 c000

[13:14:43.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a039 80c0 4301 4301 e022 c000

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

[13:14:43.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03b 8040 4300 4300 e022 c000

[13:14:43.327] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03c 80b1 4300 4300 e022 c000

[13:14:43.328] <TB0> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03d 80c0 4200 4700 e022 c000

[13:14:55.883] <TB0> INFO: 3120000 events read in total (143423ms).
[13:14:55.963] <TB0> INFO: Test took 144337ms.
[13:15:20.893] <TB0> INFO: PixTestBBMap::doTest() done with 1 decoding errors: , duration: 169 seconds
[13:15:20.893] <TB0> INFO: number of dead bumps (per ROC): 0 0 0 0 2 1 0 0 0 0 0 2 0 1 0 0
[13:15:20.893] <TB0> INFO: separation cut (per ROC): 110 117 101 101 105 109 102 103 112 110 108 119 93 97 106 103
[13:15:20.893] <TB0> INFO: Decoding statistics:
[13:15:20.893] <TB0> INFO: General information:
[13:15:20.893] <TB0> INFO: 16bit words read: 0
[13:15:20.893] <TB0> INFO: valid events total: 0
[13:15:20.893] <TB0> INFO: empty events: 0
[13:15:20.893] <TB0> INFO: valid events with pixels: 0
[13:15:20.893] <TB0> INFO: valid pixel hits: 0
[13:15:20.893] <TB0> INFO: Event errors: 0
[13:15:20.893] <TB0> INFO: start marker: 0
[13:15:20.893] <TB0> INFO: stop marker: 0
[13:15:20.893] <TB0> INFO: overflow: 0
[13:15:20.893] <TB0> INFO: invalid 5bit words: 0
[13:15:20.893] <TB0> INFO: invalid XOR eye diagram: 0
[13:15:20.893] <TB0> INFO: frame (failed synchr.): 0
[13:15:20.893] <TB0> INFO: idle data (no TBM trl): 0
[13:15:20.893] <TB0> INFO: no data (only TBM hdr): 0
[13:15:20.893] <TB0> INFO: TBM errors: 0
[13:15:20.893] <TB0> INFO: flawed TBM headers: 0
[13:15:20.893] <TB0> INFO: flawed TBM trailers: 0
[13:15:20.893] <TB0> INFO: event ID mismatches: 0
[13:15:20.893] <TB0> INFO: ROC errors: 0
[13:15:20.893] <TB0> INFO: missing ROC header(s): 0
[13:15:20.893] <TB0> INFO: misplaced readback start: 0
[13:15:20.893] <TB0> INFO: Pixel decoding errors: 0
[13:15:20.893] <TB0> INFO: pixel data incomplete: 0
[13:15:20.893] <TB0> INFO: pixel address: 0
[13:15:20.893] <TB0> INFO: pulse height fill bit: 0
[13:15:20.893] <TB0> INFO: buffer corruption: 0
[13:15:20.931] <TB0> INFO: ######################################################################
[13:15:20.931] <TB0> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[13:15:20.931] <TB0> INFO: ######################################################################
[13:15:20.931] <TB0> INFO: ----------------------------------------------------------------------
[13:15:20.931] <TB0> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[13:15:20.931] <TB0> INFO: ----------------------------------------------------------------------
[13:15:20.931] <TB0> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[13:15:20.945] <TB0> INFO: dacScan split into 1 runs with ntrig = 50
[13:15:20.945] <TB0> INFO: run 1 of 1
[13:15:21.193] <TB0> INFO: Expecting 36608000 events.
[13:15:45.503] <TB0> INFO: 694950 events read in total (23718ms).
[13:16:08.787] <TB0> INFO: 1374500 events read in total (47002ms).
[13:16:31.457] <TB0> INFO: 2051850 events read in total (69672ms).
[13:16:54.447] <TB0> INFO: 2731800 events read in total (92662ms).
[13:17:17.333] <TB0> INFO: 3410000 events read in total (115548ms).
[13:17:40.273] <TB0> INFO: 4086500 events read in total (138488ms).
[13:18:03.053] <TB0> INFO: 4759400 events read in total (161268ms).
[13:18:25.956] <TB0> INFO: 5434800 events read in total (184171ms).
[13:18:49.139] <TB0> INFO: 6108500 events read in total (207354ms).
[13:19:12.208] <TB0> INFO: 6783550 events read in total (230423ms).
[13:19:35.224] <TB0> INFO: 7457350 events read in total (253439ms).
[13:19:57.975] <TB0> INFO: 8130100 events read in total (276190ms).
[13:20:20.665] <TB0> INFO: 8805950 events read in total (298880ms).
[13:20:43.748] <TB0> INFO: 9482200 events read in total (321963ms).
[13:21:07.054] <TB0> INFO: 10155200 events read in total (345269ms).
[13:21:29.973] <TB0> INFO: 10828800 events read in total (368188ms).
[13:21:52.742] <TB0> INFO: 11501850 events read in total (390957ms).
[13:22:15.815] <TB0> INFO: 12177600 events read in total (414030ms).
[13:22:39.079] <TB0> INFO: 12850600 events read in total (437294ms).
[13:23:01.917] <TB0> INFO: 13522850 events read in total (460132ms).
[13:23:24.539] <TB0> INFO: 14195450 events read in total (482754ms).
[13:23:47.528] <TB0> INFO: 14867850 events read in total (505743ms).
[13:24:10.311] <TB0> INFO: 15537050 events read in total (528526ms).
[13:24:33.180] <TB0> INFO: 16205850 events read in total (551395ms).
[13:24:56.010] <TB0> INFO: 16875800 events read in total (574225ms).
[13:25:19.007] <TB0> INFO: 17546200 events read in total (597223ms).
[13:25:41.827] <TB0> INFO: 18214350 events read in total (620042ms).
[13:26:04.601] <TB0> INFO: 18883750 events read in total (642816ms).
[13:26:27.270] <TB0> INFO: 19552450 events read in total (665485ms).
[13:26:50.237] <TB0> INFO: 20220900 events read in total (688452ms).
[13:27:13.239] <TB0> INFO: 20888450 events read in total (711454ms).
[13:27:36.040] <TB0> INFO: 21556900 events read in total (734255ms).
[13:27:58.976] <TB0> INFO: 22225650 events read in total (757191ms).
[13:28:21.801] <TB0> INFO: 22893950 events read in total (780017ms).
[13:28:44.593] <TB0> INFO: 23561750 events read in total (802808ms).
[13:29:07.533] <TB0> INFO: 24228000 events read in total (825748ms).
[13:29:30.518] <TB0> INFO: 24893350 events read in total (848733ms).
[13:29:53.259] <TB0> INFO: 25559700 events read in total (871474ms).
[13:30:16.012] <TB0> INFO: 26224100 events read in total (894227ms).
[13:30:38.611] <TB0> INFO: 26890850 events read in total (916826ms).
[13:31:01.647] <TB0> INFO: 27559100 events read in total (939862ms).
[13:31:24.515] <TB0> INFO: 28226400 events read in total (962730ms).
[13:31:47.408] <TB0> INFO: 28893350 events read in total (985623ms).
[13:32:09.901] <TB0> INFO: 29558900 events read in total (1008116ms).
[13:32:32.606] <TB0> INFO: 30224400 events read in total (1030821ms).
[13:32:55.426] <TB0> INFO: 30889550 events read in total (1053641ms).
[13:33:18.543] <TB0> INFO: 31557650 events read in total (1076758ms).
[13:33:41.386] <TB0> INFO: 32224650 events read in total (1099601ms).
[13:34:04.306] <TB0> INFO: 32892150 events read in total (1122521ms).
[13:34:27.302] <TB0> INFO: 33562100 events read in total (1145517ms).
[13:34:50.041] <TB0> INFO: 34231050 events read in total (1168256ms).
[13:35:13.019] <TB0> INFO: 34900000 events read in total (1191234ms).
[13:35:35.863] <TB0> INFO: 35568550 events read in total (1214078ms).
[13:35:58.999] <TB0> INFO: 36245800 events read in total (1237214ms).
[13:36:11.281] <TB0> INFO: 36608000 events read in total (1249496ms).
[13:36:11.401] <TB0> INFO: Test took 1250455ms.
[13:36:11.914] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:13.823] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:15.567] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:17.061] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:18.482] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:19.912] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:21.320] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:23.021] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:24.874] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:26.885] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:28.454] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:30.145] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:31.724] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:33.275] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:35.082] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:36.912] <TB0> INFO: dumping ASCII scurve output file: SCurveData
[13:36:39.043] <TB0> INFO: PixTestScurves::scurves() done
[13:36:39.043] <TB0> INFO: Vcal mean: 130.11 134.46 125.56 120.90 126.39 127.66 124.13 121.46 130.67 126.44 122.63 132.80 112.83 118.77 117.28 122.09
[13:36:39.043] <TB0> INFO: Vcal RMS: 6.26 6.68 6.97 5.91 6.62 5.78 6.34 6.31 6.34 6.10 6.48 7.11 5.21 6.13 5.62 6.41
[13:36:39.043] <TB0> INFO: PixTestScurves::fullTest() done, duration: 1278 seconds
[13:36:39.043] <TB0> INFO: Decoding statistics:
[13:36:39.043] <TB0> INFO: General information:
[13:36:39.043] <TB0> INFO: 16bit words read: 0
[13:36:39.043] <TB0> INFO: valid events total: 0
[13:36:39.043] <TB0> INFO: empty events: 0
[13:36:39.043] <TB0> INFO: valid events with pixels: 0
[13:36:39.043] <TB0> INFO: valid pixel hits: 0
[13:36:39.043] <TB0> INFO: Event errors: 0
[13:36:39.043] <TB0> INFO: start marker: 0
[13:36:39.043] <TB0> INFO: stop marker: 0
[13:36:39.043] <TB0> INFO: overflow: 0
[13:36:39.043] <TB0> INFO: invalid 5bit words: 0
[13:36:39.043] <TB0> INFO: invalid XOR eye diagram: 0
[13:36:39.043] <TB0> INFO: frame (failed synchr.): 0
[13:36:39.043] <TB0> INFO: idle data (no TBM trl): 0
[13:36:39.043] <TB0> INFO: no data (only TBM hdr): 0
[13:36:39.043] <TB0> INFO: TBM errors: 0
[13:36:39.043] <TB0> INFO: flawed TBM headers: 0
[13:36:39.043] <TB0> INFO: flawed TBM trailers: 0
[13:36:39.043] <TB0> INFO: event ID mismatches: 0
[13:36:39.043] <TB0> INFO: ROC errors: 0
[13:36:39.043] <TB0> INFO: missing ROC header(s): 0
[13:36:39.043] <TB0> INFO: misplaced readback start: 0
[13:36:39.043] <TB0> INFO: Pixel decoding errors: 0
[13:36:39.043] <TB0> INFO: pixel data incomplete: 0
[13:36:39.043] <TB0> INFO: pixel address: 0
[13:36:39.043] <TB0> INFO: pulse height fill bit: 0
[13:36:39.043] <TB0> INFO: buffer corruption: 0
[13:36:39.113] <TB0> INFO: ######################################################################
[13:36:39.113] <TB0> INFO: PixTestTrim::doTest()
[13:36:39.113] <TB0> INFO: ######################################################################
[13:36:39.114] <TB0> INFO: ----------------------------------------------------------------------
[13:36:39.114] <TB0> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[13:36:39.114] <TB0> INFO: ----------------------------------------------------------------------
[13:36:39.155] <TB0> INFO: ---> VthrComp thr map (minimal VthrComp)
[13:36:39.155] <TB0> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[13:36:39.169] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:36:39.169] <TB0> INFO: run 1 of 1
[13:36:39.466] <TB0> INFO: Expecting 5025280 events.
[13:37:10.458] <TB0> INFO: 828808 events read in total (30391ms).
[13:37:40.548] <TB0> INFO: 1654792 events read in total (60481ms).
[13:38:10.641] <TB0> INFO: 2478288 events read in total (90575ms).
[13:38:40.821] <TB0> INFO: 3300432 events read in total (120754ms).
[13:39:10.923] <TB0> INFO: 4118808 events read in total (150856ms).
[13:39:41.129] <TB0> INFO: 4935152 events read in total (181062ms).
[13:39:44.838] <TB0> INFO: 5025280 events read in total (184771ms).
[13:39:44.893] <TB0> INFO: Test took 185724ms.
[13:40:00.940] <TB0> INFO: ROC 0 VthrComp = 125
[13:40:00.940] <TB0> INFO: ROC 1 VthrComp = 131
[13:40:00.940] <TB0> INFO: ROC 2 VthrComp = 117
[13:40:00.941] <TB0> INFO: ROC 3 VthrComp = 113
[13:40:00.941] <TB0> INFO: ROC 4 VthrComp = 119
[13:40:00.941] <TB0> INFO: ROC 5 VthrComp = 123
[13:40:00.941] <TB0> INFO: ROC 6 VthrComp = 119
[13:40:00.942] <TB0> INFO: ROC 7 VthrComp = 115
[13:40:00.942] <TB0> INFO: ROC 8 VthrComp = 132
[13:40:00.943] <TB0> INFO: ROC 9 VthrComp = 128
[13:40:00.943] <TB0> INFO: ROC 10 VthrComp = 119
[13:40:00.943] <TB0> INFO: ROC 11 VthrComp = 121
[13:40:00.943] <TB0> INFO: ROC 12 VthrComp = 112
[13:40:00.943] <TB0> INFO: ROC 13 VthrComp = 111
[13:40:00.943] <TB0> INFO: ROC 14 VthrComp = 114
[13:40:00.944] <TB0> INFO: ROC 15 VthrComp = 113
[13:40:01.215] <TB0> INFO: Expecting 41600 events.
[13:40:04.673] <TB0> INFO: 41600 events read in total (2866ms).
[13:40:04.674] <TB0> INFO: Test took 3729ms.
[13:40:04.683] <TB0> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[13:40:04.683] <TB0> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[13:40:04.694] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:40:04.694] <TB0> INFO: run 1 of 1
[13:40:04.972] <TB0> INFO: Expecting 5025280 events.
[13:40:31.574] <TB0> INFO: 593512 events read in total (26010ms).
[13:40:57.716] <TB0> INFO: 1185584 events read in total (52152ms).
[13:41:23.476] <TB0> INFO: 1777728 events read in total (77912ms).
[13:41:48.984] <TB0> INFO: 2368976 events read in total (103420ms).
[13:42:14.584] <TB0> INFO: 2958168 events read in total (129020ms).
[13:42:40.093] <TB0> INFO: 3546200 events read in total (154529ms).
[13:43:05.885] <TB0> INFO: 4132928 events read in total (180321ms).
[13:43:31.458] <TB0> INFO: 4720584 events read in total (205894ms).
[13:43:45.146] <TB0> INFO: 5025280 events read in total (219582ms).
[13:43:45.213] <TB0> INFO: Test took 220519ms.
[13:44:11.481] <TB0> INFO: roc 0 with ID = 0 has maximal Vcal 64.0097 for pixel 14/14 mean/min/max = 48.7492/33.1269/64.3716
[13:44:11.481] <TB0> INFO: roc 1 with ID = 1 has maximal Vcal 62.3741 for pixel 24/79 mean/min/max = 47.1824/31.9036/62.4613
[13:44:11.482] <TB0> INFO: roc 2 with ID = 2 has maximal Vcal 66.0934 for pixel 4/8 mean/min/max = 48.658/31.0399/66.2762
[13:44:11.482] <TB0> INFO: roc 3 with ID = 3 has maximal Vcal 63.4889 for pixel 49/4 mean/min/max = 48.1923/32.8391/63.5455
[13:44:11.482] <TB0> INFO: roc 4 with ID = 4 has maximal Vcal 62.4024 for pixel 0/76 mean/min/max = 46.9224/31.4264/62.4183
[13:44:11.483] <TB0> INFO: roc 5 with ID = 5 has maximal Vcal 62.0295 for pixel 46/0 mean/min/max = 46.9892/31.8637/62.1146
[13:44:11.483] <TB0> INFO: roc 6 with ID = 6 has maximal Vcal 61.8005 for pixel 15/3 mean/min/max = 46.9164/31.8821/61.9507
[13:44:11.483] <TB0> INFO: roc 7 with ID = 7 has maximal Vcal 64.7548 for pixel 0/45 mean/min/max = 48.1086/31.4048/64.8124
[13:44:11.484] <TB0> INFO: roc 8 with ID = 8 has maximal Vcal 62.9687 for pixel 51/7 mean/min/max = 48.0549/33.1388/62.9709
[13:44:11.484] <TB0> INFO: roc 9 with ID = 9 has maximal Vcal 59.8653 for pixel 5/5 mean/min/max = 45.6423/31.1566/60.128
[13:44:11.484] <TB0> INFO: roc 10 with ID = 10 has maximal Vcal 62.1696 for pixel 17/10 mean/min/max = 46.3466/30.4476/62.2456
[13:44:11.485] <TB0> INFO: roc 11 with ID = 11 has maximal Vcal 68.6495 for pixel 7/15 mean/min/max = 50.3396/32.0115/68.6677
[13:44:11.485] <TB0> INFO: roc 12 with ID = 12 has maximal Vcal 60.0847 for pixel 18/1 mean/min/max = 46.3836/32.443/60.3242
[13:44:11.485] <TB0> INFO: roc 13 with ID = 13 has maximal Vcal 64.2744 for pixel 47/9 mean/min/max = 49.8051/35.2726/64.3376
[13:44:11.486] <TB0> INFO: roc 14 with ID = 14 has maximal Vcal 60.8527 for pixel 51/6 mean/min/max = 46.6713/32.3166/61.026
[13:44:11.486] <TB0> INFO: roc 15 with ID = 15 has maximal Vcal 64.2938 for pixel 9/5 mean/min/max = 48.3396/32.0828/64.5964
[13:44:11.486] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:44:11.575] <TB0> INFO: Expecting 411648 events.
[13:44:21.095] <TB0> INFO: 411648 events read in total (8929ms).
[13:44:21.105] <TB0> INFO: Expecting 411648 events.
[13:44:30.550] <TB0> INFO: 411648 events read in total (9042ms).
[13:44:30.560] <TB0> INFO: Expecting 411648 events.
[13:44:39.809] <TB0> INFO: 411648 events read in total (8846ms).
[13:44:39.822] <TB0> INFO: Expecting 411648 events.
[13:44:49.336] <TB0> INFO: 411648 events read in total (9111ms).
[13:44:49.351] <TB0> INFO: Expecting 411648 events.
[13:44:58.776] <TB0> INFO: 411648 events read in total (9022ms).
[13:44:58.798] <TB0> INFO: Expecting 411648 events.
[13:45:08.301] <TB0> INFO: 411648 events read in total (9100ms).
[13:45:08.323] <TB0> INFO: Expecting 411648 events.
[13:45:17.830] <TB0> INFO: 411648 events read in total (9105ms).
[13:45:17.863] <TB0> INFO: Expecting 411648 events.
[13:45:27.359] <TB0> INFO: 411648 events read in total (9093ms).
[13:45:27.386] <TB0> INFO: Expecting 411648 events.
[13:45:36.947] <TB0> INFO: 411648 events read in total (9158ms).
[13:45:36.983] <TB0> INFO: Expecting 411648 events.
[13:45:46.461] <TB0> INFO: 411648 events read in total (9075ms).
[13:45:46.493] <TB0> INFO: Expecting 411648 events.
[13:45:55.984] <TB0> INFO: 411648 events read in total (9088ms).
[13:45:56.020] <TB0> INFO: Expecting 411648 events.
[13:46:05.468] <TB0> INFO: 411648 events read in total (9045ms).
[13:46:05.511] <TB0> INFO: Expecting 411648 events.
[13:46:15.052] <TB0> INFO: 411648 events read in total (9138ms).
[13:46:15.105] <TB0> INFO: Expecting 411648 events.
[13:46:24.588] <TB0> INFO: 411648 events read in total (9080ms).
[13:46:24.643] <TB0> INFO: Expecting 411648 events.
[13:46:34.136] <TB0> INFO: 411648 events read in total (9090ms).
[13:46:34.195] <TB0> INFO: Expecting 411648 events.
[13:46:43.745] <TB0> INFO: 411648 events read in total (9147ms).
[13:46:43.797] <TB0> INFO: Test took 152311ms.
[13:46:44.467] <TB0> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[13:46:44.480] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:46:44.480] <TB0> INFO: run 1 of 1
[13:46:44.719] <TB0> INFO: Expecting 5025280 events.
[13:47:11.529] <TB0> INFO: 590432 events read in total (26218ms).
[13:47:37.343] <TB0> INFO: 1181776 events read in total (52032ms).
[13:48:03.435] <TB0> INFO: 1771312 events read in total (78125ms).
[13:48:29.504] <TB0> INFO: 2358832 events read in total (104193ms).
[13:48:55.338] <TB0> INFO: 2951008 events read in total (130027ms).
[13:49:21.211] <TB0> INFO: 3541840 events read in total (155900ms).
[13:49:46.997] <TB0> INFO: 4132736 events read in total (181686ms).
[13:50:13.030] <TB0> INFO: 4721312 events read in total (207719ms).
[13:50:26.686] <TB0> INFO: 5025280 events read in total (221375ms).
[13:50:26.815] <TB0> INFO: Test took 222336ms.
[13:50:49.148] <TB0> INFO: ---> TrimStepCorr4 extremal thresholds: 7.382270 .. 145.858236
[13:50:49.389] <TB0> INFO: Expecting 208000 events.
[13:50:59.074] <TB0> INFO: 208000 events read in total (9093ms).
[13:50:59.076] <TB0> INFO: Test took 9927ms.
[13:50:59.142] <TB0> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 7 .. 155 (-1/-1) hits flags = 528 (plus default)
[13:50:59.157] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:50:59.157] <TB0> INFO: run 1 of 1
[13:50:59.462] <TB0> INFO: Expecting 4958720 events.
[13:51:26.746] <TB0> INFO: 577304 events read in total (26692ms).
[13:51:52.250] <TB0> INFO: 1154144 events read in total (52197ms).
[13:52:17.921] <TB0> INFO: 1730296 events read in total (77867ms).
[13:52:43.780] <TB0> INFO: 2307336 events read in total (103726ms).
[13:53:09.687] <TB0> INFO: 2884056 events read in total (129633ms).
[13:53:35.472] <TB0> INFO: 3460848 events read in total (155418ms).
[13:54:01.481] <TB0> INFO: 4037592 events read in total (181427ms).
[13:54:27.472] <TB0> INFO: 4613872 events read in total (207418ms).
[13:54:42.881] <TB0> INFO: 4958720 events read in total (222827ms).
[13:54:42.984] <TB0> INFO: Test took 223828ms.
[13:55:06.976] <TB0> INFO: ---> TrimStepCorr2 extremal thresholds: 27.051743 .. 47.334524
[13:55:07.222] <TB0> INFO: Expecting 208000 events.
[13:55:16.995] <TB0> INFO: 208000 events read in total (9181ms).
[13:55:16.996] <TB0> INFO: Test took 10017ms.
[13:55:17.059] <TB0> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 57 (-1/-1) hits flags = 528 (plus default)
[13:55:17.073] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:55:17.073] <TB0> INFO: run 1 of 1
[13:55:17.351] <TB0> INFO: Expecting 1364480 events.
[13:55:46.128] <TB0> INFO: 655080 events read in total (28186ms).
[13:56:13.791] <TB0> INFO: 1310216 events read in total (55850ms).
[13:56:16.427] <TB0> INFO: 1364480 events read in total (58485ms).
[13:56:16.459] <TB0> INFO: Test took 59387ms.
[13:56:30.084] <TB0> INFO: ---> TrimStepCorr1a extremal thresholds: 23.248517 .. 51.248310
[13:56:30.321] <TB0> INFO: Expecting 208000 events.
[13:56:40.194] <TB0> INFO: 208000 events read in total (9281ms).
[13:56:40.195] <TB0> INFO: Test took 10109ms.
[13:56:40.250] <TB0> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 13 .. 61 (-1/-1) hits flags = 528 (plus default)
[13:56:40.265] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:56:40.265] <TB0> INFO: run 1 of 1
[13:56:40.543] <TB0> INFO: Expecting 1630720 events.
[13:57:08.723] <TB0> INFO: 656408 events read in total (27588ms).
[13:57:36.149] <TB0> INFO: 1312064 events read in total (55014ms).
[13:57:49.490] <TB0> INFO: 1630720 events read in total (68355ms).
[13:57:49.525] <TB0> INFO: Test took 69261ms.
[13:58:04.950] <TB0> INFO: ---> TrimStepCorr1b extremal thresholds: 23.820213 .. 53.805582
[13:58:05.265] <TB0> INFO: Expecting 208000 events.
[13:58:15.400] <TB0> INFO: 208000 events read in total (9543ms).
[13:58:15.401] <TB0> INFO: Test took 10449ms.
[13:58:15.480] <TB0> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 13 .. 63 (-1/-1) hits flags = 528 (plus default)
[13:58:15.494] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:58:15.494] <TB0> INFO: run 1 of 1
[13:58:15.818] <TB0> INFO: Expecting 1697280 events.
[13:58:43.892] <TB0> INFO: 648688 events read in total (27482ms).
[13:59:11.391] <TB0> INFO: 1297144 events read in total (54981ms).
[13:59:28.541] <TB0> INFO: 1697280 events read in total (72131ms).
[13:59:28.575] <TB0> INFO: Test took 73082ms.
[13:59:42.621] <TB0> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[13:59:42.621] <TB0> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[13:59:42.634] <TB0> INFO: dacScan split into 1 runs with ntrig = 8
[13:59:42.634] <TB0> INFO: run 1 of 1
[13:59:42.873] <TB0> INFO: Expecting 1364480 events.
[14:00:12.099] <TB0> INFO: 668944 events read in total (28634ms).
[14:00:40.398] <TB0> INFO: 1337000 events read in total (56933ms).
[14:00:42.012] <TB0> INFO: 1364480 events read in total (58547ms).
[14:00:42.038] <TB0> INFO: Test took 59405ms.
[14:00:57.069] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C0.dat
[14:00:57.069] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C1.dat
[14:00:57.069] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C2.dat
[14:00:57.069] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C3.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C4.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C5.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C6.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C7.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C8.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C9.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C10.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C11.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C12.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C13.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C14.dat
[14:00:57.070] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C15.dat
[14:00:57.071] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C0.dat
[14:00:57.076] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C1.dat
[14:00:57.080] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C2.dat
[14:00:57.085] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C3.dat
[14:00:57.090] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C4.dat
[14:00:57.095] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C5.dat
[14:00:57.099] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C6.dat
[14:00:57.104] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C7.dat
[14:00:57.109] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C8.dat
[14:00:57.114] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C9.dat
[14:00:57.118] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C10.dat
[14:00:57.123] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C11.dat
[14:00:57.128] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C12.dat
[14:00:57.133] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C13.dat
[14:00:57.137] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C14.dat
[14:00:57.142] <TB0> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//trimParameters35_C15.dat
[14:00:57.147] <TB0> INFO: PixTestTrim::trimTest() done
[14:00:57.147] <TB0> INFO: vtrim: 127 124 146 128 115 118 124 140 137 122 122 136 138 130 106 118
[14:00:57.147] <TB0> INFO: vthrcomp: 125 131 117 113 119 123 119 115 132 128 119 121 112 111 114 113
[14:00:57.147] <TB0> INFO: vcal mean: 35.93 35.35 35.43 35.20 35.05 35.10 35.12 35.17 35.18 34.92 34.95 36.96 35.01 35.27 34.99 35.61
[14:00:57.147] <TB0> INFO: vcal RMS: 2.08 1.49 1.72 1.38 1.31 1.17 1.29 1.34 1.38 1.03 1.28 3.03 1.14 1.44 1.07 1.91
[14:00:57.147] <TB0> INFO: bits mean: 9.39 9.38 9.75 9.33 9.16 9.48 9.66 9.18 8.57 9.63 9.98 9.48 10.04 8.69 8.77 9.37
[14:00:57.147] <TB0> INFO: bits RMS: 2.71 2.79 2.62 2.64 2.95 2.77 2.65 2.86 2.85 2.80 2.70 2.94 2.39 2.55 3.00 2.81
[14:00:57.155] <TB0> INFO: ----------------------------------------------------------------------
[14:00:57.155] <TB0> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[14:00:57.155] <TB0> INFO: ----------------------------------------------------------------------
[14:00:57.157] <TB0> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[14:00:57.170] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[14:00:57.170] <TB0> INFO: run 1 of 1
[14:00:57.413] <TB0> INFO: Expecting 4160000 events.
[14:01:30.301] <TB0> INFO: 769395 events read in total (32296ms).
[14:02:02.717] <TB0> INFO: 1531870 events read in total (64712ms).
[14:02:35.158] <TB0> INFO: 2288770 events read in total (97153ms).
[14:03:07.481] <TB0> INFO: 3041445 events read in total (129476ms).
[14:03:39.698] <TB0> INFO: 3793165 events read in total (161693ms).
[14:03:55.476] <TB0> INFO: 4160000 events read in total (177471ms).
[14:03:55.590] <TB0> INFO: Test took 178420ms.
[14:04:21.291] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 215 (-1/-1) hits flags = 528 (plus default)
[14:04:21.305] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[14:04:21.305] <TB0> INFO: run 1 of 1
[14:04:21.541] <TB0> INFO: Expecting 4492800 events.
[14:04:52.988] <TB0> INFO: 722770 events read in total (30856ms).
[14:05:24.062] <TB0> INFO: 1440485 events read in total (61930ms).
[14:05:55.124] <TB0> INFO: 2154715 events read in total (92992ms).
[14:06:25.919] <TB0> INFO: 2865785 events read in total (123787ms).
[14:06:56.889] <TB0> INFO: 3574250 events read in total (154757ms).
[14:07:27.891] <TB0> INFO: 4283240 events read in total (185759ms).
[14:07:37.300] <TB0> INFO: 4492800 events read in total (195168ms).
[14:07:37.397] <TB0> INFO: Test took 196091ms.
[14:08:07.510] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 208 (-1/-1) hits flags = 528 (plus default)
[14:08:07.524] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[14:08:07.524] <TB0> INFO: run 1 of 1
[14:08:07.790] <TB0> INFO: Expecting 4347200 events.
[14:08:39.726] <TB0> INFO: 731615 events read in total (31345ms).
[14:09:10.830] <TB0> INFO: 1458220 events read in total (62449ms).
[14:09:42.121] <TB0> INFO: 2180780 events read in total (93740ms).
[14:10:13.818] <TB0> INFO: 2899605 events read in total (125437ms).
[14:10:45.106] <TB0> INFO: 3616350 events read in total (156726ms).
[14:11:16.482] <TB0> INFO: 4336385 events read in total (188101ms).
[14:11:17.349] <TB0> INFO: 4347200 events read in total (188968ms).
[14:11:17.509] <TB0> INFO: Test took 189984ms.
[14:11:44.531] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 208 (-1/-1) hits flags = 528 (plus default)
[14:11:44.545] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[14:11:44.545] <TB0> INFO: run 1 of 1
[14:11:44.783] <TB0> INFO: Expecting 4347200 events.
[14:12:16.687] <TB0> INFO: 731955 events read in total (31312ms).
[14:12:48.045] <TB0> INFO: 1458715 events read in total (62670ms).
[14:13:18.968] <TB0> INFO: 2181110 events read in total (93593ms).
[14:13:50.164] <TB0> INFO: 2900135 events read in total (124789ms).
[14:14:21.143] <TB0> INFO: 3616780 events read in total (155768ms).
[14:14:52.243] <TB0> INFO: 4337225 events read in total (186868ms).
[14:14:53.067] <TB0> INFO: 4347200 events read in total (187692ms).
[14:14:53.138] <TB0> INFO: Test took 188594ms.
[14:15:20.896] <TB0> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 205 (-1/-1) hits flags = 528 (plus default)
[14:15:20.910] <TB0> INFO: dacScan split into 1 runs with ntrig = 5
[14:15:20.910] <TB0> INFO: run 1 of 1
[14:15:21.188] <TB0> INFO: Expecting 4284800 events.
[14:15:53.264] <TB0> INFO: 736275 events read in total (31484ms).
[14:16:24.573] <TB0> INFO: 1466930 events read in total (62793ms).
[14:16:56.066] <TB0> INFO: 2192880 events read in total (94286ms).
[14:17:27.504] <TB0> INFO: 2915505 events read in total (125724ms).
[14:17:58.791] <TB0> INFO: 3635725 events read in total (157011ms).
[14:18:27.021] <TB0> INFO: 4284800 events read in total (185241ms).
[14:18:27.109] <TB0> INFO: Test took 186199ms.
[14:18:56.128] <TB0> INFO: PixTestTrim::trimBitTest() done
[14:18:56.129] <TB0> INFO: PixTestTrim::doTest() done, duration: 2537 seconds
[14:18:56.129] <TB0> INFO: Decoding statistics:
[14:18:56.129] <TB0> INFO: General information:
[14:18:56.129] <TB0> INFO: 16bit words read: 0
[14:18:56.129] <TB0> INFO: valid events total: 0
[14:18:56.129] <TB0> INFO: empty events: 0
[14:18:56.129] <TB0> INFO: valid events with pixels: 0
[14:18:56.129] <TB0> INFO: valid pixel hits: 0
[14:18:56.129] <TB0> INFO: Event errors: 0
[14:18:56.129] <TB0> INFO: start marker: 0
[14:18:56.129] <TB0> INFO: stop marker: 0
[14:18:56.129] <TB0> INFO: overflow: 0
[14:18:56.129] <TB0> INFO: invalid 5bit words: 0
[14:18:56.129] <TB0> INFO: invalid XOR eye diagram: 0
[14:18:56.129] <TB0> INFO: frame (failed synchr.): 0
[14:18:56.129] <TB0> INFO: idle data (no TBM trl): 0
[14:18:56.129] <TB0> INFO: no data (only TBM hdr): 0
[14:18:56.129] <TB0> INFO: TBM errors: 0
[14:18:56.129] <TB0> INFO: flawed TBM headers: 0
[14:18:56.129] <TB0> INFO: flawed TBM trailers: 0
[14:18:56.129] <TB0> INFO: event ID mismatches: 0
[14:18:56.129] <TB0> INFO: ROC errors: 0
[14:18:56.129] <TB0> INFO: missing ROC header(s): 0
[14:18:56.129] <TB0> INFO: misplaced readback start: 0
[14:18:56.129] <TB0> INFO: Pixel decoding errors: 0
[14:18:56.129] <TB0> INFO: pixel data incomplete: 0
[14:18:56.129] <TB0> INFO: pixel address: 0
[14:18:56.129] <TB0> INFO: pulse height fill bit: 0
[14:18:56.129] <TB0> INFO: buffer corruption: 0
[14:18:56.837] <TB0> INFO: ######################################################################
[14:18:56.837] <TB0> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[14:18:56.837] <TB0> INFO: ######################################################################
[14:18:57.076] <TB0> INFO: Expecting 41600 events.
[14:19:00.691] <TB0> INFO: 41600 events read in total (3023ms).
[14:19:00.692] <TB0> INFO: Test took 3853ms.
[14:19:01.211] <TB0> INFO: Expecting 41600 events.
[14:19:04.679] <TB0> INFO: 41600 events read in total (2876ms).
[14:19:04.681] <TB0> INFO: Test took 3786ms.
[14:19:04.997] <TB0> INFO: Expecting 41600 events.
[14:19:08.557] <TB0> INFO: 41600 events read in total (2968ms).
[14:19:08.558] <TB0> INFO: Test took 3853ms.
[14:19:08.907] <TB0> INFO: Expecting 41600 events.
[14:19:12.605] <TB0> INFO: 41600 events read in total (3106ms).
[14:19:12.606] <TB0> INFO: Test took 4024ms.
[14:19:12.960] <TB0> INFO: Expecting 41600 events.
[14:19:16.521] <TB0> INFO: 41600 events read in total (2969ms).
[14:19:16.522] <TB0> INFO: Test took 3887ms.
[14:19:16.828] <TB0> INFO: Expecting 41600 events.
[14:19:20.302] <TB0> INFO: 41600 events read in total (2882ms).
[14:19:20.303] <TB0> INFO: Test took 3755ms.
[14:19:20.594] <TB0> INFO: Expecting 41600 events.
[14:19:24.087] <TB0> INFO: 41600 events read in total (2901ms).
[14:19:24.088] <TB0> INFO: Test took 3759ms.
[14:19:24.378] <TB0> INFO: Expecting 41600 events.
[14:19:27.822] <TB0> INFO: 41600 events read in total (2852ms).
[14:19:27.823] <TB0> INFO: Test took 3712ms.
[14:19:28.112] <TB0> INFO: Expecting 41600 events.
[14:19:31.647] <TB0> INFO: 41600 events read in total (2943ms).
[14:19:31.648] <TB0> INFO: Test took 3801ms.
[14:19:31.941] <TB0> INFO: Expecting 41600 events.
[14:19:35.468] <TB0> INFO: 41600 events read in total (2936ms).
[14:19:35.469] <TB0> INFO: Test took 3794ms.
[14:19:35.765] <TB0> INFO: Expecting 41600 events.
[14:19:39.269] <TB0> INFO: 41600 events read in total (2913ms).
[14:19:39.270] <TB0> INFO: Test took 3775ms.
[14:19:39.559] <TB0> INFO: Expecting 41600 events.
[14:19:43.049] <TB0> INFO: 41600 events read in total (2899ms).
[14:19:43.049] <TB0> INFO: Test took 3756ms.
[14:19:43.340] <TB0> INFO: Expecting 41600 events.
[14:19:46.817] <TB0> INFO: 41600 events read in total (2882ms).
[14:19:46.818] <TB0> INFO: Test took 3743ms.
[14:19:47.107] <TB0> INFO: Expecting 41600 events.
[14:19:50.663] <TB0> INFO: 41600 events read in total (2965ms).
[14:19:50.664] <TB0> INFO: Test took 3822ms.
[14:19:50.964] <TB0> INFO: Expecting 41600 events.
[14:19:54.536] <TB0> INFO: 41600 events read in total (2980ms).
[14:19:54.537] <TB0> INFO: Test took 3848ms.
[14:19:54.825] <TB0> INFO: Expecting 41600 events.
[14:19:58.346] <TB0> INFO: 41600 events read in total (2929ms).
[14:19:58.347] <TB0> INFO: Test took 3787ms.
[14:19:58.635] <TB0> INFO: Expecting 41600 events.
[14:20:02.269] <TB0> INFO: 41600 events read in total (3042ms).
[14:20:02.270] <TB0> INFO: Test took 3899ms.
[14:20:02.577] <TB0> INFO: Expecting 41600 events.
[14:20:06.059] <TB0> INFO: 41600 events read in total (2891ms).
[14:20:06.061] <TB0> INFO: Test took 3766ms.
[14:20:06.351] <TB0> INFO: Expecting 41600 events.
[14:20:09.816] <TB0> INFO: 41600 events read in total (2873ms).
[14:20:09.817] <TB0> INFO: Test took 3731ms.
[14:20:10.106] <TB0> INFO: Expecting 41600 events.
[14:20:13.599] <TB0> INFO: 41600 events read in total (2901ms).
[14:20:13.600] <TB0> INFO: Test took 3759ms.
[14:20:13.905] <TB0> INFO: Expecting 41600 events.
[14:20:17.425] <TB0> INFO: 41600 events read in total (2928ms).
[14:20:17.426] <TB0> INFO: Test took 3801ms.
[14:20:17.717] <TB0> INFO: Expecting 41600 events.
[14:20:21.203] <TB0> INFO: 41600 events read in total (2894ms).
[14:20:21.204] <TB0> INFO: Test took 3752ms.
[14:20:21.494] <TB0> INFO: Expecting 41600 events.
[14:20:25.050] <TB0> INFO: 41600 events read in total (2965ms).
[14:20:25.051] <TB0> INFO: Test took 3822ms.
[14:20:25.340] <TB0> INFO: Expecting 41600 events.
[14:20:28.832] <TB0> INFO: 41600 events read in total (2901ms).
[14:20:28.833] <TB0> INFO: Test took 3758ms.
[14:20:29.122] <TB0> INFO: Expecting 41600 events.
[14:20:32.611] <TB0> INFO: 41600 events read in total (2897ms).
[14:20:32.612] <TB0> INFO: Test took 3755ms.
[14:20:32.903] <TB0> INFO: Expecting 41600 events.
[14:20:36.348] <TB0> INFO: 41600 events read in total (2853ms).
[14:20:36.349] <TB0> INFO: Test took 3711ms.
[14:20:36.639] <TB0> INFO: Expecting 41600 events.
[14:20:40.119] <TB0> INFO: 41600 events read in total (2889ms).
[14:20:40.120] <TB0> INFO: Test took 3746ms.
[14:20:40.412] <TB0> INFO: Expecting 2560 events.
[14:20:41.295] <TB0> INFO: 2560 events read in total (291ms).
[14:20:41.295] <TB0> INFO: Test took 1159ms.
[14:20:41.604] <TB0> INFO: Expecting 2560 events.
[14:20:42.487] <TB0> INFO: 2560 events read in total (292ms).
[14:20:42.487] <TB0> INFO: Test took 1191ms.
[14:20:42.795] <TB0> INFO: Expecting 2560 events.
[14:20:43.679] <TB0> INFO: 2560 events read in total (293ms).
[14:20:43.679] <TB0> INFO: Test took 1191ms.
[14:20:43.987] <TB0> INFO: Expecting 2560 events.
[14:20:44.874] <TB0> INFO: 2560 events read in total (295ms).
[14:20:44.874] <TB0> INFO: Test took 1193ms.
[14:20:45.182] <TB0> INFO: Expecting 2560 events.
[14:20:46.062] <TB0> INFO: 2560 events read in total (288ms).
[14:20:46.062] <TB0> INFO: Test took 1188ms.
[14:20:46.370] <TB0> INFO: Expecting 2560 events.
[14:20:47.251] <TB0> INFO: 2560 events read in total (289ms).
[14:20:47.251] <TB0> INFO: Test took 1188ms.
[14:20:47.560] <TB0> INFO: Expecting 2560 events.
[14:20:48.439] <TB0> INFO: 2560 events read in total (288ms).
[14:20:48.439] <TB0> INFO: Test took 1187ms.
[14:20:48.746] <TB0> INFO: Expecting 2560 events.
[14:20:49.626] <TB0> INFO: 2560 events read in total (288ms).
[14:20:49.626] <TB0> INFO: Test took 1187ms.
[14:20:49.934] <TB0> INFO: Expecting 2560 events.
[14:20:50.813] <TB0> INFO: 2560 events read in total (288ms).
[14:20:50.813] <TB0> INFO: Test took 1187ms.
[14:20:51.121] <TB0> INFO: Expecting 2560 events.
[14:20:51.000] <TB0> INFO: 2560 events read in total (287ms).
[14:20:51.000] <TB0> INFO: Test took 1186ms.
[14:20:52.308] <TB0> INFO: Expecting 2560 events.
[14:20:53.194] <TB0> INFO: 2560 events read in total (294ms).
[14:20:53.194] <TB0> INFO: Test took 1193ms.
[14:20:53.503] <TB0> INFO: Expecting 2560 events.
[14:20:54.383] <TB0> INFO: 2560 events read in total (288ms).
[14:20:54.383] <TB0> INFO: Test took 1188ms.
[14:20:54.691] <TB0> INFO: Expecting 2560 events.
[14:20:55.574] <TB0> INFO: 2560 events read in total (291ms).
[14:20:55.574] <TB0> INFO: Test took 1190ms.
[14:20:55.883] <TB0> INFO: Expecting 2560 events.
[14:20:56.769] <TB0> INFO: 2560 events read in total (294ms).
[14:20:56.770] <TB0> INFO: Test took 1195ms.
[14:20:57.078] <TB0> INFO: Expecting 2560 events.
[14:20:57.961] <TB0> INFO: 2560 events read in total (291ms).
[14:20:57.962] <TB0> INFO: Test took 1192ms.
[14:20:58.270] <TB0> INFO: Expecting 2560 events.
[14:20:59.156] <TB0> INFO: 2560 events read in total (295ms).
[14:20:59.156] <TB0> INFO: Test took 1194ms.
[14:20:59.159] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:20:59.465] <TB0> INFO: Expecting 655360 events.
[14:21:14.388] <TB0> INFO: 655360 events read in total (14331ms).
[14:21:14.406] <TB0> INFO: Expecting 655360 events.
[14:21:29.266] <TB0> INFO: 655360 events read in total (14456ms).
[14:21:29.284] <TB0> INFO: Expecting 655360 events.
[14:21:44.114] <TB0> INFO: 655360 events read in total (14427ms).
[14:21:44.138] <TB0> INFO: Expecting 655360 events.
[14:21:58.731] <TB0> INFO: 655360 events read in total (14190ms).
[14:21:58.759] <TB0> INFO: Expecting 655360 events.
[14:22:13.477] <TB0> INFO: 655360 events read in total (14315ms).
[14:22:13.510] <TB0> INFO: Expecting 655360 events.
[14:22:28.390] <TB0> INFO: 655360 events read in total (14477ms).
[14:22:28.428] <TB0> INFO: Expecting 655360 events.
[14:22:43.240] <TB0> INFO: 655360 events read in total (14409ms).
[14:22:43.281] <TB0> INFO: Expecting 655360 events.
[14:22:58.065] <TB0> INFO: 655360 events read in total (14381ms).
[14:22:58.119] <TB0> INFO: Expecting 655360 events.
[14:23:12.699] <TB0> INFO: 655360 events read in total (14177ms).
[14:23:12.889] <TB0> INFO: Expecting 655360 events.
[14:23:27.357] <TB0> INFO: 655360 events read in total (14065ms).
[14:23:27.519] <TB0> INFO: Expecting 655360 events.
[14:23:42.168] <TB0> INFO: 655360 events read in total (14246ms).
[14:23:42.239] <TB0> INFO: Expecting 655360 events.
[14:23:56.758] <TB0> INFO: 655360 events read in total (14116ms).
[14:23:56.835] <TB0> INFO: Expecting 655360 events.
[14:24:11.450] <TB0> INFO: 655360 events read in total (14212ms).
[14:24:11.534] <TB0> INFO: Expecting 655360 events.
[14:24:26.031] <TB0> INFO: 655360 events read in total (14094ms).
[14:24:26.122] <TB0> INFO: Expecting 655360 events.
[14:24:40.746] <TB0> INFO: 655360 events read in total (14221ms).
[14:24:40.839] <TB0> INFO: Expecting 655360 events.
[14:24:55.582] <TB0> INFO: 655360 events read in total (14339ms).
[14:24:55.709] <TB0> INFO: Test took 236550ms.
[14:24:55.803] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:24:56.061] <TB0> INFO: Expecting 655360 events.
[14:25:10.459] <TB0> INFO: 655360 events read in total (13807ms).
[14:25:10.472] <TB0> INFO: Expecting 655360 events.
[14:25:24.923] <TB0> INFO: 655360 events read in total (14048ms).
[14:25:24.944] <TB0> INFO: Expecting 655360 events.
[14:25:39.485] <TB0> INFO: 655360 events read in total (14138ms).
[14:25:39.508] <TB0> INFO: Expecting 655360 events.
[14:25:53.774] <TB0> INFO: 655360 events read in total (13862ms).
[14:25:53.807] <TB0> INFO: Expecting 655360 events.
[14:26:08.347] <TB0> INFO: 655360 events read in total (14137ms).
[14:26:08.383] <TB0> INFO: Expecting 655360 events.
[14:26:23.077] <TB0> INFO: 655360 events read in total (14291ms).
[14:26:23.112] <TB0> INFO: Expecting 655360 events.
[14:26:37.916] <TB0> INFO: 655360 events read in total (14401ms).
[14:26:37.970] <TB0> INFO: Expecting 655360 events.
[14:26:52.516] <TB0> INFO: 655360 events read in total (14142ms).
[14:26:52.566] <TB0> INFO: Expecting 655360 events.
[14:27:06.930] <TB0> INFO: 655360 events read in total (13961ms).
[14:27:06.988] <TB0> INFO: Expecting 655360 events.
[14:27:21.456] <TB0> INFO: 655360 events read in total (14065ms).
[14:27:21.521] <TB0> INFO: Expecting 655360 events.
[14:27:36.180] <TB0> INFO: 655360 events read in total (14256ms).
[14:27:36.306] <TB0> INFO: Expecting 655360 events.
[14:27:50.919] <TB0> INFO: 655360 events read in total (14210ms).
[14:27:50.993] <TB0> INFO: Expecting 655360 events.
[14:28:05.670] <TB0> INFO: 655360 events read in total (14274ms).
[14:28:05.754] <TB0> INFO: Expecting 655360 events.
[14:28:20.342] <TB0> INFO: 655360 events read in total (14185ms).
[14:28:20.429] <TB0> INFO: Expecting 655360 events.
[14:28:35.252] <TB0> INFO: 655360 events read in total (14420ms).
[14:28:35.368] <TB0> INFO: Expecting 655360 events.
[14:28:49.706] <TB0> INFO: 655360 events read in total (13935ms).
[14:28:49.882] <TB0> INFO: Test took 234079ms.
[14:28:50.108] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.116] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.124] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.132] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[14:28:50.140] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[14:28:50.148] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[14:28:50.157] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[14:28:50.165] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[14:28:50.174] <TB0> INFO: safety margin for low PH: adding 6, margin is now 26
[14:28:50.182] <TB0> INFO: safety margin for low PH: adding 7, margin is now 27
[14:28:50.190] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.198] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[14:28:50.207] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[14:28:50.215] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[14:28:50.224] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.232] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.240] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[14:28:50.249] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[14:28:50.257] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[14:28:50.266] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[14:28:50.275] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[14:28:50.283] <TB0> INFO: safety margin for low PH: adding 6, margin is now 26
[14:28:50.291] <TB0> INFO: safety margin for low PH: adding 7, margin is now 27
[14:28:50.300] <TB0> INFO: safety margin for low PH: adding 8, margin is now 28
[14:28:50.308] <TB0> INFO: safety margin for low PH: adding 9, margin is now 29
[14:28:50.316] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.325] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[14:28:50.333] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[14:28:50.341] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[14:28:50.350] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.358] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[14:28:50.366] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.374] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[14:28:50.383] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[14:28:50.391] <TB0> INFO: safety margin for low PH: adding 3, margin is now 23
[14:28:50.400] <TB0> INFO: safety margin for low PH: adding 4, margin is now 24
[14:28:50.408] <TB0> INFO: safety margin for low PH: adding 5, margin is now 25
[14:28:50.417] <TB0> INFO: safety margin for low PH: adding 6, margin is now 26
[14:28:50.425] <TB0> INFO: safety margin for low PH: adding 7, margin is now 27
[14:28:50.434] <TB0> INFO: safety margin for low PH: adding 8, margin is now 28
[14:28:50.442] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.451] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.459] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.467] <TB0> INFO: safety margin for low PH: adding 1, margin is now 21
[14:28:50.475] <TB0> INFO: safety margin for low PH: adding 2, margin is now 22
[14:28:50.484] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.492] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.501] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.509] <TB0> INFO: safety margin for low PH: adding 0, margin is now 20
[14:28:50.545] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C0.dat
[14:28:50.546] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C1.dat
[14:28:50.546] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C2.dat
[14:28:50.546] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C3.dat
[14:28:50.546] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C4.dat
[14:28:50.546] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C5.dat
[14:28:50.547] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C6.dat
[14:28:50.547] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C7.dat
[14:28:50.547] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C8.dat
[14:28:50.547] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C9.dat
[14:28:50.547] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C10.dat
[14:28:50.547] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C11.dat
[14:28:50.547] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C12.dat
[14:28:50.548] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C13.dat
[14:28:50.548] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C14.dat
[14:28:50.548] <TB0> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//dacParameters35_C15.dat
[14:28:50.788] <TB0> INFO: Expecting 41600 events.
[14:28:53.913] <TB0> INFO: 41600 events read in total (2534ms).
[14:28:53.914] <TB0> INFO: Test took 3363ms.
[14:28:54.364] <TB0> INFO: Expecting 41600 events.
[14:28:57.350] <TB0> INFO: 41600 events read in total (2395ms).
[14:28:57.351] <TB0> INFO: Test took 3225ms.
[14:28:57.816] <TB0> INFO: Expecting 41600 events.
[14:29:01.018] <TB0> INFO: 41600 events read in total (2610ms).
[14:29:01.019] <TB0> INFO: Test took 3454ms.
[14:29:01.239] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:01.329] <TB0> INFO: Expecting 2560 events.
[14:29:02.225] <TB0> INFO: 2560 events read in total (304ms).
[14:29:02.225] <TB0> INFO: Test took 986ms.
[14:29:02.228] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:02.532] <TB0> INFO: Expecting 2560 events.
[14:29:03.427] <TB0> INFO: 2560 events read in total (303ms).
[14:29:03.428] <TB0> INFO: Test took 1200ms.
[14:29:03.432] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:03.735] <TB0> INFO: Expecting 2560 events.
[14:29:04.627] <TB0> INFO: 2560 events read in total (300ms).
[14:29:04.628] <TB0> INFO: Test took 1196ms.
[14:29:04.630] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:04.935] <TB0> INFO: Expecting 2560 events.
[14:29:05.828] <TB0> INFO: 2560 events read in total (301ms).
[14:29:05.829] <TB0> INFO: Test took 1199ms.
[14:29:05.831] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:06.138] <TB0> INFO: Expecting 2560 events.
[14:29:07.032] <TB0> INFO: 2560 events read in total (303ms).
[14:29:07.033] <TB0> INFO: Test took 1203ms.
[14:29:07.036] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:07.340] <TB0> INFO: Expecting 2560 events.
[14:29:08.231] <TB0> INFO: 2560 events read in total (300ms).
[14:29:08.231] <TB0> INFO: Test took 1196ms.
[14:29:08.235] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:08.540] <TB0> INFO: Expecting 2560 events.
[14:29:09.429] <TB0> INFO: 2560 events read in total (297ms).
[14:29:09.430] <TB0> INFO: Test took 1195ms.
[14:29:09.432] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:09.738] <TB0> INFO: Expecting 2560 events.
[14:29:10.631] <TB0> INFO: 2560 events read in total (301ms).
[14:29:10.631] <TB0> INFO: Test took 1199ms.
[14:29:10.634] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:10.940] <TB0> INFO: Expecting 2560 events.
[14:29:11.824] <TB0> INFO: 2560 events read in total (292ms).
[14:29:11.824] <TB0> INFO: Test took 1190ms.
[14:29:11.826] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:12.133] <TB0> INFO: Expecting 2560 events.
[14:29:13.025] <TB0> INFO: 2560 events read in total (300ms).
[14:29:13.025] <TB0> INFO: Test took 1199ms.
[14:29:13.028] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:13.334] <TB0> INFO: Expecting 2560 events.
[14:29:14.221] <TB0> INFO: 2560 events read in total (296ms).
[14:29:14.221] <TB0> INFO: Test took 1193ms.
[14:29:14.224] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:14.530] <TB0> INFO: Expecting 2560 events.
[14:29:15.423] <TB0> INFO: 2560 events read in total (301ms).
[14:29:15.424] <TB0> INFO: Test took 1200ms.
[14:29:15.428] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:15.731] <TB0> INFO: Expecting 2560 events.
[14:29:16.626] <TB0> INFO: 2560 events read in total (303ms).
[14:29:16.626] <TB0> INFO: Test took 1199ms.
[14:29:16.628] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:16.935] <TB0> INFO: Expecting 2560 events.
[14:29:17.824] <TB0> INFO: 2560 events read in total (297ms).
[14:29:17.825] <TB0> INFO: Test took 1197ms.
[14:29:17.827] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:18.133] <TB0> INFO: Expecting 2560 events.
[14:29:19.012] <TB0> INFO: 2560 events read in total (287ms).
[14:29:19.013] <TB0> INFO: Test took 1186ms.
[14:29:19.015] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:19.321] <TB0> INFO: Expecting 2560 events.
[14:29:20.202] <TB0> INFO: 2560 events read in total (289ms).
[14:29:20.202] <TB0> INFO: Test took 1187ms.
[14:29:20.206] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:20.510] <TB0> INFO: Expecting 2560 events.
[14:29:21.390] <TB0> INFO: 2560 events read in total (289ms).
[14:29:21.391] <TB0> INFO: Test took 1186ms.
[14:29:21.395] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:21.698] <TB0> INFO: Expecting 2560 events.
[14:29:22.587] <TB0> INFO: 2560 events read in total (297ms).
[14:29:22.587] <TB0> INFO: Test took 1192ms.
[14:29:22.591] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:22.895] <TB0> INFO: Expecting 2560 events.
[14:29:23.782] <TB0> INFO: 2560 events read in total (296ms).
[14:29:23.783] <TB0> INFO: Test took 1192ms.
[14:29:23.786] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:24.091] <TB0> INFO: Expecting 2560 events.
[14:29:24.977] <TB0> INFO: 2560 events read in total (294ms).
[14:29:24.978] <TB0> INFO: Test took 1192ms.
[14:29:24.981] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:25.285] <TB0> INFO: Expecting 2560 events.
[14:29:26.167] <TB0> INFO: 2560 events read in total (290ms).
[14:29:26.167] <TB0> INFO: Test took 1186ms.
[14:29:26.169] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:26.475] <TB0> INFO: Expecting 2560 events.
[14:29:27.361] <TB0> INFO: 2560 events read in total (294ms).
[14:29:27.362] <TB0> INFO: Test took 1193ms.
[14:29:27.364] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:27.670] <TB0> INFO: Expecting 2560 events.
[14:29:28.561] <TB0> INFO: 2560 events read in total (299ms).
[14:29:28.562] <TB0> INFO: Test took 1199ms.
[14:29:28.566] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:28.869] <TB0> INFO: Expecting 2560 events.
[14:29:29.757] <TB0> INFO: 2560 events read in total (296ms).
[14:29:29.758] <TB0> INFO: Test took 1192ms.
[14:29:29.761] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:30.065] <TB0> INFO: Expecting 2560 events.
[14:29:30.958] <TB0> INFO: 2560 events read in total (301ms).
[14:29:30.958] <TB0> INFO: Test took 1197ms.
[14:29:30.960] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:31.268] <TB0> INFO: Expecting 2560 events.
[14:29:32.163] <TB0> INFO: 2560 events read in total (304ms).
[14:29:32.164] <TB0> INFO: Test took 1204ms.
[14:29:32.167] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:32.472] <TB0> INFO: Expecting 2560 events.
[14:29:33.366] <TB0> INFO: 2560 events read in total (302ms).
[14:29:33.367] <TB0> INFO: Test took 1200ms.
[14:29:33.369] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:33.677] <TB0> INFO: Expecting 2560 events.
[14:29:34.565] <TB0> INFO: 2560 events read in total (296ms).
[14:29:34.565] <TB0> INFO: Test took 1196ms.
[14:29:34.568] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:34.874] <TB0> INFO: Expecting 2560 events.
[14:29:35.766] <TB0> INFO: 2560 events read in total (300ms).
[14:29:35.767] <TB0> INFO: Test took 1200ms.
[14:29:35.769] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:36.076] <TB0> INFO: Expecting 2560 events.
[14:29:36.965] <TB0> INFO: 2560 events read in total (297ms).
[14:29:36.965] <TB0> INFO: Test took 1196ms.
[14:29:36.967] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:37.274] <TB0> INFO: Expecting 2560 events.
[14:29:38.165] <TB0> INFO: 2560 events read in total (299ms).
[14:29:38.167] <TB0> INFO: Test took 1200ms.
[14:29:38.170] <TB0> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:29:38.473] <TB0> INFO: Expecting 2560 events.
[14:29:39.368] <TB0> INFO: 2560 events read in total (304ms).
[14:29:39.368] <TB0> INFO: Test took 1199ms.
[14:29:39.844] <TB0> INFO: PixTestPhOptimization::doTest() done, duration: 643 seconds
[14:29:39.845] <TB0> INFO: PH scale (per ROC): 37 38 30 37 46 29 36 31 49 36 40 34 38 37 42 33
[14:29:39.845] <TB0> INFO: PH offset (per ROC): 101 103 80 100 104 96 113 101 123 99 100 106 100 93 105 104
[14:29:39.857] <TB0> INFO: Decoding statistics:
[14:29:39.857] <TB0> INFO: General information:
[14:29:39.857] <TB0> INFO: 16bit words read: 127872
[14:29:39.857] <TB0> INFO: valid events total: 20480
[14:29:39.857] <TB0> INFO: empty events: 17984
[14:29:39.857] <TB0> INFO: valid events with pixels: 2496
[14:29:39.857] <TB0> INFO: valid pixel hits: 2496
[14:29:39.857] <TB0> INFO: Event errors: 0
[14:29:39.857] <TB0> INFO: start marker: 0
[14:29:39.857] <TB0> INFO: stop marker: 0
[14:29:39.857] <TB0> INFO: overflow: 0
[14:29:39.857] <TB0> INFO: invalid 5bit words: 0
[14:29:39.857] <TB0> INFO: invalid XOR eye diagram: 0
[14:29:39.857] <TB0> INFO: frame (failed synchr.): 0
[14:29:39.857] <TB0> INFO: idle data (no TBM trl): 0
[14:29:39.857] <TB0> INFO: no data (only TBM hdr): 0
[14:29:39.857] <TB0> INFO: TBM errors: 0
[14:29:39.857] <TB0> INFO: flawed TBM headers: 0
[14:29:39.857] <TB0> INFO: flawed TBM trailers: 0
[14:29:39.857] <TB0> INFO: event ID mismatches: 0
[14:29:39.857] <TB0> INFO: ROC errors: 0
[14:29:39.858] <TB0> INFO: missing ROC header(s): 0
[14:29:39.858] <TB0> INFO: misplaced readback start: 0
[14:29:39.858] <TB0> INFO: Pixel decoding errors: 0
[14:29:39.858] <TB0> INFO: pixel data incomplete: 0
[14:29:39.858] <TB0> INFO: pixel address: 0
[14:29:39.858] <TB0> INFO: pulse height fill bit: 0
[14:29:39.858] <TB0> INFO: buffer corruption: 0
[14:29:40.048] <TB0> INFO: ######################################################################
[14:29:40.048] <TB0> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[14:29:40.048] <TB0> INFO: ######################################################################
[14:29:40.063] <TB0> INFO: scanning low vcal = 10
[14:29:40.305] <TB0> INFO: Expecting 41600 events.
[14:29:43.924] <TB0> INFO: 41600 events read in total (3027ms).
[14:29:43.924] <TB0> INFO: Test took 3861ms.
[14:29:43.926] <TB0> INFO: scanning low vcal = 20
[14:29:44.223] <TB0> INFO: Expecting 41600 events.
[14:29:47.842] <TB0> INFO: 41600 events read in total (3027ms).
[14:29:47.842] <TB0> INFO: Test took 3916ms.
[14:29:47.844] <TB0> INFO: scanning low vcal = 30
[14:29:48.135] <TB0> INFO: Expecting 41600 events.
[14:29:51.838] <TB0> INFO: 41600 events read in total (3111ms).
[14:29:51.839] <TB0> INFO: Test took 3995ms.
[14:29:51.841] <TB0> INFO: scanning low vcal = 40
[14:29:52.119] <TB0> INFO: Expecting 41600 events.
[14:29:56.110] <TB0> INFO: 41600 events read in total (3399ms).
[14:29:56.111] <TB0> INFO: Test took 4269ms.
[14:29:56.115] <TB0> INFO: scanning low vcal = 50
[14:29:56.392] <TB0> INFO: Expecting 41600 events.
[14:30:00.498] <TB0> INFO: 41600 events read in total (3514ms).
[14:30:00.499] <TB0> INFO: Test took 4384ms.
[14:30:00.502] <TB0> INFO: scanning low vcal = 60
[14:30:00.779] <TB0> INFO: Expecting 41600 events.
[14:30:04.814] <TB0> INFO: 41600 events read in total (3443ms).
[14:30:04.815] <TB0> INFO: Test took 4313ms.
[14:30:04.818] <TB0> INFO: scanning low vcal = 70
[14:30:05.095] <TB0> INFO: Expecting 41600 events.
[14:30:09.144] <TB0> INFO: 41600 events read in total (3457ms).
[14:30:09.145] <TB0> INFO: Test took 4327ms.
[14:30:09.148] <TB0> INFO: scanning low vcal = 80
[14:30:09.425] <TB0> INFO: Expecting 41600 events.
[14:30:13.464] <TB0> INFO: 41600 events read in total (3447ms).
[14:30:13.465] <TB0> INFO: Test took 4317ms.
[14:30:13.468] <TB0> INFO: scanning low vcal = 90
[14:30:13.746] <TB0> INFO: Expecting 41600 events.
[14:30:17.753] <TB0> INFO: 41600 events read in total (3415ms).
[14:30:17.753] <TB0> INFO: Test took 4285ms.
[14:30:17.757] <TB0> INFO: scanning low vcal = 100
[14:30:18.034] <TB0> INFO: Expecting 41600 events.
[14:30:22.062] <TB0> INFO: 41600 events read in total (3436ms).
[14:30:22.063] <TB0> INFO: Test took 4306ms.
[14:30:22.066] <TB0> INFO: scanning low vcal = 110
[14:30:22.344] <TB0> INFO: Expecting 41600 events.
[14:30:26.365] <TB0> INFO: 41600 events read in total (3429ms).
[14:30:26.365] <TB0> INFO: Test took 4299ms.
[14:30:26.368] <TB0> INFO: scanning low vcal = 120
[14:30:26.646] <TB0> INFO: Expecting 41600 events.
[14:30:30.699] <TB0> INFO: 41600 events read in total (3461ms).
[14:30:30.700] <TB0> INFO: Test took 4332ms.
[14:30:30.702] <TB0> INFO: scanning low vcal = 130
[14:30:30.980] <TB0> INFO: Expecting 41600 events.
[14:30:34.971] <TB0> INFO: 41600 events read in total (3399ms).
[14:30:34.971] <TB0> INFO: Test took 4268ms.
[14:30:34.975] <TB0> INFO: scanning low vcal = 140
[14:30:35.252] <TB0> INFO: Expecting 41600 events.
[14:30:39.277] <TB0> INFO: 41600 events read in total (3434ms).
[14:30:39.278] <TB0> INFO: Test took 4303ms.
[14:30:39.281] <TB0> INFO: scanning low vcal = 150
[14:30:39.558] <TB0> INFO: Expecting 41600 events.
[14:30:43.595] <TB0> INFO: 41600 events read in total (3445ms).
[14:30:43.596] <TB0> INFO: Test took 4315ms.
[14:30:43.599] <TB0> INFO: scanning low vcal = 160
[14:30:43.876] <TB0> INFO: Expecting 41600 events.
[14:30:47.908] <TB0> INFO: 41600 events read in total (3440ms).
[14:30:47.909] <TB0> INFO: Test took 4310ms.
[14:30:47.912] <TB0> INFO: scanning low vcal = 170
[14:30:48.188] <TB0> INFO: Expecting 41600 events.
[14:30:52.187] <TB0> INFO: 41600 events read in total (3407ms).
[14:30:52.188] <TB0> INFO: Test took 4275ms.
[14:30:52.193] <TB0> INFO: scanning low vcal = 180
[14:30:52.467] <TB0> INFO: Expecting 41600 events.
[14:30:56.462] <TB0> INFO: 41600 events read in total (3403ms).
[14:30:56.463] <TB0> INFO: Test took 4270ms.
[14:30:56.466] <TB0> INFO: scanning low vcal = 190
[14:30:56.744] <TB0> INFO: Expecting 41600 events.
[14:31:00.788] <TB0> INFO: 41600 events read in total (3452ms).
[14:31:00.789] <TB0> INFO: Test took 4323ms.
[14:31:00.792] <TB0> INFO: scanning low vcal = 200
[14:31:01.069] <TB0> INFO: Expecting 41600 events.
[14:31:05.062] <TB0> INFO: 41600 events read in total (3401ms).
[14:31:05.063] <TB0> INFO: Test took 4271ms.
[14:31:05.066] <TB0> INFO: scanning low vcal = 210
[14:31:05.343] <TB0> INFO: Expecting 41600 events.
[14:31:09.368] <TB0> INFO: 41600 events read in total (3433ms).
[14:31:09.369] <TB0> INFO: Test took 4303ms.
[14:31:09.372] <TB0> INFO: scanning low vcal = 220
[14:31:09.650] <TB0> INFO: Expecting 41600 events.
[14:31:13.706] <TB0> INFO: 41600 events read in total (3464ms).
[14:31:13.706] <TB0> INFO: Test took 4334ms.
[14:31:13.710] <TB0> INFO: scanning low vcal = 230
[14:31:13.987] <TB0> INFO: Expecting 41600 events.
[14:31:18.052] <TB0> INFO: 41600 events read in total (3474ms).
[14:31:18.052] <TB0> INFO: Test took 4342ms.
[14:31:18.055] <TB0> INFO: scanning low vcal = 240
[14:31:18.332] <TB0> INFO: Expecting 41600 events.
[14:31:22.393] <TB0> INFO: 41600 events read in total (3469ms).
[14:31:22.394] <TB0> INFO: Test took 4338ms.
[14:31:22.397] <TB0> INFO: scanning low vcal = 250
[14:31:22.675] <TB0> INFO: Expecting 41600 events.
[14:31:26.726] <TB0> INFO: 41600 events read in total (3459ms).
[14:31:26.727] <TB0> INFO: Test took 4330ms.
[14:31:26.731] <TB0> INFO: scanning high vcal = 30 (= 210 in low range)
[14:31:27.007] <TB0> INFO: Expecting 41600 events.
[14:31:31.067] <TB0> INFO: 41600 events read in total (3468ms).
[14:31:31.068] <TB0> INFO: Test took 4337ms.
[14:31:31.071] <TB0> INFO: scanning high vcal = 50 (= 350 in low range)
[14:31:31.349] <TB0> INFO: Expecting 41600 events.
[14:31:35.421] <TB0> INFO: 41600 events read in total (3480ms).
[14:31:35.422] <TB0> INFO: Test took 4351ms.
[14:31:35.425] <TB0> INFO: scanning high vcal = 70 (= 490 in low range)
[14:31:35.703] <TB0> INFO: Expecting 41600 events.
[14:31:39.778] <TB0> INFO: 41600 events read in total (3483ms).
[14:31:39.779] <TB0> INFO: Test took 4354ms.
[14:31:39.782] <TB0> INFO: scanning high vcal = 90 (= 630 in low range)
[14:31:40.059] <TB0> INFO: Expecting 41600 events.
[14:31:43.985] <TB0> INFO: 41600 events read in total (3334ms).
[14:31:43.986] <TB0> INFO: Test took 4204ms.
[14:31:43.989] <TB0> INFO: scanning high vcal = 200 (= 1400 in low range)
[14:31:44.265] <TB0> INFO: Expecting 41600 events.
[14:31:48.214] <TB0> INFO: 41600 events read in total (3357ms).
[14:31:48.215] <TB0> INFO: Test took 4226ms.
[14:31:48.718] <TB0> INFO: PixTestGainPedestal::measure() done
[14:32:26.041] <TB0> INFO: PixTestGainPedestal::fit() done
[14:32:26.041] <TB0> INFO: non-linearity mean: 0.930 0.938 1.012 0.922 0.972 1.044 0.942 0.947 0.978 0.895 0.943 0.947 0.940 0.936 0.961 0.966
[14:32:26.041] <TB0> INFO: non-linearity RMS: 0.121 0.101 0.179 0.111 0.014 0.140 0.076 0.151 0.005 0.162 0.076 0.119 0.074 0.103 0.040 0.156
[14:32:26.041] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C0.dat
[14:32:26.062] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C1.dat
[14:32:26.075] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C2.dat
[14:32:26.088] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C3.dat
[14:32:26.101] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C4.dat
[14:32:26.114] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C5.dat
[14:32:26.127] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C6.dat
[14:32:26.140] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C7.dat
[14:32:26.153] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C8.dat
[14:32:26.166] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C9.dat
[14:32:26.179] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C10.dat
[14:32:26.191] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C11.dat
[14:32:26.204] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C12.dat
[14:32:26.217] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C13.dat
[14:32:26.230] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C14.dat
[14:32:26.243] <TB0> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1044_FullQualification_2016-10-22_10h41m_1477125660//003_Fulltest_p17//phCalibrationFitErr35_C15.dat
[14:32:26.256] <TB0> INFO: PixTestGainPedestal::fullTest() done, duration: 166 seconds
[14:32:26.256] <TB0> INFO: Decoding statistics:
[14:32:26.256] <TB0> INFO: General information:
[14:32:26.256] <TB0> INFO: 16bit words read: 3233620
[14:32:26.256] <TB0> INFO: valid events total: 332800
[14:32:26.256] <TB0> INFO: empty events: 5464
[14:32:26.256] <TB0> INFO: valid events with pixels: 327336
[14:32:26.256] <TB0> INFO: valid pixel hits: 618410
[14:32:26.256] <TB0> INFO: Event errors: 0
[14:32:26.256] <TB0> INFO: start marker: 0
[14:32:26.256] <TB0> INFO: stop marker: 0
[14:32:26.256] <TB0> INFO: overflow: 0
[14:32:26.256] <TB0> INFO: invalid 5bit words: 0
[14:32:26.256] <TB0> INFO: invalid XOR eye diagram: 0
[14:32:26.256] <TB0> INFO: frame (failed synchr.): 0
[14:32:26.256] <TB0> INFO: idle data (no TBM trl): 0
[14:32:26.256] <TB0> INFO: no data (only TBM hdr): 0
[14:32:26.256] <TB0> INFO: TBM errors: 0
[14:32:26.256] <TB0> INFO: flawed TBM headers: 0
[14:32:26.256] <TB0> INFO: flawed TBM trailers: 0
[14:32:26.256] <TB0> INFO: event ID mismatches: 0
[14:32:26.256] <TB0> INFO: ROC errors: 0
[14:32:26.256] <TB0> INFO: missing ROC header(s): 0
[14:32:26.256] <TB0> INFO: misplaced readback start: 0
[14:32:26.256] <TB0> INFO: Pixel decoding errors: 0
[14:32:26.256] <TB0> INFO: pixel data incomplete: 0
[14:32:26.256] <TB0> INFO: pixel address: 0
[14:32:26.256] <TB0> INFO: pulse height fill bit: 0
[14:32:26.256] <TB0> INFO: buffer corruption: 0
[14:32:26.271] <TB0> INFO: Decoding statistics:
[14:32:26.271] <TB0> INFO: General information:
[14:32:26.271] <TB0> INFO: 16bit words read: 3363028
[14:32:26.271] <TB0> INFO: valid events total: 353536
[14:32:26.271] <TB0> INFO: empty events: 23704
[14:32:26.271] <TB0> INFO: valid events with pixels: 329832
[14:32:26.271] <TB0> INFO: valid pixel hits: 620906
[14:32:26.271] <TB0> INFO: Event errors: 0
[14:32:26.271] <TB0> INFO: start marker: 0
[14:32:26.271] <TB0> INFO: stop marker: 0
[14:32:26.271] <TB0> INFO: overflow: 0
[14:32:26.271] <TB0> INFO: invalid 5bit words: 0
[14:32:26.271] <TB0> INFO: invalid XOR eye diagram: 0
[14:32:26.271] <TB0> INFO: frame (failed synchr.): 0
[14:32:26.271] <TB0> INFO: idle data (no TBM trl): 0
[14:32:26.271] <TB0> INFO: no data (only TBM hdr): 0
[14:32:26.271] <TB0> INFO: TBM errors: 0
[14:32:26.271] <TB0> INFO: flawed TBM headers: 0
[14:32:26.271] <TB0> INFO: flawed TBM trailers: 0
[14:32:26.271] <TB0> INFO: event ID mismatches: 0
[14:32:26.271] <TB0> INFO: ROC errors: 0
[14:32:26.271] <TB0> INFO: missing ROC header(s): 0
[14:32:26.271] <TB0> INFO: misplaced readback start: 0
[14:32:26.271] <TB0> INFO: Pixel decoding errors: 0
[14:32:26.271] <TB0> INFO: pixel data incomplete: 0
[14:32:26.271] <TB0> INFO: pixel address: 0
[14:32:26.271] <TB0> INFO: pulse height fill bit: 0
[14:32:26.271] <TB0> INFO: buffer corruption: 0
[14:32:26.271] <TB0> INFO: enter test to run
[14:32:26.271] <TB0> INFO: test: exit no parameter change
[14:32:26.388] <TB0> QUIET: Connection to board 71 closed.
[14:32:26.389] <TB0> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud