Test Date: 2016-10-22 10:41
Analysis date: 2016-10-24 09:51
Logfile
LogfileView
[11:33:12.230] <TB3> INFO: *** Welcome to pxar ***
[11:33:12.230] <TB3> INFO: *** Today: 2016/10/22
[11:33:12.236] <TB3> INFO: *** Version: c8ba-dirty
[11:33:12.236] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C15.dat
[11:33:12.236] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//tbmParameters_C1b.dat
[11:33:12.236] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//defaultMaskFile.dat
[11:33:12.237] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters_C15.dat
[11:33:12.305] <TB3> INFO: clk: 4
[11:33:12.305] <TB3> INFO: ctr: 4
[11:33:12.305] <TB3> INFO: sda: 19
[11:33:12.305] <TB3> INFO: tin: 9
[11:33:12.305] <TB3> INFO: level: 15
[11:33:12.305] <TB3> INFO: triggerdelay: 0
[11:33:12.305] <TB3> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[11:33:12.305] <TB3> INFO: Log level: INFO
[11:33:12.313] <TB3> INFO: Found DTB DTB_WWVASW
[11:33:12.322] <TB3> QUIET: Connection to board DTB_WWVASW opened.
[11:33:12.324] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 126
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWVASW
MAC address: 40D85511807E
Hostname: pixelDTB126
Comment:
------------------------------------------------------
[11:33:12.326] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[11:33:13.861] <TB3> INFO: DUT info:
[11:33:13.861] <TB3> INFO: The DUT currently contains the following objects:
[11:33:13.861] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[11:33:13.861] <TB3> INFO: TBM Core alpha (0): 7 registers set
[11:33:13.861] <TB3> INFO: TBM Core beta (1): 7 registers set
[11:33:13.862] <TB3> INFO: TBM Core alpha (2): 7 registers set
[11:33:13.862] <TB3> INFO: TBM Core beta (3): 7 registers set
[11:33:13.862] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[11:33:13.862] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:13.862] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:33:14.263] <TB3> INFO: enter 'restricted' command line mode
[11:33:14.264] <TB3> INFO: enter test to run
[11:33:14.264] <TB3> INFO: test: pretest no parameter change
[11:33:14.264] <TB3> INFO: running: pretest
[11:33:14.271] <TB3> INFO: ######################################################################
[11:33:14.271] <TB3> INFO: PixTestPretest::doTest()
[11:33:14.271] <TB3> INFO: ######################################################################
[11:33:14.272] <TB3> INFO: ----------------------------------------------------------------------
[11:33:14.272] <TB3> INFO: PixTestPretest::programROC()
[11:33:14.272] <TB3> INFO: ----------------------------------------------------------------------
[11:33:32.287] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:33:32.287] <TB3> INFO: IA differences per ROC: 19.3 16.9 18.5 18.5 20.1 19.3 21.7 18.5 20.1 16.9 16.9 18.5 19.3 18.5 20.1 20.1
[11:33:32.350] <TB3> INFO: ----------------------------------------------------------------------
[11:33:32.350] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:33:32.350] <TB3> INFO: ----------------------------------------------------------------------
[11:33:53.641] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 385.9 mA = 24.1188 mA/ROC
[11:33:53.641] <TB3> INFO: i(loss) [mA/ROC]: 20.1 20.1 20.1 19.3 19.3 20.1 20.1 21.7 20.1 20.9 20.1 20.1 19.3 19.3 20.1 19.3
[11:33:53.673] <TB3> INFO: ----------------------------------------------------------------------
[11:33:53.673] <TB3> INFO: PixTestPretest::findTiming()
[11:33:53.673] <TB3> INFO: ----------------------------------------------------------------------
[11:33:53.673] <TB3> INFO: PixTestCmd::init()
[11:33:54.253] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!

[11:34:25.476] <TB3> INFO: TBM phases: 160MHz: 7, 400MHz: 6, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[11:34:25.476] <TB3> INFO: (success/tries = 100/100), width = 4
[11:34:26.979] <TB3> INFO: ----------------------------------------------------------------------
[11:34:26.979] <TB3> INFO: PixTestPretest::findWorkingPixel()
[11:34:26.979] <TB3> INFO: ----------------------------------------------------------------------
[11:34:27.072] <TB3> INFO: Expecting 231680 events.
[11:34:36.982] <TB3> INFO: 231680 events read in total (9318ms).
[11:34:36.989] <TB3> INFO: Test took 10006ms.
[11:34:37.241] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:34:37.277] <TB3> INFO: ----------------------------------------------------------------------
[11:34:37.277] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[11:34:37.277] <TB3> INFO: ----------------------------------------------------------------------
[11:34:37.371] <TB3> INFO: Expecting 231680 events.
[11:34:47.472] <TB3> INFO: 231680 events read in total (9508ms).
[11:34:47.479] <TB3> INFO: Test took 10197ms.
[11:34:47.747] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[11:34:47.747] <TB3> INFO: CalDel: 110 108 91 121 108 91 108 100 107 110 104 108 86 99 107 95
[11:34:47.747] <TB3> INFO: VthrComp: 51 51 51 51 51 54 51 51 51 51 51 51 51 51 51 58
[11:34:47.751] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C0.dat
[11:34:47.751] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C1.dat
[11:34:47.752] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C2.dat
[11:34:47.752] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C3.dat
[11:34:47.752] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C4.dat
[11:34:47.752] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C5.dat
[11:34:47.753] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C6.dat
[11:34:47.753] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C7.dat
[11:34:47.753] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C8.dat
[11:34:47.753] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C9.dat
[11:34:47.753] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C10.dat
[11:34:47.753] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C11.dat
[11:34:47.754] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C12.dat
[11:34:47.754] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C13.dat
[11:34:47.754] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C14.dat
[11:34:47.754] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters_C15.dat
[11:34:47.754] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//tbmParameters_C0a.dat
[11:34:47.755] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//tbmParameters_C0b.dat
[11:34:47.755] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//tbmParameters_C1a.dat
[11:34:47.755] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//tbmParameters_C1b.dat
[11:34:47.755] <TB3> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[11:34:47.811] <TB3> INFO: enter test to run
[11:34:47.811] <TB3> INFO: test: FullTest no parameter change
[11:34:47.811] <TB3> INFO: running: fulltest
[11:34:47.811] <TB3> INFO: ######################################################################
[11:34:47.811] <TB3> INFO: PixTestFullTest::doTest()
[11:34:47.811] <TB3> INFO: ######################################################################
[11:34:47.812] <TB3> INFO: ######################################################################
[11:34:47.812] <TB3> INFO: PixTestAlive::doTest()
[11:34:47.812] <TB3> INFO: ######################################################################
[11:34:47.813] <TB3> INFO: ----------------------------------------------------------------------
[11:34:47.813] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:34:47.813] <TB3> INFO: ----------------------------------------------------------------------
[11:34:48.054] <TB3> INFO: Expecting 41600 events.
[11:34:51.586] <TB3> INFO: 41600 events read in total (2940ms).
[11:34:51.586] <TB3> INFO: Test took 3771ms.
[11:34:51.824] <TB3> INFO: PixTestAlive::aliveTest() done
[11:34:51.824] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[11:34:51.826] <TB3> INFO: ----------------------------------------------------------------------
[11:34:51.826] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:34:51.826] <TB3> INFO: ----------------------------------------------------------------------
[11:34:52.071] <TB3> INFO: Expecting 41600 events.
[11:34:55.200] <TB3> INFO: 41600 events read in total (2538ms).
[11:34:55.200] <TB3> INFO: Test took 3372ms.
[11:34:55.201] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:34:55.436] <TB3> INFO: PixTestAlive::maskTest() done
[11:34:55.437] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:34:55.438] <TB3> INFO: ----------------------------------------------------------------------
[11:34:55.438] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:34:55.438] <TB3> INFO: ----------------------------------------------------------------------
[11:34:55.687] <TB3> INFO: Expecting 41600 events.
[11:34:59.231] <TB3> INFO: 41600 events read in total (2952ms).
[11:34:59.232] <TB3> INFO: Test took 3791ms.
[11:34:59.471] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[11:34:59.471] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:34:59.471] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[11:34:59.471] <TB3> INFO: Decoding statistics:
[11:34:59.471] <TB3> INFO: General information:
[11:34:59.471] <TB3> INFO: 16bit words read: 0
[11:34:59.471] <TB3> INFO: valid events total: 0
[11:34:59.471] <TB3> INFO: empty events: 0
[11:34:59.471] <TB3> INFO: valid events with pixels: 0
[11:34:59.471] <TB3> INFO: valid pixel hits: 0
[11:34:59.471] <TB3> INFO: Event errors: 0
[11:34:59.471] <TB3> INFO: start marker: 0
[11:34:59.471] <TB3> INFO: stop marker: 0
[11:34:59.471] <TB3> INFO: overflow: 0
[11:34:59.471] <TB3> INFO: invalid 5bit words: 0
[11:34:59.471] <TB3> INFO: invalid XOR eye diagram: 0
[11:34:59.471] <TB3> INFO: frame (failed synchr.): 0
[11:34:59.471] <TB3> INFO: idle data (no TBM trl): 0
[11:34:59.472] <TB3> INFO: no data (only TBM hdr): 0
[11:34:59.472] <TB3> INFO: TBM errors: 0
[11:34:59.472] <TB3> INFO: flawed TBM headers: 0
[11:34:59.472] <TB3> INFO: flawed TBM trailers: 0
[11:34:59.472] <TB3> INFO: event ID mismatches: 0
[11:34:59.472] <TB3> INFO: ROC errors: 0
[11:34:59.472] <TB3> INFO: missing ROC header(s): 0
[11:34:59.472] <TB3> INFO: misplaced readback start: 0
[11:34:59.472] <TB3> INFO: Pixel decoding errors: 0
[11:34:59.472] <TB3> INFO: pixel data incomplete: 0
[11:34:59.472] <TB3> INFO: pixel address: 0
[11:34:59.472] <TB3> INFO: pulse height fill bit: 0
[11:34:59.472] <TB3> INFO: buffer corruption: 0
[11:34:59.479] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C15.dat
[11:34:59.480] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[11:34:59.480] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[11:34:59.480] <TB3> INFO: ######################################################################
[11:34:59.480] <TB3> INFO: PixTestReadback::doTest()
[11:34:59.480] <TB3> INFO: ######################################################################
[11:34:59.480] <TB3> INFO: ----------------------------------------------------------------------
[11:34:59.480] <TB3> INFO: PixTestReadback::CalibrateVd()
[11:34:59.480] <TB3> INFO: ----------------------------------------------------------------------
[11:35:09.468] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C0.dat
[11:35:09.468] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C1.dat
[11:35:09.468] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C2.dat
[11:35:09.468] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C3.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C4.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C5.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C6.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C7.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C8.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C9.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C10.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C11.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C12.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C13.dat
[11:35:09.469] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C14.dat
[11:35:09.470] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C15.dat
[11:35:09.505] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:35:09.505] <TB3> INFO: ----------------------------------------------------------------------
[11:35:09.506] <TB3> INFO: PixTestReadback::CalibrateVa()
[11:35:09.506] <TB3> INFO: ----------------------------------------------------------------------
[11:35:19.445] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C0.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C1.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C2.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C3.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C4.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C5.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C6.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C7.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C8.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C9.dat
[11:35:19.446] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C10.dat
[11:35:19.447] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C11.dat
[11:35:19.447] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C12.dat
[11:35:19.447] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C13.dat
[11:35:19.447] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C14.dat
[11:35:19.447] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C15.dat
[11:35:19.479] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:35:19.479] <TB3> INFO: ----------------------------------------------------------------------
[11:35:19.479] <TB3> INFO: PixTestReadback::readbackVbg()
[11:35:19.479] <TB3> INFO: ----------------------------------------------------------------------
[11:35:27.151] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:35:27.151] <TB3> INFO: ----------------------------------------------------------------------
[11:35:27.152] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[11:35:27.152] <TB3> INFO: ----------------------------------------------------------------------
[11:35:27.152] <TB3> INFO: Vbg will be calibrated using Vd calibration
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 149.8calibrated Vbg = 1.19822 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 153.6calibrated Vbg = 1.19896 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 153.9calibrated Vbg = 1.19036 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 156.1calibrated Vbg = 1.19397 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 153.6calibrated Vbg = 1.19118 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 159calibrated Vbg = 1.19385 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 160.5calibrated Vbg = 1.19582 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 169.3calibrated Vbg = 1.2005 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 153.5calibrated Vbg = 1.19894 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 150.6calibrated Vbg = 1.18619 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 158calibrated Vbg = 1.18274 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 160.7calibrated Vbg = 1.18293 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 163.3calibrated Vbg = 1.1949 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 155.8calibrated Vbg = 1.19037 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 153.2calibrated Vbg = 1.19359 :::*/*/*/*/
[11:35:27.152] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 156.9calibrated Vbg = 1.19351 :::*/*/*/*/
[11:35:27.155] <TB3> INFO: ----------------------------------------------------------------------
[11:35:27.155] <TB3> INFO: PixTestReadback::CalibrateIa()
[11:35:27.155] <TB3> INFO: ----------------------------------------------------------------------
[11:38:07.915] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C0.dat
[11:38:07.915] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C1.dat
[11:38:07.915] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C2.dat
[11:38:07.915] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C3.dat
[11:38:07.915] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C4.dat
[11:38:07.915] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C5.dat
[11:38:07.915] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C6.dat
[11:38:07.915] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C7.dat
[11:38:07.915] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C8.dat
[11:38:07.916] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C9.dat
[11:38:07.916] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C10.dat
[11:38:07.916] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C11.dat
[11:38:07.916] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C12.dat
[11:38:07.916] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C13.dat
[11:38:07.916] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C14.dat
[11:38:07.916] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//readbackCal_C15.dat
[11:38:07.943] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[11:38:07.944] <TB3> INFO: PixTestReadback::doTest() done
[11:38:07.944] <TB3> INFO: Decoding statistics:
[11:38:07.944] <TB3> INFO: General information:
[11:38:07.944] <TB3> INFO: 16bit words read: 1536
[11:38:07.944] <TB3> INFO: valid events total: 256
[11:38:07.944] <TB3> INFO: empty events: 256
[11:38:07.944] <TB3> INFO: valid events with pixels: 0
[11:38:07.944] <TB3> INFO: valid pixel hits: 0
[11:38:07.944] <TB3> INFO: Event errors: 0
[11:38:07.944] <TB3> INFO: start marker: 0
[11:38:07.944] <TB3> INFO: stop marker: 0
[11:38:07.944] <TB3> INFO: overflow: 0
[11:38:07.944] <TB3> INFO: invalid 5bit words: 0
[11:38:07.944] <TB3> INFO: invalid XOR eye diagram: 0
[11:38:07.944] <TB3> INFO: frame (failed synchr.): 0
[11:38:07.944] <TB3> INFO: idle data (no TBM trl): 0
[11:38:07.944] <TB3> INFO: no data (only TBM hdr): 0
[11:38:07.944] <TB3> INFO: TBM errors: 0
[11:38:07.944] <TB3> INFO: flawed TBM headers: 0
[11:38:07.944] <TB3> INFO: flawed TBM trailers: 0
[11:38:07.944] <TB3> INFO: event ID mismatches: 0
[11:38:07.944] <TB3> INFO: ROC errors: 0
[11:38:07.945] <TB3> INFO: missing ROC header(s): 0
[11:38:07.945] <TB3> INFO: misplaced readback start: 0
[11:38:07.945] <TB3> INFO: Pixel decoding errors: 0
[11:38:07.945] <TB3> INFO: pixel data incomplete: 0
[11:38:07.945] <TB3> INFO: pixel address: 0
[11:38:07.945] <TB3> INFO: pulse height fill bit: 0
[11:38:07.945] <TB3> INFO: buffer corruption: 0
[11:38:07.996] <TB3> INFO: ######################################################################
[11:38:07.996] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:38:07.996] <TB3> INFO: ######################################################################
[11:38:07.999] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[11:38:08.029] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[11:38:08.029] <TB3> INFO: run 1 of 1
[11:38:08.271] <TB3> INFO: Expecting 3120000 events.
[11:38:39.090] <TB3> INFO: 667470 events read in total (30227ms).
[11:38:51.311] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (207) != TBM ID (129)

[11:38:51.452] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 207 207 129 207 207 207 207 207

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

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

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d3 8040 4700 4701 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0cd 80c0 4701 4701 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ce 8000 4700 4700 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4701 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d0 80b1 4600 4600 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d1 80c0 4601 4601 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d2 8000 4600 4600 262 23ef e022 c000

[11:38:51.452] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 32 readouts!

[11:38:51.452] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 32 readouts!

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

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e2 8000 4600 4600 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dc 80b1 4600 4600 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dd 80c0 4600 4600 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0de 8000 4600 4600 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0df 8040 4702 4702 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e0 80b1 4700 4700 262 23ef e022 c000

[11:38:51.452] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e1 80c0 4601 4601 262 23ef e022 c000

[11:39:09.168] <TB3> INFO: 1332630 events read in total (60306ms).
[11:39:21.363] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (23) != TBM ID (129)

[11:39:21.503] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 23 23 129 23 23 23 23 23

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

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

[11:39:21.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01b 8040 4601 4c4 21ef 4601 4c4 21ef e022 c000

[11:39:21.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a015 80c0 4600 4c4 21ef 4700 4c4 21ef e022 c000

[11:39:21.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a016 8000 4600 4c4 21ef 4700 4c4 21ef e022 c000

[11:39:21.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4701 21ef 4700 4c4 21ef e022 c000

[11:39:21.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a018 80b1 4700 4c4 21ef 4700 4c4 21ef e022 c000

[11:39:21.507] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a019 80c0 4701 4c4 21ef 4601 4c4 21ef e022 c000

[11:39:21.508] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a01a 8000 4601 4c4 21ef 4601 4c4 21ef e022 c000

[11:39:39.443] <TB3> INFO: 1995615 events read in total (90580ms).
[11:39:51.641] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (224) != TBM ID (129)

[11:39:51.782] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 224 224 129 224 224 224 224 224

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

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

[11:39:51.787] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e4 80b1 4600 824 29ef 4700 824 29ef e022 c000

[11:39:51.787] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0de 8000 4600 824 29ef 4700 824 29ef e022 c000

[11:39:51.787] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0df 8040 4702 824 29ef 4702 824 29ed e022 c000

[11:39:51.787] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4701 29ef 4700 824 29ef e022 c000

[11:39:51.787] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e1 80c0 4601 824 29ef 4701 824 29ef e022 c000

[11:39:51.787] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e2 8000 4600 824 29ef 4700 824 29ed e022 c000

[11:39:51.787] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e3 8040 4600 824 29ef 4601 824 29ef e022 c000

[11:40:09.274] <TB3> INFO: 2659165 events read in total (120411ms).
[11:40:17.838] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (222) != TBM ID (129)

[11:40:17.984] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 222 222 129 222 222 222 222 222

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

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

[11:40:17.985] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e2 8000 4700 a86 23ef 4600 a86 23ef e022 c000

[11:40:17.985] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dc 80b1 4700 a86 23ef 4600 e022 c000

[11:40:17.985] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dd 80c0 4600 a86 23ef 4700 e022 c000

[11:40:17.985] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4601 4701 23ef 4600 a86 23ef e022 c000

[11:40:17.985] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0df 8040 4602 a86 23ef 4602 e022 c000

[11:40:17.985] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e0 80b1 4600 a86 23ef 4600 e022 c000

[11:40:17.985] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e1 80c0 4701 a86 23ef 4701 a86 23ef e022 c000

[11:40:30.316] <TB3> INFO: 3120000 events read in total (141454ms).
[11:40:30.396] <TB3> INFO: Test took 142368ms.
[11:40:53.018] <TB3> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 165 seconds
[11:40:53.018] <TB3> INFO: number of dead bumps (per ROC): 0 0 0 1 1 0 1 0 0 0 0 0 0 0 0 1
[11:40:53.019] <TB3> INFO: separation cut (per ROC): 105 100 105 98 103 113 102 114 100 106 97 111 112 105 104 111
[11:40:53.019] <TB3> INFO: Decoding statistics:
[11:40:53.019] <TB3> INFO: General information:
[11:40:53.019] <TB3> INFO: 16bit words read: 0
[11:40:53.019] <TB3> INFO: valid events total: 0
[11:40:53.019] <TB3> INFO: empty events: 0
[11:40:53.019] <TB3> INFO: valid events with pixels: 0
[11:40:53.019] <TB3> INFO: valid pixel hits: 0
[11:40:53.019] <TB3> INFO: Event errors: 0
[11:40:53.019] <TB3> INFO: start marker: 0
[11:40:53.019] <TB3> INFO: stop marker: 0
[11:40:53.019] <TB3> INFO: overflow: 0
[11:40:53.019] <TB3> INFO: invalid 5bit words: 0
[11:40:53.019] <TB3> INFO: invalid XOR eye diagram: 0
[11:40:53.019] <TB3> INFO: frame (failed synchr.): 0
[11:40:53.019] <TB3> INFO: idle data (no TBM trl): 0
[11:40:53.019] <TB3> INFO: no data (only TBM hdr): 0
[11:40:53.019] <TB3> INFO: TBM errors: 0
[11:40:53.019] <TB3> INFO: flawed TBM headers: 0
[11:40:53.019] <TB3> INFO: flawed TBM trailers: 0
[11:40:53.019] <TB3> INFO: event ID mismatches: 0
[11:40:53.019] <TB3> INFO: ROC errors: 0
[11:40:53.019] <TB3> INFO: missing ROC header(s): 0
[11:40:53.019] <TB3> INFO: misplaced readback start: 0
[11:40:53.019] <TB3> INFO: Pixel decoding errors: 0
[11:40:53.019] <TB3> INFO: pixel data incomplete: 0
[11:40:53.019] <TB3> INFO: pixel address: 0
[11:40:53.019] <TB3> INFO: pulse height fill bit: 0
[11:40:53.019] <TB3> INFO: buffer corruption: 0
[11:40:53.068] <TB3> INFO: ######################################################################
[11:40:53.068] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:40:53.068] <TB3> INFO: ######################################################################
[11:40:53.068] <TB3> INFO: ----------------------------------------------------------------------
[11:40:53.068] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:40:53.068] <TB3> INFO: ----------------------------------------------------------------------
[11:40:53.068] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[11:40:53.084] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[11:40:53.084] <TB3> INFO: run 1 of 1
[11:40:53.356] <TB3> INFO: Expecting 36608000 events.
[11:41:16.880] <TB3> INFO: 675350 events read in total (22932ms).
[11:41:39.511] <TB3> INFO: 1338800 events read in total (45563ms).
[11:42:02.429] <TB3> INFO: 2003250 events read in total (68481ms).
[11:42:25.012] <TB3> INFO: 2665900 events read in total (91064ms).
[11:42:47.657] <TB3> INFO: 3325650 events read in total (113709ms).
[11:43:09.970] <TB3> INFO: 3984950 events read in total (136022ms).
[11:43:32.554] <TB3> INFO: 4643900 events read in total (158606ms).
[11:43:55.193] <TB3> INFO: 5304000 events read in total (181245ms).
[11:44:17.696] <TB3> INFO: 5963800 events read in total (203748ms).
[11:44:40.591] <TB3> INFO: 6623200 events read in total (226643ms).
[11:45:03.629] <TB3> INFO: 7283100 events read in total (249681ms).
[11:45:26.190] <TB3> INFO: 7943350 events read in total (272242ms).
[11:45:48.766] <TB3> INFO: 8604250 events read in total (294818ms).
[11:46:11.688] <TB3> INFO: 9264000 events read in total (317740ms).
[11:46:34.242] <TB3> INFO: 9923100 events read in total (340294ms).
[11:46:56.873] <TB3> INFO: 10582300 events read in total (362925ms).
[11:47:19.782] <TB3> INFO: 11239050 events read in total (385834ms).
[11:47:42.781] <TB3> INFO: 11896300 events read in total (408833ms).
[11:48:05.578] <TB3> INFO: 12554650 events read in total (431630ms).
[11:48:28.333] <TB3> INFO: 13213600 events read in total (454385ms).
[11:48:51.255] <TB3> INFO: 13871800 events read in total (477307ms).
[11:49:14.090] <TB3> INFO: 14527800 events read in total (500142ms).
[11:49:36.563] <TB3> INFO: 15184600 events read in total (522615ms).
[11:49:59.332] <TB3> INFO: 15839800 events read in total (545384ms).
[11:50:22.118] <TB3> INFO: 16496050 events read in total (568170ms).
[11:50:44.937] <TB3> INFO: 17150200 events read in total (590989ms).
[11:51:07.915] <TB3> INFO: 17806400 events read in total (613967ms).
[11:51:30.520] <TB3> INFO: 18460200 events read in total (636572ms).
[11:51:53.420] <TB3> INFO: 19116450 events read in total (659472ms).
[11:52:16.330] <TB3> INFO: 19770750 events read in total (682382ms).
[11:52:39.473] <TB3> INFO: 20424400 events read in total (705525ms).
[11:53:02.439] <TB3> INFO: 21078950 events read in total (728491ms).
[11:53:25.437] <TB3> INFO: 21729450 events read in total (751489ms).
[11:53:48.300] <TB3> INFO: 22379750 events read in total (774352ms).
[11:54:10.893] <TB3> INFO: 23030100 events read in total (796945ms).
[11:54:33.347] <TB3> INFO: 23681050 events read in total (819399ms).
[11:54:55.889] <TB3> INFO: 24332450 events read in total (841941ms).
[11:55:18.337] <TB3> INFO: 24982550 events read in total (864389ms).
[11:55:40.697] <TB3> INFO: 25634500 events read in total (886749ms).
[11:56:03.337] <TB3> INFO: 26288400 events read in total (909389ms).
[11:56:25.977] <TB3> INFO: 26941200 events read in total (932029ms).
[11:56:48.577] <TB3> INFO: 27593250 events read in total (954629ms).
[11:57:11.307] <TB3> INFO: 28244300 events read in total (977359ms).
[11:57:33.732] <TB3> INFO: 28895700 events read in total (999784ms).
[11:57:56.313] <TB3> INFO: 29545850 events read in total (1022365ms).
[11:58:18.908] <TB3> INFO: 30198050 events read in total (1044960ms).
[11:58:41.406] <TB3> INFO: 30850250 events read in total (1067458ms).
[11:59:03.970] <TB3> INFO: 31502200 events read in total (1090022ms).
[11:59:26.751] <TB3> INFO: 32153150 events read in total (1112803ms).
[11:59:49.110] <TB3> INFO: 32806100 events read in total (1135162ms).
[12:00:11.736] <TB3> INFO: 33461700 events read in total (1157788ms).
[12:00:34.581] <TB3> INFO: 34115500 events read in total (1180633ms).
[12:00:57.550] <TB3> INFO: 34770100 events read in total (1203602ms).
[12:01:20.122] <TB3> INFO: 35425600 events read in total (1226174ms).
[12:01:42.732] <TB3> INFO: 36085300 events read in total (1248784ms).
[12:02:00.755] <TB3> INFO: 36608000 events read in total (1266807ms).
[12:02:00.910] <TB3> INFO: Test took 1267826ms.
[12:02:01.521] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:03.922] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:05.940] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:08.256] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:10.236] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:11.656] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:13.090] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:14.527] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:16.537] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:18.221] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:19.732] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:22.189] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:24.328] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:26.463] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:28.415] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:30.139] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:02:32.106] <TB3> INFO: PixTestScurves::scurves() done
[12:02:32.106] <TB3> INFO: Vcal mean: 112.37 110.26 117.74 111.81 106.30 124.55 115.39 130.77 104.71 110.88 101.81 117.27 119.82 110.80 114.18 121.46
[12:02:32.106] <TB3> INFO: Vcal RMS: 4.96 5.22 5.98 5.45 5.74 6.95 5.16 6.27 5.59 5.19 5.19 5.71 6.63 5.38 5.23 7.60
[12:02:32.106] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1299 seconds
[12:02:32.106] <TB3> INFO: Decoding statistics:
[12:02:32.106] <TB3> INFO: General information:
[12:02:32.106] <TB3> INFO: 16bit words read: 0
[12:02:32.106] <TB3> INFO: valid events total: 0
[12:02:32.106] <TB3> INFO: empty events: 0
[12:02:32.106] <TB3> INFO: valid events with pixels: 0
[12:02:32.106] <TB3> INFO: valid pixel hits: 0
[12:02:32.106] <TB3> INFO: Event errors: 0
[12:02:32.106] <TB3> INFO: start marker: 0
[12:02:32.106] <TB3> INFO: stop marker: 0
[12:02:32.106] <TB3> INFO: overflow: 0
[12:02:32.106] <TB3> INFO: invalid 5bit words: 0
[12:02:32.106] <TB3> INFO: invalid XOR eye diagram: 0
[12:02:32.106] <TB3> INFO: frame (failed synchr.): 0
[12:02:32.106] <TB3> INFO: idle data (no TBM trl): 0
[12:02:32.106] <TB3> INFO: no data (only TBM hdr): 0
[12:02:32.106] <TB3> INFO: TBM errors: 0
[12:02:32.106] <TB3> INFO: flawed TBM headers: 0
[12:02:32.106] <TB3> INFO: flawed TBM trailers: 0
[12:02:32.106] <TB3> INFO: event ID mismatches: 0
[12:02:32.106] <TB3> INFO: ROC errors: 0
[12:02:32.106] <TB3> INFO: missing ROC header(s): 0
[12:02:32.106] <TB3> INFO: misplaced readback start: 0
[12:02:32.106] <TB3> INFO: Pixel decoding errors: 0
[12:02:32.106] <TB3> INFO: pixel data incomplete: 0
[12:02:32.106] <TB3> INFO: pixel address: 0
[12:02:32.106] <TB3> INFO: pulse height fill bit: 0
[12:02:32.106] <TB3> INFO: buffer corruption: 0
[12:02:32.181] <TB3> INFO: ######################################################################
[12:02:32.181] <TB3> INFO: PixTestTrim::doTest()
[12:02:32.181] <TB3> INFO: ######################################################################
[12:02:32.183] <TB3> INFO: ----------------------------------------------------------------------
[12:02:32.183] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[12:02:32.183] <TB3> INFO: ----------------------------------------------------------------------
[12:02:32.224] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:02:32.224] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:02:32.238] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:02:32.238] <TB3> INFO: run 1 of 1
[12:02:32.478] <TB3> INFO: Expecting 5025280 events.
[12:03:03.040] <TB3> INFO: 824776 events read in total (29963ms).
[12:03:33.192] <TB3> INFO: 1646352 events read in total (60115ms).
[12:04:03.116] <TB3> INFO: 2464616 events read in total (90039ms).
[12:04:33.184] <TB3> INFO: 3280808 events read in total (120107ms).
[12:05:03.074] <TB3> INFO: 4094504 events read in total (149997ms).
[12:05:33.490] <TB3> INFO: 4907584 events read in total (180413ms).
[12:05:38.152] <TB3> INFO: 5025280 events read in total (185075ms).
[12:05:38.214] <TB3> INFO: Test took 185975ms.
[12:05:56.872] <TB3> INFO: ROC 0 VthrComp = 117
[12:05:56.872] <TB3> INFO: ROC 1 VthrComp = 108
[12:05:56.872] <TB3> INFO: ROC 2 VthrComp = 119
[12:05:56.872] <TB3> INFO: ROC 3 VthrComp = 110
[12:05:56.872] <TB3> INFO: ROC 4 VthrComp = 105
[12:05:56.873] <TB3> INFO: ROC 5 VthrComp = 132
[12:05:56.873] <TB3> INFO: ROC 6 VthrComp = 119
[12:05:56.873] <TB3> INFO: ROC 7 VthrComp = 133
[12:05:56.873] <TB3> INFO: ROC 8 VthrComp = 106
[12:05:56.873] <TB3> INFO: ROC 9 VthrComp = 113
[12:05:56.873] <TB3> INFO: ROC 10 VthrComp = 106
[12:05:56.873] <TB3> INFO: ROC 11 VthrComp = 123
[12:05:56.873] <TB3> INFO: ROC 12 VthrComp = 115
[12:05:56.873] <TB3> INFO: ROC 13 VthrComp = 110
[12:05:56.873] <TB3> INFO: ROC 14 VthrComp = 116
[12:05:56.873] <TB3> INFO: ROC 15 VthrComp = 126
[12:05:57.112] <TB3> INFO: Expecting 41600 events.
[12:06:00.586] <TB3> INFO: 41600 events read in total (2882ms).
[12:06:00.587] <TB3> INFO: Test took 3711ms.
[12:06:00.596] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:06:00.596] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:06:00.607] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:06:00.607] <TB3> INFO: run 1 of 1
[12:06:00.885] <TB3> INFO: Expecting 5025280 events.
[12:06:27.492] <TB3> INFO: 590704 events read in total (26015ms).
[12:06:52.936] <TB3> INFO: 1181928 events read in total (51459ms).
[12:07:18.500] <TB3> INFO: 1773120 events read in total (77023ms).
[12:07:44.196] <TB3> INFO: 2364408 events read in total (102719ms).
[12:08:10.183] <TB3> INFO: 2953184 events read in total (128706ms).
[12:08:35.813] <TB3> INFO: 3540120 events read in total (154336ms).
[12:09:01.713] <TB3> INFO: 4126312 events read in total (180236ms).
[12:09:27.177] <TB3> INFO: 4712240 events read in total (205700ms).
[12:09:41.299] <TB3> INFO: 5025280 events read in total (219822ms).
[12:09:41.400] <TB3> INFO: Test took 220792ms.
[12:10:07.435] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 60.7382 for pixel 19/1 mean/min/max = 46.0761/31.2886/60.8636
[12:10:07.436] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 63.9461 for pixel 2/1 mean/min/max = 49.2475/34.3983/64.0966
[12:10:07.436] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 62.2791 for pixel 3/57 mean/min/max = 46.5367/30.7769/62.2966
[12:10:07.436] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 64.601 for pixel 21/4 mean/min/max = 49.495/34.3584/64.6316
[12:10:07.437] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 62.9879 for pixel 51/71 mean/min/max = 48.7896/34.5229/63.0563
[12:10:07.437] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 60.7887 for pixel 10/76 mean/min/max = 46.0216/31.184/60.8592
[12:10:07.438] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 60.6055 for pixel 49/8 mean/min/max = 45.7355/30.8548/60.6162
[12:10:07.438] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 62.0688 for pixel 19/4 mean/min/max = 48.0073/33.3847/62.6299
[12:10:07.439] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 62.5849 for pixel 0/0 mean/min/max = 48.3672/33.9379/62.7966
[12:10:07.439] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 60.8056 for pixel 34/30 mean/min/max = 46.3879/31.8713/60.9044
[12:10:07.439] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 61.3672 for pixel 3/5 mean/min/max = 48.1987/34.9609/61.4366
[12:10:07.440] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 60.2856 for pixel 21/0 mean/min/max = 45.6113/30.9273/60.2952
[12:10:07.440] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 63.7107 for pixel 0/5 mean/min/max = 48.0377/31.4782/64.5971
[12:10:07.441] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 62.0129 for pixel 46/3 mean/min/max = 48.2891/34.2532/62.3249
[12:10:07.441] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 59.7331 for pixel 14/0 mean/min/max = 45.9784/32.1661/59.7908
[12:10:07.442] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 63.4417 for pixel 19/4 mean/min/max = 46.7911/29.9085/63.6737
[12:10:07.442] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:10:07.532] <TB3> INFO: Expecting 411648 events.
[12:10:16.863] <TB3> INFO: 411648 events read in total (8739ms).
[12:10:16.870] <TB3> INFO: Expecting 411648 events.
[12:10:26.098] <TB3> INFO: 411648 events read in total (8825ms).
[12:10:26.109] <TB3> INFO: Expecting 411648 events.
[12:10:35.474] <TB3> INFO: 411648 events read in total (8962ms).
[12:10:35.492] <TB3> INFO: Expecting 411648 events.
[12:10:44.881] <TB3> INFO: 411648 events read in total (8986ms).
[12:10:44.898] <TB3> INFO: Expecting 411648 events.
[12:10:54.258] <TB3> INFO: 411648 events read in total (8957ms).
[12:10:54.276] <TB3> INFO: Expecting 411648 events.
[12:11:03.630] <TB3> INFO: 411648 events read in total (8951ms).
[12:11:03.652] <TB3> INFO: Expecting 411648 events.
[12:11:12.963] <TB3> INFO: 411648 events read in total (8908ms).
[12:11:12.987] <TB3> INFO: Expecting 411648 events.
[12:11:22.410] <TB3> INFO: 411648 events read in total (9020ms).
[12:11:22.446] <TB3> INFO: Expecting 411648 events.
[12:11:31.689] <TB3> INFO: 411648 events read in total (8839ms).
[12:11:31.720] <TB3> INFO: Expecting 411648 events.
[12:11:41.026] <TB3> INFO: 411648 events read in total (8903ms).
[12:11:41.060] <TB3> INFO: Expecting 411648 events.
[12:11:50.365] <TB3> INFO: 411648 events read in total (8902ms).
[12:11:50.411] <TB3> INFO: Expecting 411648 events.
[12:11:59.806] <TB3> INFO: 411648 events read in total (8992ms).
[12:11:59.857] <TB3> INFO: Expecting 411648 events.
[12:12:09.191] <TB3> INFO: 411648 events read in total (8931ms).
[12:12:09.258] <TB3> INFO: Expecting 411648 events.
[12:12:18.607] <TB3> INFO: 411648 events read in total (8946ms).
[12:12:18.659] <TB3> INFO: Expecting 411648 events.
[12:12:28.122] <TB3> INFO: 411648 events read in total (9059ms).
[12:12:28.180] <TB3> INFO: Expecting 411648 events.
[12:12:37.420] <TB3> INFO: 411648 events read in total (8837ms).
[12:12:37.594] <TB3> INFO: Test took 150152ms.
[12:12:38.381] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[12:12:38.395] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:12:38.395] <TB3> INFO: run 1 of 1
[12:12:38.634] <TB3> INFO: Expecting 5025280 events.
[12:13:05.180] <TB3> INFO: 588984 events read in total (25954ms).
[12:13:30.933] <TB3> INFO: 1177704 events read in total (51707ms).
[12:13:56.884] <TB3> INFO: 1766632 events read in total (77658ms).
[12:14:22.808] <TB3> INFO: 2354904 events read in total (103582ms).
[12:14:48.799] <TB3> INFO: 2941912 events read in total (129573ms).
[12:15:14.782] <TB3> INFO: 3530968 events read in total (155556ms).
[12:15:40.968] <TB3> INFO: 4117160 events read in total (181742ms).
[12:16:06.839] <TB3> INFO: 4704808 events read in total (207613ms).
[12:16:21.665] <TB3> INFO: 5025280 events read in total (222439ms).
[12:16:21.824] <TB3> INFO: Test took 223430ms.
[12:16:44.494] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 5.186595 .. 146.963821
[12:16:44.733] <TB3> INFO: Expecting 208000 events.
[12:16:54.334] <TB3> INFO: 208000 events read in total (9009ms).
[12:16:54.336] <TB3> INFO: Test took 9841ms.
[12:16:54.393] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 5 .. 156 (-1/-1) hits flags = 528 (plus default)
[12:16:54.406] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:16:54.406] <TB3> INFO: run 1 of 1
[12:16:54.684] <TB3> INFO: Expecting 5058560 events.
[12:17:21.038] <TB3> INFO: 579232 events read in total (25762ms).
[12:17:46.721] <TB3> INFO: 1157816 events read in total (51446ms).
[12:18:12.350] <TB3> INFO: 1736224 events read in total (77074ms).
[12:18:38.287] <TB3> INFO: 2314880 events read in total (103011ms).
[12:19:03.659] <TB3> INFO: 2893560 events read in total (128383ms).
[12:19:29.308] <TB3> INFO: 3472552 events read in total (154032ms).
[12:19:54.663] <TB3> INFO: 4050560 events read in total (179387ms).
[12:20:20.011] <TB3> INFO: 4628952 events read in total (204735ms).
[12:20:39.581] <TB3> INFO: 5058560 events read in total (224305ms).
[12:20:39.701] <TB3> INFO: Test took 225295ms.
[12:21:05.685] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 27.969666 .. 47.378056
[12:21:05.923] <TB3> INFO: Expecting 208000 events.
[12:21:15.747] <TB3> INFO: 208000 events read in total (9232ms).
[12:21:15.748] <TB3> INFO: Test took 10062ms.
[12:21:15.796] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 57 (-1/-1) hits flags = 528 (plus default)
[12:21:15.812] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:21:15.812] <TB3> INFO: run 1 of 1
[12:21:16.091] <TB3> INFO: Expecting 1364480 events.
[12:21:44.708] <TB3> INFO: 650768 events read in total (28025ms).
[12:22:12.793] <TB3> INFO: 1301128 events read in total (56111ms).
[12:22:15.928] <TB3> INFO: 1364480 events read in total (59245ms).
[12:22:15.970] <TB3> INFO: Test took 60158ms.
[12:22:30.255] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 27.206643 .. 47.259139
[12:22:30.493] <TB3> INFO: Expecting 208000 events.
[12:22:40.390] <TB3> INFO: 208000 events read in total (9305ms).
[12:22:40.391] <TB3> INFO: Test took 10135ms.
[12:22:40.439] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 17 .. 57 (-1/-1) hits flags = 528 (plus default)
[12:22:40.452] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:22:40.452] <TB3> INFO: run 1 of 1
[12:22:40.730] <TB3> INFO: Expecting 1364480 events.
[12:23:08.488] <TB3> INFO: 651520 events read in total (27167ms).
[12:23:36.114] <TB3> INFO: 1302224 events read in total (54793ms).
[12:23:39.189] <TB3> INFO: 1364480 events read in total (57868ms).
[12:23:39.220] <TB3> INFO: Test took 58769ms.
[12:23:54.395] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 24.055054 .. 45.485938
[12:23:54.633] <TB3> INFO: Expecting 208000 events.
[12:24:04.703] <TB3> INFO: 208000 events read in total (9478ms).
[12:24:04.704] <TB3> INFO: Test took 10308ms.
[12:24:04.751] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 14 .. 55 (-1/-1) hits flags = 528 (plus default)
[12:24:04.764] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:24:04.764] <TB3> INFO: run 1 of 1
[12:24:05.043] <TB3> INFO: Expecting 1397760 events.
[12:24:33.187] <TB3> INFO: 670832 events read in total (27553ms).
[12:25:00.916] <TB3> INFO: 1341648 events read in total (55282ms).
[12:25:03.688] <TB3> INFO: 1397760 events read in total (58055ms).
[12:25:03.720] <TB3> INFO: Test took 58955ms.
[12:25:17.308] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:25:17.309] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[12:25:17.323] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:25:17.323] <TB3> INFO: run 1 of 1
[12:25:17.563] <TB3> INFO: Expecting 1364480 events.
[12:25:45.905] <TB3> INFO: 667472 events read in total (27751ms).
[12:26:14.450] <TB3> INFO: 1334336 events read in total (56297ms).
[12:26:16.104] <TB3> INFO: 1364480 events read in total (57950ms).
[12:26:16.132] <TB3> INFO: Test took 58810ms.
[12:26:29.929] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C0.dat
[12:26:29.929] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C1.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C2.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C3.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C4.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C5.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C6.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C7.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C8.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C9.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C10.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C11.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C12.dat
[12:26:29.930] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C13.dat
[12:26:29.931] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C14.dat
[12:26:29.931] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C15.dat
[12:26:29.931] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C0.dat
[12:26:29.937] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C1.dat
[12:26:29.942] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C2.dat
[12:26:29.947] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C3.dat
[12:26:29.952] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C4.dat
[12:26:29.957] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C5.dat
[12:26:29.961] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C6.dat
[12:26:29.966] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C7.dat
[12:26:29.971] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C8.dat
[12:26:29.976] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C9.dat
[12:26:29.981] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C10.dat
[12:26:29.986] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C11.dat
[12:26:29.990] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C12.dat
[12:26:29.995] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C13.dat
[12:26:29.000] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C14.dat
[12:26:30.005] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//trimParameters35_C15.dat
[12:26:30.009] <TB3> INFO: PixTestTrim::trimTest() done
[12:26:30.009] <TB3> INFO: vtrim: 137 123 143 121 115 133 141 142 119 134 139 127 115 129 119 135
[12:26:30.009] <TB3> INFO: vthrcomp: 117 108 119 110 105 132 119 133 106 113 106 123 115 110 116 126
[12:26:30.009] <TB3> INFO: vcal mean: 34.96 35.02 35.00 35.09 34.93 34.90 34.99 35.01 35.00 34.98 34.99 34.96 35.04 34.99 34.96 34.98
[12:26:30.009] <TB3> INFO: vcal RMS: 1.06 1.04 1.22 1.12 0.98 1.06 1.21 1.02 0.97 1.06 0.97 1.11 1.23 1.00 1.08 1.54
[12:26:30.009] <TB3> INFO: bits mean: 9.96 8.79 9.78 8.50 8.02 9.64 9.80 8.77 8.29 9.50 8.26 9.80 9.00 8.92 9.48 9.70
[12:26:30.009] <TB3> INFO: bits RMS: 2.54 2.45 2.68 2.61 2.72 2.69 2.72 2.70 2.70 2.70 2.64 2.68 2.88 2.51 2.68 2.80
[12:26:30.017] <TB3> INFO: ----------------------------------------------------------------------
[12:26:30.017] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[12:26:30.017] <TB3> INFO: ----------------------------------------------------------------------
[12:26:30.020] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[12:26:30.034] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:26:30.034] <TB3> INFO: run 1 of 1
[12:26:30.313] <TB3> INFO: Expecting 4160000 events.
[12:27:02.487] <TB3> INFO: 744735 events read in total (31582ms).
[12:27:34.470] <TB3> INFO: 1484145 events read in total (63565ms).
[12:28:06.363] <TB3> INFO: 2218910 events read in total (95458ms).
[12:28:38.548] <TB3> INFO: 2948265 events read in total (127643ms).
[12:29:10.255] <TB3> INFO: 3677985 events read in total (159350ms).
[12:29:31.389] <TB3> INFO: 4160000 events read in total (180484ms).
[12:29:31.565] <TB3> INFO: Test took 181531ms.
[12:29:59.631] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 255 (-1/-1) hits flags = 528 (plus default)
[12:29:59.644] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:29:59.644] <TB3> INFO: run 1 of 1
[12:29:59.881] <TB3> INFO: Expecting 5324800 events.
[12:30:30.460] <TB3> INFO: 669650 events read in total (29987ms).
[12:31:00.723] <TB3> INFO: 1336105 events read in total (60250ms).
[12:31:30.467] <TB3> INFO: 2000810 events read in total (89994ms).
[12:32:00.266] <TB3> INFO: 2663200 events read in total (119793ms).
[12:32:30.118] <TB3> INFO: 3323560 events read in total (149645ms).
[12:32:59.993] <TB3> INFO: 3982780 events read in total (179520ms).
[12:33:30.787] <TB3> INFO: 4642105 events read in total (210314ms).
[12:34:00.446] <TB3> INFO: 5305130 events read in total (239973ms).
[12:34:01.704] <TB3> INFO: 5324800 events read in total (241231ms).
[12:34:01.905] <TB3> INFO: Test took 242262ms.
[12:34:38.428] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 201 (-1/-1) hits flags = 528 (plus default)
[12:34:38.443] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:34:38.443] <TB3> INFO: run 1 of 1
[12:34:38.703] <TB3> INFO: Expecting 4201600 events.
[12:35:10.751] <TB3> INFO: 718860 events read in total (31457ms).
[12:35:42.143] <TB3> INFO: 1433020 events read in total (62849ms).
[12:36:13.182] <TB3> INFO: 2143170 events read in total (93888ms).
[12:36:44.467] <TB3> INFO: 2848705 events read in total (125173ms).
[12:37:15.314] <TB3> INFO: 3554110 events read in total (156020ms).
[12:37:43.650] <TB3> INFO: 4201600 events read in total (184356ms).
[12:37:43.898] <TB3> INFO: Test took 185456ms.
[12:38:09.824] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 200 (-1/-1) hits flags = 528 (plus default)
[12:38:09.838] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:38:09.838] <TB3> INFO: run 1 of 1
[12:38:10.109] <TB3> INFO: Expecting 4180800 events.
[12:38:42.120] <TB3> INFO: 720220 events read in total (31419ms).
[12:39:13.070] <TB3> INFO: 1435540 events read in total (62369ms).
[12:39:44.559] <TB3> INFO: 2146665 events read in total (93858ms).
[12:40:15.077] <TB3> INFO: 2853300 events read in total (124376ms).
[12:40:45.565] <TB3> INFO: 3560040 events read in total (154864ms).
[12:41:12.635] <TB3> INFO: 4180800 events read in total (181934ms).
[12:41:12.843] <TB3> INFO: Test took 183006ms.
[12:41:41.582] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[12:41:41.599] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:41:41.599] <TB3> INFO: run 1 of 1
[12:41:41.873] <TB3> INFO: Expecting 4160000 events.
[12:42:13.962] <TB3> INFO: 721300 events read in total (31497ms).
[12:42:45.081] <TB3> INFO: 1437845 events read in total (62616ms).
[12:43:15.637] <TB3> INFO: 2149990 events read in total (93173ms).
[12:43:46.938] <TB3> INFO: 2857600 events read in total (124473ms).
[12:44:17.903] <TB3> INFO: 3565435 events read in total (155438ms).
[12:44:44.029] <TB3> INFO: 4160000 events read in total (181564ms).
[12:44:44.118] <TB3> INFO: Test took 182519ms.
[12:45:11.083] <TB3> INFO: PixTestTrim::trimBitTest() done
[12:45:11.084] <TB3> INFO: PixTestTrim::doTest() done, duration: 2558 seconds
[12:45:11.084] <TB3> INFO: Decoding statistics:
[12:45:11.084] <TB3> INFO: General information:
[12:45:11.084] <TB3> INFO: 16bit words read: 0
[12:45:11.084] <TB3> INFO: valid events total: 0
[12:45:11.084] <TB3> INFO: empty events: 0
[12:45:11.084] <TB3> INFO: valid events with pixels: 0
[12:45:11.084] <TB3> INFO: valid pixel hits: 0
[12:45:11.084] <TB3> INFO: Event errors: 0
[12:45:11.084] <TB3> INFO: start marker: 0
[12:45:11.084] <TB3> INFO: stop marker: 0
[12:45:11.084] <TB3> INFO: overflow: 0
[12:45:11.084] <TB3> INFO: invalid 5bit words: 0
[12:45:11.084] <TB3> INFO: invalid XOR eye diagram: 0
[12:45:11.084] <TB3> INFO: frame (failed synchr.): 0
[12:45:11.084] <TB3> INFO: idle data (no TBM trl): 0
[12:45:11.084] <TB3> INFO: no data (only TBM hdr): 0
[12:45:11.084] <TB3> INFO: TBM errors: 0
[12:45:11.084] <TB3> INFO: flawed TBM headers: 0
[12:45:11.084] <TB3> INFO: flawed TBM trailers: 0
[12:45:11.084] <TB3> INFO: event ID mismatches: 0
[12:45:11.084] <TB3> INFO: ROC errors: 0
[12:45:11.084] <TB3> INFO: missing ROC header(s): 0
[12:45:11.084] <TB3> INFO: misplaced readback start: 0
[12:45:11.084] <TB3> INFO: Pixel decoding errors: 0
[12:45:11.084] <TB3> INFO: pixel data incomplete: 0
[12:45:11.084] <TB3> INFO: pixel address: 0
[12:45:11.084] <TB3> INFO: pulse height fill bit: 0
[12:45:11.084] <TB3> INFO: buffer corruption: 0
[12:45:11.697] <TB3> INFO: ######################################################################
[12:45:11.697] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:45:11.697] <TB3> INFO: ######################################################################
[12:45:11.934] <TB3> INFO: Expecting 41600 events.
[12:45:15.374] <TB3> INFO: 41600 events read in total (2848ms).
[12:45:15.375] <TB3> INFO: Test took 3676ms.
[12:45:15.814] <TB3> INFO: Expecting 41600 events.
[12:45:19.350] <TB3> INFO: 41600 events read in total (2945ms).
[12:45:19.351] <TB3> INFO: Test took 3773ms.
[12:45:19.643] <TB3> INFO: Expecting 41600 events.
[12:45:23.111] <TB3> INFO: 41600 events read in total (2877ms).
[12:45:23.112] <TB3> INFO: Test took 3734ms.
[12:45:23.401] <TB3> INFO: Expecting 41600 events.
[12:45:26.910] <TB3> INFO: 41600 events read in total (2918ms).
[12:45:26.911] <TB3> INFO: Test took 3775ms.
[12:45:27.201] <TB3> INFO: Expecting 41600 events.
[12:45:30.702] <TB3> INFO: 41600 events read in total (2909ms).
[12:45:30.703] <TB3> INFO: Test took 3767ms.
[12:45:30.993] <TB3> INFO: Expecting 41600 events.
[12:45:34.555] <TB3> INFO: 41600 events read in total (2970ms).
[12:45:34.556] <TB3> INFO: Test took 3829ms.
[12:45:34.845] <TB3> INFO: Expecting 41600 events.
[12:45:38.367] <TB3> INFO: 41600 events read in total (2930ms).
[12:45:38.368] <TB3> INFO: Test took 3788ms.
[12:45:38.659] <TB3> INFO: Expecting 41600 events.
[12:45:42.221] <TB3> INFO: 41600 events read in total (2970ms).
[12:45:42.222] <TB3> INFO: Test took 3828ms.
[12:45:42.515] <TB3> INFO: Expecting 41600 events.
[12:45:46.023] <TB3> INFO: 41600 events read in total (2916ms).
[12:45:46.024] <TB3> INFO: Test took 3774ms.
[12:45:46.316] <TB3> INFO: Expecting 41600 events.
[12:45:49.926] <TB3> INFO: 41600 events read in total (3017ms).
[12:45:49.927] <TB3> INFO: Test took 3876ms.
[12:45:50.216] <TB3> INFO: Expecting 41600 events.
[12:45:53.874] <TB3> INFO: 41600 events read in total (3066ms).
[12:45:53.874] <TB3> INFO: Test took 3923ms.
[12:45:54.164] <TB3> INFO: Expecting 41600 events.
[12:45:57.675] <TB3> INFO: 41600 events read in total (2920ms).
[12:45:57.676] <TB3> INFO: Test took 3778ms.
[12:45:57.966] <TB3> INFO: Expecting 41600 events.
[12:46:01.572] <TB3> INFO: 41600 events read in total (3015ms).
[12:46:01.572] <TB3> INFO: Test took 3872ms.
[12:46:01.862] <TB3> INFO: Expecting 41600 events.
[12:46:05.469] <TB3> INFO: 41600 events read in total (3015ms).
[12:46:05.470] <TB3> INFO: Test took 3874ms.
[12:46:05.774] <TB3> INFO: Expecting 41600 events.
[12:46:09.305] <TB3> INFO: 41600 events read in total (2939ms).
[12:46:09.306] <TB3> INFO: Test took 3812ms.
[12:46:09.595] <TB3> INFO: Expecting 41600 events.
[12:46:13.117] <TB3> INFO: 41600 events read in total (2931ms).
[12:46:13.118] <TB3> INFO: Test took 3788ms.
[12:46:13.408] <TB3> INFO: Expecting 41600 events.
[12:46:16.971] <TB3> INFO: 41600 events read in total (2972ms).
[12:46:16.972] <TB3> INFO: Test took 3830ms.
[12:46:17.265] <TB3> INFO: Expecting 41600 events.
[12:46:20.772] <TB3> INFO: 41600 events read in total (2915ms).
[12:46:20.772] <TB3> INFO: Test took 3773ms.
[12:46:21.062] <TB3> INFO: Expecting 41600 events.
[12:46:24.563] <TB3> INFO: 41600 events read in total (2909ms).
[12:46:24.564] <TB3> INFO: Test took 3767ms.
[12:46:24.855] <TB3> INFO: Expecting 41600 events.
[12:46:28.425] <TB3> INFO: 41600 events read in total (2978ms).
[12:46:28.426] <TB3> INFO: Test took 3836ms.
[12:46:28.717] <TB3> INFO: Expecting 41600 events.
[12:46:32.203] <TB3> INFO: 41600 events read in total (2895ms).
[12:46:32.203] <TB3> INFO: Test took 3752ms.
[12:46:32.494] <TB3> INFO: Expecting 41600 events.
[12:46:35.978] <TB3> INFO: 41600 events read in total (2893ms).
[12:46:35.978] <TB3> INFO: Test took 3750ms.
[12:46:36.268] <TB3> INFO: Expecting 41600 events.
[12:46:39.862] <TB3> INFO: 41600 events read in total (3002ms).
[12:46:39.863] <TB3> INFO: Test took 3860ms.
[12:46:40.153] <TB3> INFO: Expecting 41600 events.
[12:46:43.673] <TB3> INFO: 41600 events read in total (2928ms).
[12:46:43.674] <TB3> INFO: Test took 3787ms.
[12:46:43.967] <TB3> INFO: Expecting 41600 events.
[12:46:47.531] <TB3> INFO: 41600 events read in total (2972ms).
[12:46:47.532] <TB3> INFO: Test took 3830ms.
[12:46:47.821] <TB3> INFO: Expecting 41600 events.
[12:46:51.310] <TB3> INFO: 41600 events read in total (2897ms).
[12:46:51.311] <TB3> INFO: Test took 3754ms.
[12:46:51.601] <TB3> INFO: Expecting 41600 events.
[12:46:55.082] <TB3> INFO: 41600 events read in total (2889ms).
[12:46:55.082] <TB3> INFO: Test took 3747ms.
[12:46:55.372] <TB3> INFO: Expecting 41600 events.
[12:46:58.925] <TB3> INFO: 41600 events read in total (2961ms).
[12:46:58.926] <TB3> INFO: Test took 3820ms.
[12:46:59.221] <TB3> INFO: Expecting 41600 events.
[12:47:02.909] <TB3> INFO: 41600 events read in total (3097ms).
[12:47:02.909] <TB3> INFO: Test took 3954ms.
[12:47:03.203] <TB3> INFO: Expecting 2560 events.
[12:47:04.096] <TB3> INFO: 2560 events read in total (301ms).
[12:47:04.096] <TB3> INFO: Test took 1170ms.
[12:47:04.403] <TB3> INFO: Expecting 2560 events.
[12:47:05.294] <TB3> INFO: 2560 events read in total (299ms).
[12:47:05.294] <TB3> INFO: Test took 1197ms.
[12:47:05.602] <TB3> INFO: Expecting 2560 events.
[12:47:06.486] <TB3> INFO: 2560 events read in total (292ms).
[12:47:06.486] <TB3> INFO: Test took 1192ms.
[12:47:06.794] <TB3> INFO: Expecting 2560 events.
[12:47:07.684] <TB3> INFO: 2560 events read in total (298ms).
[12:47:07.685] <TB3> INFO: Test took 1198ms.
[12:47:07.992] <TB3> INFO: Expecting 2560 events.
[12:47:08.875] <TB3> INFO: 2560 events read in total (291ms).
[12:47:08.876] <TB3> INFO: Test took 1191ms.
[12:47:09.184] <TB3> INFO: Expecting 2560 events.
[12:47:10.064] <TB3> INFO: 2560 events read in total (288ms).
[12:47:10.064] <TB3> INFO: Test took 1188ms.
[12:47:10.372] <TB3> INFO: Expecting 2560 events.
[12:47:11.253] <TB3> INFO: 2560 events read in total (289ms).
[12:47:11.254] <TB3> INFO: Test took 1189ms.
[12:47:11.562] <TB3> INFO: Expecting 2560 events.
[12:47:12.449] <TB3> INFO: 2560 events read in total (295ms).
[12:47:12.449] <TB3> INFO: Test took 1195ms.
[12:47:12.756] <TB3> INFO: Expecting 2560 events.
[12:47:13.640] <TB3> INFO: 2560 events read in total (292ms).
[12:47:13.640] <TB3> INFO: Test took 1190ms.
[12:47:13.949] <TB3> INFO: Expecting 2560 events.
[12:47:14.828] <TB3> INFO: 2560 events read in total (287ms).
[12:47:14.829] <TB3> INFO: Test took 1188ms.
[12:47:15.137] <TB3> INFO: Expecting 2560 events.
[12:47:16.020] <TB3> INFO: 2560 events read in total (291ms).
[12:47:16.020] <TB3> INFO: Test took 1191ms.
[12:47:16.327] <TB3> INFO: Expecting 2560 events.
[12:47:17.215] <TB3> INFO: 2560 events read in total (296ms).
[12:47:17.215] <TB3> INFO: Test took 1194ms.
[12:47:17.522] <TB3> INFO: Expecting 2560 events.
[12:47:18.414] <TB3> INFO: 2560 events read in total (300ms).
[12:47:18.414] <TB3> INFO: Test took 1198ms.
[12:47:18.721] <TB3> INFO: Expecting 2560 events.
[12:47:19.613] <TB3> INFO: 2560 events read in total (300ms).
[12:47:19.613] <TB3> INFO: Test took 1198ms.
[12:47:19.920] <TB3> INFO: Expecting 2560 events.
[12:47:20.810] <TB3> INFO: 2560 events read in total (298ms).
[12:47:20.810] <TB3> INFO: Test took 1196ms.
[12:47:21.118] <TB3> INFO: Expecting 2560 events.
[12:47:22.010] <TB3> INFO: 2560 events read in total (300ms).
[12:47:22.010] <TB3> INFO: Test took 1200ms.
[12:47:22.013] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:47:22.318] <TB3> INFO: Expecting 655360 events.
[12:47:37.314] <TB3> INFO: 655360 events read in total (14404ms).
[12:47:37.329] <TB3> INFO: Expecting 655360 events.
[12:47:51.824] <TB3> INFO: 655360 events read in total (14092ms).
[12:47:51.845] <TB3> INFO: Expecting 655360 events.
[12:48:06.471] <TB3> INFO: 655360 events read in total (14223ms).
[12:48:06.494] <TB3> INFO: Expecting 655360 events.
[12:48:20.956] <TB3> INFO: 655360 events read in total (14059ms).
[12:48:20.985] <TB3> INFO: Expecting 655360 events.
[12:48:35.910] <TB3> INFO: 655360 events read in total (14522ms).
[12:48:35.943] <TB3> INFO: Expecting 655360 events.
[12:48:50.621] <TB3> INFO: 655360 events read in total (14275ms).
[12:48:50.675] <TB3> INFO: Expecting 655360 events.
[12:49:05.272] <TB3> INFO: 655360 events read in total (14194ms).
[12:49:05.314] <TB3> INFO: Expecting 655360 events.
[12:49:19.761] <TB3> INFO: 655360 events read in total (14044ms).
[12:49:19.813] <TB3> INFO: Expecting 655360 events.
[12:49:34.320] <TB3> INFO: 655360 events read in total (14104ms).
[12:49:34.388] <TB3> INFO: Expecting 655360 events.
[12:49:48.987] <TB3> INFO: 655360 events read in total (14196ms).
[12:49:49.055] <TB3> INFO: Expecting 655360 events.
[12:50:03.691] <TB3> INFO: 655360 events read in total (14233ms).
[12:50:03.796] <TB3> INFO: Expecting 655360 events.
[12:50:18.295] <TB3> INFO: 655360 events read in total (14096ms).
[12:50:18.385] <TB3> INFO: Expecting 655360 events.
[12:50:32.799] <TB3> INFO: 655360 events read in total (14011ms).
[12:50:32.879] <TB3> INFO: Expecting 655360 events.
[12:50:47.372] <TB3> INFO: 655360 events read in total (14090ms).
[12:50:47.525] <TB3> INFO: Expecting 655360 events.
[12:51:01.003] <TB3> INFO: 655360 events read in total (14075ms).
[12:51:02.133] <TB3> INFO: Expecting 655360 events.
[12:51:16.629] <TB3> INFO: 655360 events read in total (14093ms).
[12:51:16.732] <TB3> INFO: Test took 234719ms.
[12:51:16.831] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:51:17.084] <TB3> INFO: Expecting 655360 events.
[12:51:31.689] <TB3> INFO: 655360 events read in total (14013ms).
[12:51:31.703] <TB3> INFO: Expecting 655360 events.
[12:51:46.240] <TB3> INFO: 655360 events read in total (14134ms).
[12:51:46.265] <TB3> INFO: Expecting 655360 events.
[12:52:00.756] <TB3> INFO: 655360 events read in total (14088ms).
[12:52:00.780] <TB3> INFO: Expecting 655360 events.
[12:52:15.212] <TB3> INFO: 655360 events read in total (14029ms).
[12:52:15.240] <TB3> INFO: Expecting 655360 events.
[12:52:29.555] <TB3> INFO: 655360 events read in total (13911ms).
[12:52:29.587] <TB3> INFO: Expecting 655360 events.
[12:52:43.983] <TB3> INFO: 655360 events read in total (13993ms).
[12:52:44.019] <TB3> INFO: Expecting 655360 events.
[12:52:58.690] <TB3> INFO: 655360 events read in total (14267ms).
[12:52:58.734] <TB3> INFO: Expecting 655360 events.
[12:53:12.838] <TB3> INFO: 655360 events read in total (13701ms).
[12:53:12.952] <TB3> INFO: Expecting 655360 events.
[12:53:27.409] <TB3> INFO: 655360 events read in total (14054ms).
[12:53:27.471] <TB3> INFO: Expecting 655360 events.
[12:53:41.741] <TB3> INFO: 655360 events read in total (13866ms).
[12:53:41.858] <TB3> INFO: Expecting 655360 events.
[12:53:56.327] <TB3> INFO: 655360 events read in total (14066ms).
[12:53:56.412] <TB3> INFO: Expecting 655360 events.
[12:54:11.056] <TB3> INFO: 655360 events read in total (14241ms).
[12:54:11.167] <TB3> INFO: Expecting 655360 events.
[12:54:25.633] <TB3> INFO: 655360 events read in total (14063ms).
[12:54:25.760] <TB3> INFO: Expecting 655360 events.
[12:54:40.552] <TB3> INFO: 655360 events read in total (14383ms).
[12:54:40.662] <TB3> INFO: Expecting 655360 events.
[12:54:55.448] <TB3> INFO: 655360 events read in total (14383ms).
[12:54:55.547] <TB3> INFO: Expecting 655360 events.
[12:55:10.194] <TB3> INFO: 655360 events read in total (14244ms).
[12:55:10.366] <TB3> INFO: Test took 233535ms.
[12:55:10.534] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.539] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.545] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.551] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:55:10.556] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:55:10.562] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[12:55:10.567] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[12:55:10.573] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[12:55:10.579] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[12:55:10.584] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[12:55:10.590] <TB3> INFO: safety margin for low PH: adding 8, margin is now 28
[12:55:10.596] <TB3> INFO: safety margin for low PH: adding 9, margin is now 29
[12:55:10.601] <TB3> INFO: safety margin for low PH: adding 10, margin is now 30
[12:55:10.607] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.613] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.619] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.625] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.630] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.636] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.642] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.647] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.653] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.659] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:55:10.665] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:55:10.671] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[12:55:10.678] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[12:55:10.684] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.692] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:55:10.698] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[12:55:10.705] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[12:55:10.712] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[12:55:10.718] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[12:55:10.725] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[12:55:10.732] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[12:55:10.739] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.746] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.753] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[12:55:10.760] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[12:55:10.794] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C0.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C1.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C2.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C3.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C4.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C5.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C6.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C7.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C8.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C9.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C10.dat
[12:55:10.795] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C11.dat
[12:55:10.796] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C12.dat
[12:55:10.796] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C13.dat
[12:55:10.796] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C14.dat
[12:55:10.796] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//dacParameters35_C15.dat
[12:55:11.072] <TB3> INFO: Expecting 41600 events.
[12:55:14.308] <TB3> INFO: 41600 events read in total (2645ms).
[12:55:14.309] <TB3> INFO: Test took 3511ms.
[12:55:14.803] <TB3> INFO: Expecting 41600 events.
[12:55:17.893] <TB3> INFO: 41600 events read in total (2498ms).
[12:55:17.894] <TB3> INFO: Test took 3371ms.
[12:55:18.386] <TB3> INFO: Expecting 41600 events.
[12:55:21.533] <TB3> INFO: 41600 events read in total (2556ms).
[12:55:21.534] <TB3> INFO: Test took 3429ms.
[12:55:21.752] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:21.841] <TB3> INFO: Expecting 2560 events.
[12:55:22.732] <TB3> INFO: 2560 events read in total (299ms).
[12:55:22.732] <TB3> INFO: Test took 980ms.
[12:55:22.737] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:23.041] <TB3> INFO: Expecting 2560 events.
[12:55:23.932] <TB3> INFO: 2560 events read in total (299ms).
[12:55:23.932] <TB3> INFO: Test took 1195ms.
[12:55:23.934] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:24.241] <TB3> INFO: Expecting 2560 events.
[12:55:25.128] <TB3> INFO: 2560 events read in total (295ms).
[12:55:25.128] <TB3> INFO: Test took 1194ms.
[12:55:25.131] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:25.436] <TB3> INFO: Expecting 2560 events.
[12:55:26.320] <TB3> INFO: 2560 events read in total (292ms).
[12:55:26.320] <TB3> INFO: Test took 1190ms.
[12:55:26.322] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:26.629] <TB3> INFO: Expecting 2560 events.
[12:55:27.524] <TB3> INFO: 2560 events read in total (303ms).
[12:55:27.524] <TB3> INFO: Test took 1202ms.
[12:55:27.527] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:27.832] <TB3> INFO: Expecting 2560 events.
[12:55:28.721] <TB3> INFO: 2560 events read in total (297ms).
[12:55:28.722] <TB3> INFO: Test took 1195ms.
[12:55:28.725] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:29.030] <TB3> INFO: Expecting 2560 events.
[12:55:29.923] <TB3> INFO: 2560 events read in total (301ms).
[12:55:29.924] <TB3> INFO: Test took 1199ms.
[12:55:29.926] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:30.230] <TB3> INFO: Expecting 2560 events.
[12:55:31.123] <TB3> INFO: 2560 events read in total (301ms).
[12:55:31.123] <TB3> INFO: Test took 1197ms.
[12:55:31.127] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:31.430] <TB3> INFO: Expecting 2560 events.
[12:55:32.322] <TB3> INFO: 2560 events read in total (300ms).
[12:55:32.322] <TB3> INFO: Test took 1195ms.
[12:55:32.325] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:32.630] <TB3> INFO: Expecting 2560 events.
[12:55:33.510] <TB3> INFO: 2560 events read in total (288ms).
[12:55:33.511] <TB3> INFO: Test took 1186ms.
[12:55:33.514] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:33.818] <TB3> INFO: Expecting 2560 events.
[12:55:34.707] <TB3> INFO: 2560 events read in total (297ms).
[12:55:34.708] <TB3> INFO: Test took 1195ms.
[12:55:34.711] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:35.016] <TB3> INFO: Expecting 2560 events.
[12:55:35.894] <TB3> INFO: 2560 events read in total (287ms).
[12:55:35.894] <TB3> INFO: Test took 1183ms.
[12:55:35.896] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:36.204] <TB3> INFO: Expecting 2560 events.
[12:55:37.096] <TB3> INFO: 2560 events read in total (300ms).
[12:55:37.096] <TB3> INFO: Test took 1200ms.
[12:55:37.100] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:37.404] <TB3> INFO: Expecting 2560 events.
[12:55:38.293] <TB3> INFO: 2560 events read in total (297ms).
[12:55:38.294] <TB3> INFO: Test took 1195ms.
[12:55:38.297] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:38.603] <TB3> INFO: Expecting 2560 events.
[12:55:39.492] <TB3> INFO: 2560 events read in total (297ms).
[12:55:39.493] <TB3> INFO: Test took 1197ms.
[12:55:39.497] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:39.800] <TB3> INFO: Expecting 2560 events.
[12:55:40.687] <TB3> INFO: 2560 events read in total (295ms).
[12:55:40.688] <TB3> INFO: Test took 1192ms.
[12:55:40.691] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:40.995] <TB3> INFO: Expecting 2560 events.
[12:55:41.883] <TB3> INFO: 2560 events read in total (296ms).
[12:55:41.883] <TB3> INFO: Test took 1192ms.
[12:55:41.886] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:42.192] <TB3> INFO: Expecting 2560 events.
[12:55:43.085] <TB3> INFO: 2560 events read in total (301ms).
[12:55:43.085] <TB3> INFO: Test took 1199ms.
[12:55:43.089] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:43.392] <TB3> INFO: Expecting 2560 events.
[12:55:44.277] <TB3> INFO: 2560 events read in total (293ms).
[12:55:44.277] <TB3> INFO: Test took 1188ms.
[12:55:44.281] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:44.585] <TB3> INFO: Expecting 2560 events.
[12:55:45.474] <TB3> INFO: 2560 events read in total (297ms).
[12:55:45.474] <TB3> INFO: Test took 1194ms.
[12:55:45.477] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:45.783] <TB3> INFO: Expecting 2560 events.
[12:55:46.670] <TB3> INFO: 2560 events read in total (296ms).
[12:55:46.670] <TB3> INFO: Test took 1194ms.
[12:55:46.674] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:46.979] <TB3> INFO: Expecting 2560 events.
[12:55:47.871] <TB3> INFO: 2560 events read in total (300ms).
[12:55:47.871] <TB3> INFO: Test took 1197ms.
[12:55:47.876] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:48.179] <TB3> INFO: Expecting 2560 events.
[12:55:49.060] <TB3> INFO: 2560 events read in total (289ms).
[12:55:49.060] <TB3> INFO: Test took 1185ms.
[12:55:49.063] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:49.369] <TB3> INFO: Expecting 2560 events.
[12:55:50.259] <TB3> INFO: 2560 events read in total (298ms).
[12:55:50.259] <TB3> INFO: Test took 1196ms.
[12:55:50.262] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:50.566] <TB3> INFO: Expecting 2560 events.
[12:55:51.461] <TB3> INFO: 2560 events read in total (303ms).
[12:55:51.462] <TB3> INFO: Test took 1200ms.
[12:55:51.465] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:51.770] <TB3> INFO: Expecting 2560 events.
[12:55:52.661] <TB3> INFO: 2560 events read in total (299ms).
[12:55:52.661] <TB3> INFO: Test took 1196ms.
[12:55:52.664] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:52.970] <TB3> INFO: Expecting 2560 events.
[12:55:53.863] <TB3> INFO: 2560 events read in total (300ms).
[12:55:53.863] <TB3> INFO: Test took 1199ms.
[12:55:53.866] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:54.172] <TB3> INFO: Expecting 2560 events.
[12:55:55.058] <TB3> INFO: 2560 events read in total (294ms).
[12:55:55.058] <TB3> INFO: Test took 1192ms.
[12:55:55.062] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:55.366] <TB3> INFO: Expecting 2560 events.
[12:55:56.262] <TB3> INFO: 2560 events read in total (304ms).
[12:55:56.262] <TB3> INFO: Test took 1200ms.
[12:55:56.266] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:56.570] <TB3> INFO: Expecting 2560 events.
[12:55:57.464] <TB3> INFO: 2560 events read in total (302ms).
[12:55:57.464] <TB3> INFO: Test took 1198ms.
[12:55:57.466] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:57.774] <TB3> INFO: Expecting 2560 events.
[12:55:58.665] <TB3> INFO: 2560 events read in total (300ms).
[12:55:58.666] <TB3> INFO: Test took 1200ms.
[12:55:58.669] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:58.973] <TB3> INFO: Expecting 2560 events.
[12:55:59.868] <TB3> INFO: 2560 events read in total (303ms).
[12:55:59.868] <TB3> INFO: Test took 1199ms.
[12:56:00.357] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 648 seconds
[12:56:00.357] <TB3> INFO: PH scale (per ROC): 47 55 48 53 63 61 54 50 50 48 63 48 46 45 68 44
[12:56:00.358] <TB3> INFO: PH offset (per ROC): 105 130 111 131 123 121 128 98 142 125 133 112 112 100 122 107
[12:56:00.368] <TB3> INFO: Decoding statistics:
[12:56:00.368] <TB3> INFO: General information:
[12:56:00.368] <TB3> INFO: 16bit words read: 127886
[12:56:00.368] <TB3> INFO: valid events total: 20480
[12:56:00.368] <TB3> INFO: empty events: 17977
[12:56:00.368] <TB3> INFO: valid events with pixels: 2503
[12:56:00.368] <TB3> INFO: valid pixel hits: 2503
[12:56:00.368] <TB3> INFO: Event errors: 0
[12:56:00.368] <TB3> INFO: start marker: 0
[12:56:00.368] <TB3> INFO: stop marker: 0
[12:56:00.368] <TB3> INFO: overflow: 0
[12:56:00.368] <TB3> INFO: invalid 5bit words: 0
[12:56:00.369] <TB3> INFO: invalid XOR eye diagram: 0
[12:56:00.369] <TB3> INFO: frame (failed synchr.): 0
[12:56:00.369] <TB3> INFO: idle data (no TBM trl): 0
[12:56:00.369] <TB3> INFO: no data (only TBM hdr): 0
[12:56:00.369] <TB3> INFO: TBM errors: 0
[12:56:00.369] <TB3> INFO: flawed TBM headers: 0
[12:56:00.369] <TB3> INFO: flawed TBM trailers: 0
[12:56:00.369] <TB3> INFO: event ID mismatches: 0
[12:56:00.369] <TB3> INFO: ROC errors: 0
[12:56:00.369] <TB3> INFO: missing ROC header(s): 0
[12:56:00.369] <TB3> INFO: misplaced readback start: 0
[12:56:00.369] <TB3> INFO: Pixel decoding errors: 0
[12:56:00.369] <TB3> INFO: pixel data incomplete: 0
[12:56:00.369] <TB3> INFO: pixel address: 0
[12:56:00.369] <TB3> INFO: pulse height fill bit: 0
[12:56:00.369] <TB3> INFO: buffer corruption: 0
[12:56:00.547] <TB3> INFO: ######################################################################
[12:56:00.547] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:56:00.547] <TB3> INFO: ######################################################################
[12:56:00.563] <TB3> INFO: scanning low vcal = 10
[12:56:00.798] <TB3> INFO: Expecting 41600 events.
[12:56:04.441] <TB3> INFO: 41600 events read in total (3051ms).
[12:56:04.442] <TB3> INFO: Test took 3879ms.
[12:56:04.444] <TB3> INFO: scanning low vcal = 20
[12:56:04.739] <TB3> INFO: Expecting 41600 events.
[12:56:08.372] <TB3> INFO: 41600 events read in total (3041ms).
[12:56:08.373] <TB3> INFO: Test took 3929ms.
[12:56:08.374] <TB3> INFO: scanning low vcal = 30
[12:56:08.665] <TB3> INFO: Expecting 41600 events.
[12:56:12.341] <TB3> INFO: 41600 events read in total (3084ms).
[12:56:12.342] <TB3> INFO: Test took 3968ms.
[12:56:12.345] <TB3> INFO: scanning low vcal = 40
[12:56:12.623] <TB3> INFO: Expecting 41600 events.
[12:56:16.654] <TB3> INFO: 41600 events read in total (3440ms).
[12:56:16.655] <TB3> INFO: Test took 4310ms.
[12:56:16.658] <TB3> INFO: scanning low vcal = 50
[12:56:16.936] <TB3> INFO: Expecting 41600 events.
[12:56:20.970] <TB3> INFO: 41600 events read in total (3442ms).
[12:56:20.970] <TB3> INFO: Test took 4312ms.
[12:56:20.974] <TB3> INFO: scanning low vcal = 60
[12:56:21.251] <TB3> INFO: Expecting 41600 events.
[12:56:25.233] <TB3> INFO: 41600 events read in total (3390ms).
[12:56:25.233] <TB3> INFO: Test took 4259ms.
[12:56:25.237] <TB3> INFO: scanning low vcal = 70
[12:56:25.514] <TB3> INFO: Expecting 41600 events.
[12:56:29.519] <TB3> INFO: 41600 events read in total (3413ms).
[12:56:29.520] <TB3> INFO: Test took 4283ms.
[12:56:29.523] <TB3> INFO: scanning low vcal = 80
[12:56:29.800] <TB3> INFO: Expecting 41600 events.
[12:56:33.841] <TB3> INFO: 41600 events read in total (3449ms).
[12:56:33.842] <TB3> INFO: Test took 4319ms.
[12:56:33.845] <TB3> INFO: scanning low vcal = 90
[12:56:34.126] <TB3> INFO: Expecting 41600 events.
[12:56:38.129] <TB3> INFO: 41600 events read in total (3411ms).
[12:56:38.130] <TB3> INFO: Test took 4285ms.
[12:56:38.134] <TB3> INFO: scanning low vcal = 100
[12:56:38.410] <TB3> INFO: Expecting 41600 events.
[12:56:42.372] <TB3> INFO: 41600 events read in total (3371ms).
[12:56:42.373] <TB3> INFO: Test took 4238ms.
[12:56:42.376] <TB3> INFO: scanning low vcal = 110
[12:56:42.652] <TB3> INFO: Expecting 41600 events.
[12:56:46.593] <TB3> INFO: 41600 events read in total (3349ms).
[12:56:46.594] <TB3> INFO: Test took 4218ms.
[12:56:46.597] <TB3> INFO: scanning low vcal = 120
[12:56:46.874] <TB3> INFO: Expecting 41600 events.
[12:56:50.810] <TB3> INFO: 41600 events read in total (3345ms).
[12:56:50.812] <TB3> INFO: Test took 4214ms.
[12:56:50.815] <TB3> INFO: scanning low vcal = 130
[12:56:51.091] <TB3> INFO: Expecting 41600 events.
[12:56:55.030] <TB3> INFO: 41600 events read in total (3347ms).
[12:56:55.031] <TB3> INFO: Test took 4216ms.
[12:56:55.034] <TB3> INFO: scanning low vcal = 140
[12:56:55.311] <TB3> INFO: Expecting 41600 events.
[12:56:59.255] <TB3> INFO: 41600 events read in total (3353ms).
[12:56:59.255] <TB3> INFO: Test took 4221ms.
[12:56:59.258] <TB3> INFO: scanning low vcal = 150
[12:56:59.535] <TB3> INFO: Expecting 41600 events.
[12:57:03.476] <TB3> INFO: 41600 events read in total (3350ms).
[12:57:03.476] <TB3> INFO: Test took 4218ms.
[12:57:03.480] <TB3> INFO: scanning low vcal = 160
[12:57:03.756] <TB3> INFO: Expecting 41600 events.
[12:57:07.696] <TB3> INFO: 41600 events read in total (3349ms).
[12:57:07.697] <TB3> INFO: Test took 4217ms.
[12:57:07.701] <TB3> INFO: scanning low vcal = 170
[12:57:07.976] <TB3> INFO: Expecting 41600 events.
[12:57:11.932] <TB3> INFO: 41600 events read in total (3364ms).
[12:57:11.933] <TB3> INFO: Test took 4232ms.
[12:57:11.939] <TB3> INFO: scanning low vcal = 180
[12:57:12.213] <TB3> INFO: Expecting 41600 events.
[12:57:16.252] <TB3> INFO: 41600 events read in total (3447ms).
[12:57:16.253] <TB3> INFO: Test took 4314ms.
[12:57:16.256] <TB3> INFO: scanning low vcal = 190
[12:57:16.532] <TB3> INFO: Expecting 41600 events.
[12:57:20.593] <TB3> INFO: 41600 events read in total (3469ms).
[12:57:20.593] <TB3> INFO: Test took 4337ms.
[12:57:20.596] <TB3> INFO: scanning low vcal = 200
[12:57:20.894] <TB3> INFO: Expecting 41600 events.
[12:57:24.864] <TB3> INFO: 41600 events read in total (3378ms).
[12:57:24.865] <TB3> INFO: Test took 4269ms.
[12:57:24.868] <TB3> INFO: scanning low vcal = 210
[12:57:25.145] <TB3> INFO: Expecting 41600 events.
[12:57:29.159] <TB3> INFO: 41600 events read in total (3423ms).
[12:57:29.160] <TB3> INFO: Test took 4292ms.
[12:57:29.164] <TB3> INFO: scanning low vcal = 220
[12:57:29.463] <TB3> INFO: Expecting 41600 events.
[12:57:33.427] <TB3> INFO: 41600 events read in total (3373ms).
[12:57:33.428] <TB3> INFO: Test took 4264ms.
[12:57:33.431] <TB3> INFO: scanning low vcal = 230
[12:57:33.707] <TB3> INFO: Expecting 41600 events.
[12:57:37.698] <TB3> INFO: 41600 events read in total (3399ms).
[12:57:37.699] <TB3> INFO: Test took 4268ms.
[12:57:37.702] <TB3> INFO: scanning low vcal = 240
[12:57:37.978] <TB3> INFO: Expecting 41600 events.
[12:57:42.011] <TB3> INFO: 41600 events read in total (3441ms).
[12:57:42.012] <TB3> INFO: Test took 4310ms.
[12:57:42.015] <TB3> INFO: scanning low vcal = 250
[12:57:42.291] <TB3> INFO: Expecting 41600 events.
[12:57:46.280] <TB3> INFO: 41600 events read in total (3397ms).
[12:57:46.281] <TB3> INFO: Test took 4266ms.
[12:57:46.285] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[12:57:46.561] <TB3> INFO: Expecting 41600 events.
[12:57:50.533] <TB3> INFO: 41600 events read in total (3381ms).
[12:57:50.533] <TB3> INFO: Test took 4249ms.
[12:57:50.537] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[12:57:50.813] <TB3> INFO: Expecting 41600 events.
[12:57:54.779] <TB3> INFO: 41600 events read in total (3374ms).
[12:57:54.779] <TB3> INFO: Test took 4241ms.
[12:57:54.783] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[12:57:55.059] <TB3> INFO: Expecting 41600 events.
[12:57:59.031] <TB3> INFO: 41600 events read in total (3380ms).
[12:57:59.032] <TB3> INFO: Test took 4249ms.
[12:57:59.035] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[12:57:59.312] <TB3> INFO: Expecting 41600 events.
[12:58:03.293] <TB3> INFO: 41600 events read in total (3390ms).
[12:58:03.294] <TB3> INFO: Test took 4259ms.
[12:58:03.297] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:58:03.574] <TB3> INFO: Expecting 41600 events.
[12:58:07.569] <TB3> INFO: 41600 events read in total (3404ms).
[12:58:07.570] <TB3> INFO: Test took 4273ms.
[12:58:07.983] <TB3> INFO: PixTestGainPedestal::measure() done
[12:58:39.000] <TB3> INFO: PixTestGainPedestal::fit() done
[12:58:39.000] <TB3> INFO: non-linearity mean: 0.941 0.982 0.950 0.980 0.985 0.983 0.974 0.950 0.979 0.976 0.983 0.950 0.972 0.917 0.985 0.922
[12:58:39.000] <TB3> INFO: non-linearity RMS: 0.052 0.004 0.064 0.004 0.004 0.003 0.009 0.058 0.007 0.005 0.004 0.050 0.017 0.113 0.003 0.111
[12:58:39.000] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[12:58:40.013] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[12:58:40.026] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[12:58:40.039] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[12:58:40.052] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[12:58:40.065] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[12:58:40.078] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[12:58:40.090] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[12:58:40.103] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[12:58:40.116] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[12:58:40.129] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[12:58:40.142] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[12:58:40.156] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[12:58:40.169] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[12:58:40.182] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[12:58:40.196] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1047_FullQualification_2016-10-22_10h41m_1477125660//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[12:58:40.209] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 159 seconds
[12:58:40.209] <TB3> INFO: Decoding statistics:
[12:58:40.209] <TB3> INFO: General information:
[12:58:40.209] <TB3> INFO: 16bit words read: 3327806
[12:58:40.209] <TB3> INFO: valid events total: 332800
[12:58:40.209] <TB3> INFO: empty events: 0
[12:58:40.209] <TB3> INFO: valid events with pixels: 332800
[12:58:40.209] <TB3> INFO: valid pixel hits: 665503
[12:58:40.209] <TB3> INFO: Event errors: 0
[12:58:40.209] <TB3> INFO: start marker: 0
[12:58:40.209] <TB3> INFO: stop marker: 0
[12:58:40.209] <TB3> INFO: overflow: 0
[12:58:40.209] <TB3> INFO: invalid 5bit words: 0
[12:58:40.209] <TB3> INFO: invalid XOR eye diagram: 0
[12:58:40.209] <TB3> INFO: frame (failed synchr.): 0
[12:58:40.209] <TB3> INFO: idle data (no TBM trl): 0
[12:58:40.209] <TB3> INFO: no data (only TBM hdr): 0
[12:58:40.209] <TB3> INFO: TBM errors: 0
[12:58:40.209] <TB3> INFO: flawed TBM headers: 0
[12:58:40.209] <TB3> INFO: flawed TBM trailers: 0
[12:58:40.209] <TB3> INFO: event ID mismatches: 0
[12:58:40.209] <TB3> INFO: ROC errors: 0
[12:58:40.209] <TB3> INFO: missing ROC header(s): 0
[12:58:40.209] <TB3> INFO: misplaced readback start: 0
[12:58:40.209] <TB3> INFO: Pixel decoding errors: 0
[12:58:40.209] <TB3> INFO: pixel data incomplete: 0
[12:58:40.209] <TB3> INFO: pixel address: 0
[12:58:40.209] <TB3> INFO: pulse height fill bit: 0
[12:58:40.209] <TB3> INFO: buffer corruption: 0
[12:58:40.227] <TB3> INFO: Decoding statistics:
[12:58:40.227] <TB3> INFO: General information:
[12:58:40.227] <TB3> INFO: 16bit words read: 3457228
[12:58:40.227] <TB3> INFO: valid events total: 353536
[12:58:40.227] <TB3> INFO: empty events: 18233
[12:58:40.227] <TB3> INFO: valid events with pixels: 335303
[12:58:40.227] <TB3> INFO: valid pixel hits: 668006
[12:58:40.227] <TB3> INFO: Event errors: 0
[12:58:40.227] <TB3> INFO: start marker: 0
[12:58:40.227] <TB3> INFO: stop marker: 0
[12:58:40.227] <TB3> INFO: overflow: 0
[12:58:40.227] <TB3> INFO: invalid 5bit words: 0
[12:58:40.227] <TB3> INFO: invalid XOR eye diagram: 0
[12:58:40.227] <TB3> INFO: frame (failed synchr.): 0
[12:58:40.227] <TB3> INFO: idle data (no TBM trl): 0
[12:58:40.227] <TB3> INFO: no data (only TBM hdr): 0
[12:58:40.227] <TB3> INFO: TBM errors: 0
[12:58:40.227] <TB3> INFO: flawed TBM headers: 0
[12:58:40.227] <TB3> INFO: flawed TBM trailers: 0
[12:58:40.227] <TB3> INFO: event ID mismatches: 0
[12:58:40.227] <TB3> INFO: ROC errors: 0
[12:58:40.227] <TB3> INFO: missing ROC header(s): 0
[12:58:40.227] <TB3> INFO: misplaced readback start: 0
[12:58:40.227] <TB3> INFO: Pixel decoding errors: 0
[12:58:40.227] <TB3> INFO: pixel data incomplete: 0
[12:58:40.227] <TB3> INFO: pixel address: 0
[12:58:40.227] <TB3> INFO: pulse height fill bit: 0
[12:58:40.227] <TB3> INFO: buffer corruption: 0
[12:58:40.227] <TB3> INFO: enter test to run
[12:58:40.227] <TB3> INFO: test: exit no parameter change
[12:58:40.350] <TB3> QUIET: Connection to board 126 closed.
[12:58:40.351] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud