Test Date: 2016-10-20 09:44
Analysis date: 2016-10-20 16:41
Logfile
LogfileView
[10:37:03.074] <TB1> INFO: *** Welcome to pxar ***
[10:37:03.074] <TB1> INFO: *** Today: 2016/10/20
[10:37:03.081] <TB1> INFO: *** Version: c8ba-dirty
[10:37:03.081] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C15.dat
[10:37:03.081] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C1b.dat
[10:37:03.081] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//defaultMaskFile.dat
[10:37:03.081] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters_C15.dat
[10:37:03.143] <TB1> INFO: clk: 4
[10:37:03.143] <TB1> INFO: ctr: 4
[10:37:03.143] <TB1> INFO: sda: 19
[10:37:03.143] <TB1> INFO: tin: 9
[10:37:03.143] <TB1> INFO: level: 15
[10:37:03.143] <TB1> INFO: triggerdelay: 0
[10:37:03.143] <TB1> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[10:37:03.143] <TB1> INFO: Log level: INFO
[10:37:03.152] <TB1> INFO: Found DTB DTB_WXC03A
[10:37:03.163] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[10:37:03.165] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 154
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXC03A
MAC address: 40D85511809A
Hostname: pixelDTB154
Comment:
------------------------------------------------------
[10:37:03.167] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[10:37:04.658] <TB1> INFO: DUT info:
[10:37:04.659] <TB1> INFO: The DUT currently contains the following objects:
[10:37:04.659] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[10:37:04.659] <TB1> INFO: TBM Core alpha (0): 7 registers set
[10:37:04.659] <TB1> INFO: TBM Core beta (1): 7 registers set
[10:37:04.659] <TB1> INFO: TBM Core alpha (2): 7 registers set
[10:37:04.659] <TB1> INFO: TBM Core beta (3): 7 registers set
[10:37:04.659] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[10:37:04.659] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:04.659] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:37:05.060] <TB1> INFO: enter 'restricted' command line mode
[10:37:05.060] <TB1> INFO: enter test to run
[10:37:05.060] <TB1> INFO: test: pretest no parameter change
[10:37:05.060] <TB1> INFO: running: pretest
[10:37:05.064] <TB1> INFO: ######################################################################
[10:37:05.064] <TB1> INFO: PixTestPretest::doTest()
[10:37:05.064] <TB1> INFO: ######################################################################
[10:37:05.066] <TB1> INFO: ----------------------------------------------------------------------
[10:37:05.066] <TB1> INFO: PixTestPretest::programROC()
[10:37:05.066] <TB1> INFO: ----------------------------------------------------------------------
[10:37:23.079] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[10:37:23.079] <TB1> INFO: IA differences per ROC: 19.3 19.3 19.3 16.9 20.1 18.5 20.1 16.1 19.3 20.9 17.7 18.5 18.5 19.3 22.5 20.1
[10:37:23.141] <TB1> INFO: ----------------------------------------------------------------------
[10:37:23.141] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[10:37:23.141] <TB1> INFO: ----------------------------------------------------------------------
[10:37:44.446] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 384.3 mA = 24.0187 mA/ROC
[10:37:44.446] <TB1> INFO: i(loss) [mA/ROC]: 19.3 20.1 19.3 19.3 19.3 19.3 20.1 18.5 19.3 20.1 18.5 19.3 18.5 19.3 19.3 20.1
[10:37:44.482] <TB1> INFO: ----------------------------------------------------------------------
[10:37:44.482] <TB1> INFO: PixTestPretest::findTiming()
[10:37:44.482] <TB1> INFO: ----------------------------------------------------------------------
[10:37:44.483] <TB1> INFO: PixTestCmd::init()
[10:37:45.063] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[10:38:16.499] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 6, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[10:38:16.499] <TB1> INFO: (success/tries = 100/100), width = 3
[10:38:17.994] <TB1> INFO: ----------------------------------------------------------------------
[10:38:17.994] <TB1> INFO: PixTestPretest::findWorkingPixel()
[10:38:17.994] <TB1> INFO: ----------------------------------------------------------------------
[10:38:18.086] <TB1> INFO: Expecting 231680 events.
[10:38:27.897] <TB1> INFO: 231680 events read in total (9220ms).
[10:38:27.905] <TB1> INFO: Test took 9909ms.
[10:38:28.154] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[10:38:28.191] <TB1> INFO: ----------------------------------------------------------------------
[10:38:28.191] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[10:38:28.191] <TB1> INFO: ----------------------------------------------------------------------
[10:38:28.287] <TB1> INFO: Expecting 231680 events.
[10:38:38.125] <TB1> INFO: 231680 events read in total (9246ms).
[10:38:38.137] <TB1> INFO: Test took 9940ms.
[10:38:38.408] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[10:38:38.408] <TB1> INFO: CalDel: 80 91 87 89 102 96 95 105 98 106 89 98 111 96 83 96
[10:38:38.408] <TB1> INFO: VthrComp: 51 51 52 54 52 52 51 51 52 51 51 51 51 51 52 51
[10:38:38.411] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C0.dat
[10:38:38.411] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C1.dat
[10:38:38.411] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C2.dat
[10:38:38.412] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C3.dat
[10:38:38.412] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C4.dat
[10:38:38.412] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C5.dat
[10:38:38.412] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C6.dat
[10:38:38.412] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C7.dat
[10:38:38.412] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C8.dat
[10:38:38.412] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C9.dat
[10:38:38.412] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C10.dat
[10:38:38.413] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C11.dat
[10:38:38.413] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C12.dat
[10:38:38.413] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C13.dat
[10:38:38.413] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C14.dat
[10:38:38.413] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters_C15.dat
[10:38:38.413] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C0a.dat
[10:38:38.413] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C0b.dat
[10:38:38.413] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C1a.dat
[10:38:38.414] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//tbmParameters_C1b.dat
[10:38:38.414] <TB1> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[10:38:38.465] <TB1> INFO: enter test to run
[10:38:38.466] <TB1> INFO: test: FullTest no parameter change
[10:38:38.466] <TB1> INFO: running: fulltest
[10:38:38.466] <TB1> INFO: ######################################################################
[10:38:38.466] <TB1> INFO: PixTestFullTest::doTest()
[10:38:38.466] <TB1> INFO: ######################################################################
[10:38:38.467] <TB1> INFO: ######################################################################
[10:38:38.467] <TB1> INFO: PixTestAlive::doTest()
[10:38:38.467] <TB1> INFO: ######################################################################
[10:38:38.468] <TB1> INFO: ----------------------------------------------------------------------
[10:38:38.468] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:38:38.468] <TB1> INFO: ----------------------------------------------------------------------
[10:38:38.720] <TB1> INFO: Expecting 41600 events.
[10:38:42.290] <TB1> INFO: 41600 events read in total (2978ms).
[10:38:42.291] <TB1> INFO: Test took 3822ms.
[10:38:42.524] <TB1> INFO: PixTestAlive::aliveTest() done
[10:38:42.524] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:38:42.525] <TB1> INFO: ----------------------------------------------------------------------
[10:38:42.526] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:38:42.526] <TB1> INFO: ----------------------------------------------------------------------
[10:38:42.770] <TB1> INFO: Expecting 41600 events.
[10:38:45.870] <TB1> INFO: 41600 events read in total (2508ms).
[10:38:45.870] <TB1> INFO: Test took 3343ms.
[10:38:45.871] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[10:38:46.115] <TB1> INFO: PixTestAlive::maskTest() done
[10:38:46.115] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:38:46.117] <TB1> INFO: ----------------------------------------------------------------------
[10:38:46.117] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:38:46.117] <TB1> INFO: ----------------------------------------------------------------------
[10:38:46.359] <TB1> INFO: Expecting 41600 events.
[10:38:49.876] <TB1> INFO: 41600 events read in total (2925ms).
[10:38:49.877] <TB1> INFO: Test took 3758ms.
[10:38:50.116] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[10:38:50.116] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:38:50.116] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[10:38:50.116] <TB1> INFO: Decoding statistics:
[10:38:50.116] <TB1> INFO: General information:
[10:38:50.116] <TB1> INFO: 16bit words read: 0
[10:38:50.116] <TB1> INFO: valid events total: 0
[10:38:50.117] <TB1> INFO: empty events: 0
[10:38:50.117] <TB1> INFO: valid events with pixels: 0
[10:38:50.117] <TB1> INFO: valid pixel hits: 0
[10:38:50.117] <TB1> INFO: Event errors: 0
[10:38:50.117] <TB1> INFO: start marker: 0
[10:38:50.117] <TB1> INFO: stop marker: 0
[10:38:50.117] <TB1> INFO: overflow: 0
[10:38:50.117] <TB1> INFO: invalid 5bit words: 0
[10:38:50.117] <TB1> INFO: invalid XOR eye diagram: 0
[10:38:50.117] <TB1> INFO: frame (failed synchr.): 0
[10:38:50.117] <TB1> INFO: idle data (no TBM trl): 0
[10:38:50.117] <TB1> INFO: no data (only TBM hdr): 0
[10:38:50.117] <TB1> INFO: TBM errors: 0
[10:38:50.117] <TB1> INFO: flawed TBM headers: 0
[10:38:50.117] <TB1> INFO: flawed TBM trailers: 0
[10:38:50.117] <TB1> INFO: event ID mismatches: 0
[10:38:50.117] <TB1> INFO: ROC errors: 0
[10:38:50.117] <TB1> INFO: missing ROC header(s): 0
[10:38:50.117] <TB1> INFO: misplaced readback start: 0
[10:38:50.117] <TB1> INFO: Pixel decoding errors: 0
[10:38:50.117] <TB1> INFO: pixel data incomplete: 0
[10:38:50.117] <TB1> INFO: pixel address: 0
[10:38:50.117] <TB1> INFO: pulse height fill bit: 0
[10:38:50.117] <TB1> INFO: buffer corruption: 0
[10:38:50.126] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C15.dat
[10:38:50.127] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[10:38:50.127] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[10:38:50.127] <TB1> INFO: ######################################################################
[10:38:50.127] <TB1> INFO: PixTestReadback::doTest()
[10:38:50.127] <TB1> INFO: ######################################################################
[10:38:50.127] <TB1> INFO: ----------------------------------------------------------------------
[10:38:50.127] <TB1> INFO: PixTestReadback::CalibrateVd()
[10:38:50.127] <TB1> INFO: ----------------------------------------------------------------------
[10:39:00.085] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C0.dat
[10:39:00.085] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C1.dat
[10:39:00.085] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C2.dat
[10:39:00.085] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C3.dat
[10:39:00.086] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C4.dat
[10:39:00.086] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C5.dat
[10:39:00.086] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C6.dat
[10:39:00.086] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C7.dat
[10:39:00.086] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C8.dat
[10:39:00.086] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C9.dat
[10:39:00.086] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C10.dat
[10:39:00.086] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C11.dat
[10:39:00.087] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C12.dat
[10:39:00.087] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C13.dat
[10:39:00.087] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C14.dat
[10:39:00.087] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C15.dat
[10:39:00.116] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[10:39:00.116] <TB1> INFO: ----------------------------------------------------------------------
[10:39:00.116] <TB1> INFO: PixTestReadback::CalibrateVa()
[10:39:00.116] <TB1> INFO: ----------------------------------------------------------------------
[10:39:10.048] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C0.dat
[10:39:10.048] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C1.dat
[10:39:10.048] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C2.dat
[10:39:10.049] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C3.dat
[10:39:10.049] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C4.dat
[10:39:10.049] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C5.dat
[10:39:10.049] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C6.dat
[10:39:10.049] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C7.dat
[10:39:10.049] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C8.dat
[10:39:10.049] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C9.dat
[10:39:10.049] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C10.dat
[10:39:10.049] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C11.dat
[10:39:10.050] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C12.dat
[10:39:10.050] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C13.dat
[10:39:10.050] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C14.dat
[10:39:10.050] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C15.dat
[10:39:10.079] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[10:39:10.079] <TB1> INFO: ----------------------------------------------------------------------
[10:39:10.079] <TB1> INFO: PixTestReadback::readbackVbg()
[10:39:10.079] <TB1> INFO: ----------------------------------------------------------------------
[10:39:17.747] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[10:39:17.747] <TB1> INFO: ----------------------------------------------------------------------
[10:39:17.747] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[10:39:17.747] <TB1> INFO: ----------------------------------------------------------------------
[10:39:17.747] <TB1> INFO: Vbg will be calibrated using Vd calibration
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 158.2calibrated Vbg = 1.18617 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 152calibrated Vbg = 1.17546 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 156.2calibrated Vbg = 1.17905 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 155.4calibrated Vbg = 1.17468 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 162.4calibrated Vbg = 1.17877 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 162.6calibrated Vbg = 1.18314 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 148.4calibrated Vbg = 1.18628 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 156.7calibrated Vbg = 1.17836 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 154.4calibrated Vbg = 1.18009 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 149.2calibrated Vbg = 1.17843 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 159.7calibrated Vbg = 1.16933 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 160calibrated Vbg = 1.17157 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 166.9calibrated Vbg = 1.17965 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 152.9calibrated Vbg = 1.17911 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 156.1calibrated Vbg = 1.1796 :::*/*/*/*/
[10:39:17.748] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 150.3calibrated Vbg = 1.18197 :::*/*/*/*/
[10:39:17.751] <TB1> INFO: ----------------------------------------------------------------------
[10:39:17.751] <TB1> INFO: PixTestReadback::CalibrateIa()
[10:39:17.751] <TB1> INFO: ----------------------------------------------------------------------
[10:41:58.606] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C0.dat
[10:41:58.607] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C1.dat
[10:41:58.607] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C2.dat
[10:41:58.607] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C3.dat
[10:41:58.607] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C4.dat
[10:41:58.607] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C5.dat
[10:41:58.607] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C6.dat
[10:41:58.607] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C7.dat
[10:41:58.607] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C8.dat
[10:41:58.607] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C9.dat
[10:41:58.608] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C10.dat
[10:41:58.608] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C11.dat
[10:41:58.608] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C12.dat
[10:41:58.608] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C13.dat
[10:41:58.608] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C14.dat
[10:41:58.608] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//readbackCal_C15.dat
[10:41:58.641] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[10:41:58.642] <TB1> INFO: PixTestReadback::doTest() done
[10:41:58.642] <TB1> INFO: Decoding statistics:
[10:41:58.642] <TB1> INFO: General information:
[10:41:58.642] <TB1> INFO: 16bit words read: 1536
[10:41:58.642] <TB1> INFO: valid events total: 256
[10:41:58.642] <TB1> INFO: empty events: 256
[10:41:58.642] <TB1> INFO: valid events with pixels: 0
[10:41:58.642] <TB1> INFO: valid pixel hits: 0
[10:41:58.642] <TB1> INFO: Event errors: 0
[10:41:58.642] <TB1> INFO: start marker: 0
[10:41:58.642] <TB1> INFO: stop marker: 0
[10:41:58.642] <TB1> INFO: overflow: 0
[10:41:58.642] <TB1> INFO: invalid 5bit words: 0
[10:41:58.642] <TB1> INFO: invalid XOR eye diagram: 0
[10:41:58.642] <TB1> INFO: frame (failed synchr.): 0
[10:41:58.642] <TB1> INFO: idle data (no TBM trl): 0
[10:41:58.642] <TB1> INFO: no data (only TBM hdr): 0
[10:41:58.642] <TB1> INFO: TBM errors: 0
[10:41:58.642] <TB1> INFO: flawed TBM headers: 0
[10:41:58.642] <TB1> INFO: flawed TBM trailers: 0
[10:41:58.642] <TB1> INFO: event ID mismatches: 0
[10:41:58.642] <TB1> INFO: ROC errors: 0
[10:41:58.642] <TB1> INFO: missing ROC header(s): 0
[10:41:58.642] <TB1> INFO: misplaced readback start: 0
[10:41:58.642] <TB1> INFO: Pixel decoding errors: 0
[10:41:58.642] <TB1> INFO: pixel data incomplete: 0
[10:41:58.642] <TB1> INFO: pixel address: 0
[10:41:58.642] <TB1> INFO: pulse height fill bit: 0
[10:41:58.642] <TB1> INFO: buffer corruption: 0
[10:41:58.691] <TB1> INFO: ######################################################################
[10:41:58.691] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[10:41:58.691] <TB1> INFO: ######################################################################
[10:41:58.694] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[10:41:58.707] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[10:41:58.707] <TB1> INFO: run 1 of 1
[10:41:58.947] <TB1> INFO: Expecting 3120000 events.
[10:42:30.519] <TB1> INFO: 675840 events read in total (30980ms).
[10:43:00.700] <TB1> INFO: 1346750 events read in total (61161ms).
[10:43:12.934] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (63) != TBM ID (129)

[10:43:13.072] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 63 63 129 63 63 63 63 63

[10:43:13.072] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (64)

[10:43:13.073] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:43:13.073] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a043 8040 4810 4c8 27ef 4811 4c8 27ef e022 c000

[10:43:13.073] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03d 80c0 4810 4c8 27ef 4810 4c8 27ef e022 c000

[10:43:13.073] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a03e 8000 4810 4c8 27ef 4810 4c8 27ef e022 c000

[10:43:13.073] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4811 4811 27ef 4813 4c8 27ef e022 c000

[10:43:13.073] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a040 80b1 4810 4c8 27ef 4810 4c8 27ef e022 c000

[10:43:13.073] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a041 80c0 4811 4c8 27ef 4811 4c8 27ef e022 c000

[10:43:13.073] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a042 8000 4810 4c8 27ef 4810 4c8 27ef e022 c000

[10:43:13.074] <TB1> WARNING: Channel 0 ROC 0: Readback start marker after 32 readouts!

[10:43:13.074] <TB1> WARNING: Channel 0 ROC 1: Readback start marker after 32 readouts!

[10:43:13.075] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:43:13.075] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a052 8000 4810 4c8 27ef 4810 4c8 27ef e022 c000

[10:43:13.075] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04c 80b1 4810 4c8 27ef 4810 4c8 27ef e022 c000

[10:43:13.075] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04d 80c0 4811 4c8 27ef 4811 4c8 27ef e022 c000

[10:43:13.075] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04e 8000 4810 4c8 27ef 4810 4c8 27ef e022 c000

[10:43:13.075] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a04f 8040 4812 4c8 27ef 4812 4c8 27ef e022 c000

[10:43:13.075] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a050 80b1 4810 4c8 27ef 4810 4c8 27ef e022 c000

[10:43:13.075] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a051 80c0 4811 4c8 27ef 4811 4c8 27ef e022 c000

[10:43:30.909] <TB1> INFO: 2012760 events read in total (91370ms).
[10:43:43.140] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (217) != TBM ID (129)

[10:43:43.280] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 217 217 129 217 217 217 217 217

[10:43:43.282] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (218)

[10:43:43.283] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:43:43.283] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dd 80c0 4811 82a 27c4 4811 82a 27ef e022 c000

[10:43:43.283] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d7 8040 4810 82a 27c1 4810 82a 27ef e022 c000

[10:43:43.283] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0d8 80b1 4810 82a 27c1 4810 82a 27ef e022 c000

[10:43:43.283] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4811 4811 27c1 4811 82a 27ef e022 c000

[10:43:43.283] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0da 8000 4811 82a 27c1 4811 82a 27ef e022 c000

[10:43:43.283] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0db 8040 4810 82a 27c0 4810 82a 27ef e022 c000

[10:43:43.283] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0dc 80b1 4810 82a 27af 4810 82a 27ef e022 c000

[10:44:00.858] <TB1> INFO: 2678840 events read in total (121319ms).
[10:44:09.062] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (185) != TBM ID (129)

[10:44:09.200] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 185 185 129 185 185 185 185 185

[10:44:09.200] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (186)

[10:44:09.200] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[10:44:09.200] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bd 80c0 4811 a8c 27ef 4811 a8c 27ef e022 c000

[10:44:09.200] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b7 8040 4810 a8c 27ef 4810 a8c 27ef e022 c000

[10:44:09.200] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0b8 80b1 4810 a8c 27ef 4810 a8c 27ef e022 c000

[10:44:09.200] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4811 4811 27ef 4811 a8c 27ef e022 c000

[10:44:09.200] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ba 8000 4811 a8c 27ef 4811 a8c 27ef e022 c000

[10:44:09.200] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bb 8040 4811 a8c 27ef 4811 a8c 27ef e022 c000

[10:44:09.200] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0bc 80b1 4810 a8c 27ef 4810 a8c 27ef e022 c000

[10:44:20.561] <TB1> INFO: 3120000 events read in total (141022ms).
[10:44:20.623] <TB1> INFO: Test took 141917ms.
[10:44:46.132] <TB1> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 167 seconds
[10:44:46.132] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:44:46.132] <TB1> INFO: separation cut (per ROC): 109 110 121 111 112 110 107 101 112 104 107 118 101 99 129 115
[10:44:46.132] <TB1> INFO: Decoding statistics:
[10:44:46.132] <TB1> INFO: General information:
[10:44:46.132] <TB1> INFO: 16bit words read: 0
[10:44:46.132] <TB1> INFO: valid events total: 0
[10:44:46.132] <TB1> INFO: empty events: 0
[10:44:46.132] <TB1> INFO: valid events with pixels: 0
[10:44:46.132] <TB1> INFO: valid pixel hits: 0
[10:44:46.132] <TB1> INFO: Event errors: 0
[10:44:46.132] <TB1> INFO: start marker: 0
[10:44:46.132] <TB1> INFO: stop marker: 0
[10:44:46.132] <TB1> INFO: overflow: 0
[10:44:46.132] <TB1> INFO: invalid 5bit words: 0
[10:44:46.132] <TB1> INFO: invalid XOR eye diagram: 0
[10:44:46.132] <TB1> INFO: frame (failed synchr.): 0
[10:44:46.132] <TB1> INFO: idle data (no TBM trl): 0
[10:44:46.132] <TB1> INFO: no data (only TBM hdr): 0
[10:44:46.132] <TB1> INFO: TBM errors: 0
[10:44:46.132] <TB1> INFO: flawed TBM headers: 0
[10:44:46.132] <TB1> INFO: flawed TBM trailers: 0
[10:44:46.132] <TB1> INFO: event ID mismatches: 0
[10:44:46.132] <TB1> INFO: ROC errors: 0
[10:44:46.132] <TB1> INFO: missing ROC header(s): 0
[10:44:46.132] <TB1> INFO: misplaced readback start: 0
[10:44:46.132] <TB1> INFO: Pixel decoding errors: 0
[10:44:46.132] <TB1> INFO: pixel data incomplete: 0
[10:44:46.132] <TB1> INFO: pixel address: 0
[10:44:46.132] <TB1> INFO: pulse height fill bit: 0
[10:44:46.132] <TB1> INFO: buffer corruption: 0
[10:44:46.180] <TB1> INFO: ######################################################################
[10:44:46.180] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[10:44:46.180] <TB1> INFO: ######################################################################
[10:44:46.181] <TB1> INFO: ----------------------------------------------------------------------
[10:44:46.181] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[10:44:46.181] <TB1> INFO: ----------------------------------------------------------------------
[10:44:46.181] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[10:44:46.195] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[10:44:46.195] <TB1> INFO: run 1 of 1
[10:44:46.483] <TB1> INFO: Expecting 36608000 events.
[10:45:09.898] <TB1> INFO: 666050 events read in total (22823ms).
[10:45:32.360] <TB1> INFO: 1317150 events read in total (45285ms).
[10:45:54.971] <TB1> INFO: 1971500 events read in total (67896ms).
[10:46:17.446] <TB1> INFO: 2622950 events read in total (90371ms).
[10:46:40.238] <TB1> INFO: 3278400 events read in total (113163ms).
[10:47:02.568] <TB1> INFO: 3931100 events read in total (135493ms).
[10:47:25.061] <TB1> INFO: 4583600 events read in total (157986ms).
[10:47:47.801] <TB1> INFO: 5236250 events read in total (180726ms).
[10:48:10.318] <TB1> INFO: 5889000 events read in total (203243ms).
[10:48:33.292] <TB1> INFO: 6544600 events read in total (226217ms).
[10:48:55.890] <TB1> INFO: 7197300 events read in total (248815ms).
[10:49:18.358] <TB1> INFO: 7852550 events read in total (271283ms).
[10:49:40.854] <TB1> INFO: 8504050 events read in total (293779ms).
[10:50:03.451] <TB1> INFO: 9158150 events read in total (316376ms).
[10:50:25.815] <TB1> INFO: 9807000 events read in total (338740ms).
[10:50:48.367] <TB1> INFO: 10458400 events read in total (361292ms).
[10:51:10.811] <TB1> INFO: 11107200 events read in total (383736ms).
[10:51:33.461] <TB1> INFO: 11759250 events read in total (406386ms).
[10:51:55.864] <TB1> INFO: 12410350 events read in total (428789ms).
[10:52:18.483] <TB1> INFO: 13061400 events read in total (451408ms).
[10:52:40.912] <TB1> INFO: 13712150 events read in total (473837ms).
[10:53:03.465] <TB1> INFO: 14361500 events read in total (496390ms).
[10:53:25.975] <TB1> INFO: 15012050 events read in total (518900ms).
[10:53:48.481] <TB1> INFO: 15661400 events read in total (541406ms).
[10:54:10.994] <TB1> INFO: 16313250 events read in total (563919ms).
[10:54:33.430] <TB1> INFO: 16962700 events read in total (586355ms).
[10:54:56.180] <TB1> INFO: 17613500 events read in total (609105ms).
[10:55:18.473] <TB1> INFO: 18258700 events read in total (631398ms).
[10:55:40.995] <TB1> INFO: 18908700 events read in total (653920ms).
[10:56:03.767] <TB1> INFO: 19554200 events read in total (676692ms).
[10:56:26.247] <TB1> INFO: 20202200 events read in total (699172ms).
[10:56:48.799] <TB1> INFO: 20847450 events read in total (721724ms).
[10:57:11.417] <TB1> INFO: 21495350 events read in total (744342ms).
[10:57:33.811] <TB1> INFO: 22140400 events read in total (766736ms).
[10:57:56.421] <TB1> INFO: 22787200 events read in total (789346ms).
[10:58:18.927] <TB1> INFO: 23433150 events read in total (811852ms).
[10:58:41.434] <TB1> INFO: 24077300 events read in total (834359ms).
[10:59:04.030] <TB1> INFO: 24725450 events read in total (856955ms).
[10:59:26.478] <TB1> INFO: 25369550 events read in total (879403ms).
[10:59:48.937] <TB1> INFO: 26018000 events read in total (901862ms).
[11:00:11.259] <TB1> INFO: 26661500 events read in total (924184ms).
[11:00:33.576] <TB1> INFO: 27307100 events read in total (946501ms).
[11:00:55.874] <TB1> INFO: 27951800 events read in total (968799ms).
[11:01:17.915] <TB1> INFO: 28596100 events read in total (990840ms).
[11:01:40.197] <TB1> INFO: 29238950 events read in total (1013122ms).
[11:02:02.525] <TB1> INFO: 29881250 events read in total (1035450ms).
[11:02:24.971] <TB1> INFO: 30524500 events read in total (1057896ms).
[11:02:47.176] <TB1> INFO: 31166500 events read in total (1080101ms).
[11:03:09.476] <TB1> INFO: 31811550 events read in total (1102401ms).
[11:03:31.838] <TB1> INFO: 32454750 events read in total (1124763ms).
[11:03:54.222] <TB1> INFO: 33100950 events read in total (1147147ms).
[11:04:16.684] <TB1> INFO: 33740900 events read in total (1169609ms).
[11:04:39.203] <TB1> INFO: 34386350 events read in total (1192128ms).
[11:05:01.703] <TB1> INFO: 35029050 events read in total (1214628ms).
[11:05:23.996] <TB1> INFO: 35673850 events read in total (1236921ms).
[11:05:46.732] <TB1> INFO: 36325100 events read in total (1259657ms).
[11:05:57.050] <TB1> INFO: 36608000 events read in total (1269975ms).
[11:05:57.154] <TB1> INFO: Test took 1270959ms.
[11:05:57.777] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:00.015] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:02.336] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:04.411] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:06.918] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:08.837] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:10.849] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:12.867] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:15.284] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:16.939] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:18.530] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:20.178] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:21.781] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:23.342] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:25.316] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:27.261] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[11:06:29.360] <TB1> INFO: PixTestScurves::scurves() done
[11:06:29.360] <TB1> INFO: Vcal mean: 113.66 109.22 124.74 117.31 116.66 116.19 114.71 103.92 120.09 109.75 111.99 112.73 107.08 100.22 126.50 120.21
[11:06:29.360] <TB1> INFO: Vcal RMS: 5.75 5.24 5.95 6.12 6.23 6.44 5.47 4.95 6.16 4.98 5.41 5.24 5.47 5.38 6.20 6.06
[11:06:29.360] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1303 seconds
[11:06:29.360] <TB1> INFO: Decoding statistics:
[11:06:29.360] <TB1> INFO: General information:
[11:06:29.360] <TB1> INFO: 16bit words read: 0
[11:06:29.360] <TB1> INFO: valid events total: 0
[11:06:29.360] <TB1> INFO: empty events: 0
[11:06:29.360] <TB1> INFO: valid events with pixels: 0
[11:06:29.360] <TB1> INFO: valid pixel hits: 0
[11:06:29.360] <TB1> INFO: Event errors: 0
[11:06:29.360] <TB1> INFO: start marker: 0
[11:06:29.360] <TB1> INFO: stop marker: 0
[11:06:29.360] <TB1> INFO: overflow: 0
[11:06:29.360] <TB1> INFO: invalid 5bit words: 0
[11:06:29.360] <TB1> INFO: invalid XOR eye diagram: 0
[11:06:29.360] <TB1> INFO: frame (failed synchr.): 0
[11:06:29.360] <TB1> INFO: idle data (no TBM trl): 0
[11:06:29.360] <TB1> INFO: no data (only TBM hdr): 0
[11:06:29.360] <TB1> INFO: TBM errors: 0
[11:06:29.360] <TB1> INFO: flawed TBM headers: 0
[11:06:29.360] <TB1> INFO: flawed TBM trailers: 0
[11:06:29.360] <TB1> INFO: event ID mismatches: 0
[11:06:29.360] <TB1> INFO: ROC errors: 0
[11:06:29.360] <TB1> INFO: missing ROC header(s): 0
[11:06:29.360] <TB1> INFO: misplaced readback start: 0
[11:06:29.360] <TB1> INFO: Pixel decoding errors: 0
[11:06:29.360] <TB1> INFO: pixel data incomplete: 0
[11:06:29.360] <TB1> INFO: pixel address: 0
[11:06:29.360] <TB1> INFO: pulse height fill bit: 0
[11:06:29.360] <TB1> INFO: buffer corruption: 0
[11:06:29.430] <TB1> INFO: ######################################################################
[11:06:29.430] <TB1> INFO: PixTestTrim::doTest()
[11:06:29.430] <TB1> INFO: ######################################################################
[11:06:29.433] <TB1> INFO: ----------------------------------------------------------------------
[11:06:29.433] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[11:06:29.433] <TB1> INFO: ----------------------------------------------------------------------
[11:06:29.497] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[11:06:29.497] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:06:29.511] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:06:29.511] <TB1> INFO: run 1 of 1
[11:06:29.793] <TB1> INFO: Expecting 5025280 events.
[11:07:00.516] <TB1> INFO: 820904 events read in total (30124ms).
[11:07:30.599] <TB1> INFO: 1639488 events read in total (60207ms).
[11:08:00.709] <TB1> INFO: 2455360 events read in total (90317ms).
[11:08:30.900] <TB1> INFO: 3269712 events read in total (120508ms).
[11:09:00.871] <TB1> INFO: 4080968 events read in total (150480ms).
[11:09:30.893] <TB1> INFO: 4890600 events read in total (180501ms).
[11:09:36.302] <TB1> INFO: 5025280 events read in total (185910ms).
[11:09:36.356] <TB1> INFO: Test took 186846ms.
[11:09:57.788] <TB1> INFO: ROC 0 VthrComp = 119
[11:09:57.788] <TB1> INFO: ROC 1 VthrComp = 117
[11:09:57.821] <TB1> INFO: ROC 2 VthrComp = 128
[11:09:57.821] <TB1> INFO: ROC 3 VthrComp = 121
[11:09:57.821] <TB1> INFO: ROC 4 VthrComp = 121
[11:09:57.821] <TB1> INFO: ROC 5 VthrComp = 116
[11:09:57.821] <TB1> INFO: ROC 6 VthrComp = 120
[11:09:57.821] <TB1> INFO: ROC 7 VthrComp = 104
[11:09:57.822] <TB1> INFO: ROC 8 VthrComp = 126
[11:09:57.822] <TB1> INFO: ROC 9 VthrComp = 116
[11:09:57.822] <TB1> INFO: ROC 10 VthrComp = 110
[11:09:57.823] <TB1> INFO: ROC 11 VthrComp = 117
[11:09:57.823] <TB1> INFO: ROC 12 VthrComp = 104
[11:09:57.823] <TB1> INFO: ROC 13 VthrComp = 104
[11:09:57.823] <TB1> INFO: ROC 14 VthrComp = 131
[11:09:57.823] <TB1> INFO: ROC 15 VthrComp = 126
[11:09:58.076] <TB1> INFO: Expecting 41600 events.
[11:10:01.553] <TB1> INFO: 41600 events read in total (2877ms).
[11:10:01.554] <TB1> INFO: Test took 3730ms.
[11:10:01.565] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[11:10:01.565] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[11:10:01.579] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:10:01.579] <TB1> INFO: run 1 of 1
[11:10:01.858] <TB1> INFO: Expecting 5025280 events.
[11:10:27.994] <TB1> INFO: 590336 events read in total (25544ms).
[11:10:53.789] <TB1> INFO: 1180160 events read in total (51339ms).
[11:11:19.974] <TB1> INFO: 1769832 events read in total (77524ms).
[11:11:45.548] <TB1> INFO: 2359584 events read in total (103098ms).
[11:12:11.534] <TB1> INFO: 2946304 events read in total (129084ms).
[11:12:37.290] <TB1> INFO: 3531688 events read in total (154840ms).
[11:13:03.054] <TB1> INFO: 4116272 events read in total (180604ms).
[11:13:28.681] <TB1> INFO: 4700568 events read in total (206231ms).
[11:13:42.917] <TB1> INFO: 5025280 events read in total (220467ms).
[11:13:43.122] <TB1> INFO: Test took 221542ms.
[11:14:09.550] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 59.9077 for pixel 22/11 mean/min/max = 45.5425/31.0782/60.0067
[11:14:09.551] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 59.1035 for pixel 22/2 mean/min/max = 45.3416/31.0381/59.6451
[11:14:09.551] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 61.9432 for pixel 15/16 mean/min/max = 46.0409/30.1336/61.9482
[11:14:09.552] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 63.3875 for pixel 0/2 mean/min/max = 47.2187/30.9452/63.4922
[11:14:09.552] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 62.0543 for pixel 0/1 mean/min/max = 46.5256/30.9203/62.1309
[11:14:09.552] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 62.4637 for pixel 18/2 mean/min/max = 46.804/31.1321/62.4759
[11:14:09.553] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 60.5664 for pixel 19/1 mean/min/max = 46.2979/31.9443/60.6514
[11:14:09.554] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 59.9999 for pixel 7/14 mean/min/max = 47.4366/34.7109/60.1622
[11:14:09.554] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 59.9788 for pixel 2/12 mean/min/max = 45.2477/30.4363/60.0591
[11:14:09.554] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 59.0349 for pixel 22/6 mean/min/max = 45.4851/31.4969/59.4734
[11:14:09.555] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 63.828 for pixel 3/34 mean/min/max = 49.0019/33.871/64.1329
[11:14:09.555] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 60.7656 for pixel 0/9 mean/min/max = 46.0838/31.3439/60.8237
[11:14:09.556] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 62.5758 for pixel 1/77 mean/min/max = 48.0691/33.5042/62.634
[11:14:09.556] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 60.8089 for pixel 11/49 mean/min/max = 47.8381/34.8215/60.8547
[11:14:09.557] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 61.5106 for pixel 23/4 mean/min/max = 46.8345/31.9835/61.6855
[11:14:09.557] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 59.8398 for pixel 30/32 mean/min/max = 45.6385/31.4341/59.8429
[11:14:09.557] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:14:09.646] <TB1> INFO: Expecting 411648 events.
[11:14:18.936] <TB1> INFO: 411648 events read in total (8698ms).
[11:14:18.944] <TB1> INFO: Expecting 411648 events.
[11:14:28.390] <TB1> INFO: 411648 events read in total (9043ms).
[11:14:28.405] <TB1> INFO: Expecting 411648 events.
[11:14:37.765] <TB1> INFO: 411648 events read in total (8957ms).
[11:14:37.783] <TB1> INFO: Expecting 411648 events.
[11:14:47.126] <TB1> INFO: 411648 events read in total (8939ms).
[11:14:47.147] <TB1> INFO: Expecting 411648 events.
[11:14:56.584] <TB1> INFO: 411648 events read in total (9033ms).
[11:14:56.609] <TB1> INFO: Expecting 411648 events.
[11:15:05.954] <TB1> INFO: 411648 events read in total (8942ms).
[11:15:05.977] <TB1> INFO: Expecting 411648 events.
[11:15:15.333] <TB1> INFO: 411648 events read in total (8953ms).
[11:15:15.366] <TB1> INFO: Expecting 411648 events.
[11:15:24.675] <TB1> INFO: 411648 events read in total (8906ms).
[11:15:24.706] <TB1> INFO: Expecting 411648 events.
[11:15:34.115] <TB1> INFO: 411648 events read in total (9006ms).
[11:15:34.148] <TB1> INFO: Expecting 411648 events.
[11:15:43.525] <TB1> INFO: 411648 events read in total (8973ms).
[11:15:43.568] <TB1> INFO: Expecting 411648 events.
[11:15:53.030] <TB1> INFO: 411648 events read in total (9059ms).
[11:15:53.076] <TB1> INFO: Expecting 411648 events.
[11:16:02.466] <TB1> INFO: 411648 events read in total (8987ms).
[11:16:02.521] <TB1> INFO: Expecting 411648 events.
[11:16:11.856] <TB1> INFO: 411648 events read in total (8932ms).
[11:16:11.904] <TB1> INFO: Expecting 411648 events.
[11:16:21.236] <TB1> INFO: 411648 events read in total (8929ms).
[11:16:21.285] <TB1> INFO: Expecting 411648 events.
[11:16:30.723] <TB1> INFO: 411648 events read in total (9034ms).
[11:16:30.795] <TB1> INFO: Expecting 411648 events.
[11:16:40.016] <TB1> INFO: 411648 events read in total (8818ms).
[11:16:40.078] <TB1> INFO: Test took 150521ms.
[11:16:40.811] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[11:16:40.826] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:16:40.826] <TB1> INFO: run 1 of 1
[11:16:41.098] <TB1> INFO: Expecting 5025280 events.
[11:17:07.557] <TB1> INFO: 590400 events read in total (25867ms).
[11:17:33.554] <TB1> INFO: 1179112 events read in total (51864ms).
[11:17:59.892] <TB1> INFO: 1767168 events read in total (78203ms).
[11:18:26.328] <TB1> INFO: 2355328 events read in total (104638ms).
[11:18:52.535] <TB1> INFO: 2943232 events read in total (130845ms).
[11:19:18.552] <TB1> INFO: 3530216 events read in total (156862ms).
[11:19:44.698] <TB1> INFO: 4117200 events read in total (183008ms).
[11:20:10.537] <TB1> INFO: 4704728 events read in total (208847ms).
[11:20:25.326] <TB1> INFO: 5025280 events read in total (223636ms).
[11:20:25.479] <TB1> INFO: Test took 224654ms.
[11:20:49.422] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 2.170118 .. 147.627548
[11:20:49.748] <TB1> INFO: Expecting 208000 events.
[11:20:59.403] <TB1> INFO: 208000 events read in total (9063ms).
[11:20:59.404] <TB1> INFO: Test took 9980ms.
[11:20:59.455] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 2 .. 157 (-1/-1) hits flags = 528 (plus default)
[11:20:59.469] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:20:59.469] <TB1> INFO: run 1 of 1
[11:20:59.746] <TB1> INFO: Expecting 5191680 events.
[11:21:25.594] <TB1> INFO: 582504 events read in total (25256ms).
[11:21:50.878] <TB1> INFO: 1165288 events read in total (50540ms).
[11:22:16.469] <TB1> INFO: 1747120 events read in total (76131ms).
[11:22:42.161] <TB1> INFO: 2329600 events read in total (101823ms).
[11:23:07.444] <TB1> INFO: 2911832 events read in total (127106ms).
[11:23:33.113] <TB1> INFO: 3493632 events read in total (152775ms).
[11:23:58.548] <TB1> INFO: 4075032 events read in total (178210ms).
[11:24:24.435] <TB1> INFO: 4655640 events read in total (204097ms).
[11:24:48.782] <TB1> INFO: 5191680 events read in total (228444ms).
[11:24:48.897] <TB1> INFO: Test took 229429ms.
[11:25:15.034] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 28.013669 .. 47.361529
[11:25:15.364] <TB1> INFO: Expecting 208000 events.
[11:25:25.313] <TB1> INFO: 208000 events read in total (9357ms).
[11:25:25.314] <TB1> INFO: Test took 10274ms.
[11:25:25.389] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 18 .. 57 (-1/-1) hits flags = 528 (plus default)
[11:25:25.403] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:25:25.403] <TB1> INFO: run 1 of 1
[11:25:25.681] <TB1> INFO: Expecting 1331200 events.
[11:25:54.059] <TB1> INFO: 645960 events read in total (27786ms).
[11:26:21.103] <TB1> INFO: 1290080 events read in total (54830ms).
[11:26:23.329] <TB1> INFO: 1331200 events read in total (57056ms).
[11:26:23.358] <TB1> INFO: Test took 57955ms.
[11:26:36.236] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 26.526365 .. 46.241956
[11:26:36.475] <TB1> INFO: Expecting 208000 events.
[11:26:46.600] <TB1> INFO: 208000 events read in total (9533ms).
[11:26:46.601] <TB1> INFO: Test took 10363ms.
[11:26:46.648] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 56 (-1/-1) hits flags = 528 (plus default)
[11:26:46.661] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:26:46.662] <TB1> INFO: run 1 of 1
[11:26:46.940] <TB1> INFO: Expecting 1364480 events.
[11:27:15.172] <TB1> INFO: 659072 events read in total (27640ms).
[11:27:43.032] <TB1> INFO: 1316592 events read in total (55500ms).
[11:27:45.667] <TB1> INFO: 1364480 events read in total (58136ms).
[11:27:45.706] <TB1> INFO: Test took 59045ms.
[11:28:00.907] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 25.007423 .. 43.605337
[11:28:01.176] <TB1> INFO: Expecting 208000 events.
[11:28:11.057] <TB1> INFO: 208000 events read in total (9289ms).
[11:28:11.058] <TB1> INFO: Test took 10150ms.
[11:28:11.113] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 15 .. 53 (-1/-1) hits flags = 528 (plus default)
[11:28:11.127] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:28:11.127] <TB1> INFO: run 1 of 1
[11:28:11.405] <TB1> INFO: Expecting 1297920 events.
[11:28:40.217] <TB1> INFO: 676072 events read in total (28221ms).
[11:29:05.712] <TB1> INFO: 1297920 events read in total (53716ms).
[11:29:05.743] <TB1> INFO: Test took 54617ms.
[11:29:18.686] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[11:29:18.686] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[11:29:18.700] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[11:29:18.700] <TB1> INFO: run 1 of 1
[11:29:18.945] <TB1> INFO: Expecting 1364480 events.
[11:29:47.352] <TB1> INFO: 667392 events read in total (27816ms).
[11:30:14.740] <TB1> INFO: 1333904 events read in total (55204ms).
[11:30:16.392] <TB1> INFO: 1364480 events read in total (56856ms).
[11:30:16.419] <TB1> INFO: Test took 57720ms.
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C0.dat
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C1.dat
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C2.dat
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C3.dat
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C4.dat
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C5.dat
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C6.dat
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C7.dat
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C8.dat
[11:30:29.147] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C9.dat
[11:30:29.148] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C10.dat
[11:30:29.148] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C11.dat
[11:30:29.148] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C12.dat
[11:30:29.148] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C13.dat
[11:30:29.148] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C14.dat
[11:30:29.148] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C15.dat
[11:30:29.148] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C0.dat
[11:30:29.156] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C1.dat
[11:30:29.164] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C2.dat
[11:30:29.171] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C3.dat
[11:30:29.179] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C4.dat
[11:30:29.186] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C5.dat
[11:30:29.194] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C6.dat
[11:30:29.202] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C7.dat
[11:30:29.209] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C8.dat
[11:30:29.217] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C9.dat
[11:30:29.224] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C10.dat
[11:30:29.232] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C11.dat
[11:30:29.240] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C12.dat
[11:30:29.247] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C13.dat
[11:30:29.255] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C14.dat
[11:30:29.262] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//trimParameters35_C15.dat
[11:30:29.270] <TB1> INFO: PixTestTrim::trimTest() done
[11:30:29.270] <TB1> INFO: vtrim: 145 111 129 122 122 134 132 105 127 120 141 121 115 135 123 129
[11:30:29.270] <TB1> INFO: vthrcomp: 119 117 128 121 121 116 120 104 126 116 110 117 104 104 131 126
[11:30:29.270] <TB1> INFO: vcal mean: 34.98 34.98 34.95 35.03 34.95 34.97 35.03 35.01 34.93 34.96 35.01 34.96 35.00 35.01 34.99 34.94
[11:30:29.270] <TB1> INFO: vcal RMS: 1.08 1.04 1.17 1.19 1.14 1.17 1.10 0.91 1.09 1.01 1.05 0.99 1.04 0.94 1.01 1.04
[11:30:29.270] <TB1> INFO: bits mean: 9.96 9.54 9.86 9.47 8.92 9.78 9.82 8.83 10.07 9.70 9.06 9.07 8.92 9.00 9.56 9.86
[11:30:29.270] <TB1> INFO: bits RMS: 2.59 2.82 2.79 2.79 3.04 2.66 2.54 2.53 2.70 2.67 2.46 2.96 2.62 2.44 2.60 2.62
[11:30:29.278] <TB1> INFO: ----------------------------------------------------------------------
[11:30:29.278] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[11:30:29.278] <TB1> INFO: ----------------------------------------------------------------------
[11:30:29.282] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[11:30:29.295] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:30:29.295] <TB1> INFO: run 1 of 1
[11:30:29.561] <TB1> INFO: Expecting 4160000 events.
[11:31:01.992] <TB1> INFO: 735405 events read in total (31839ms).
[11:31:33.692] <TB1> INFO: 1466465 events read in total (63539ms).
[11:32:05.458] <TB1> INFO: 2194490 events read in total (95305ms).
[11:32:37.082] <TB1> INFO: 2918015 events read in total (126929ms).
[11:33:08.591] <TB1> INFO: 3638550 events read in total (158438ms).
[11:33:30.504] <TB1> INFO: 4160000 events read in total (180351ms).
[11:33:30.578] <TB1> INFO: Test took 181283ms.
[11:33:54.905] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[11:33:54.918] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:33:54.918] <TB1> INFO: run 1 of 1
[11:33:55.201] <TB1> INFO: Expecting 4139200 events.
[11:34:26.749] <TB1> INFO: 712770 events read in total (30956ms).
[11:34:58.044] <TB1> INFO: 1421580 events read in total (62251ms).
[11:35:29.039] <TB1> INFO: 2128035 events read in total (93246ms).
[11:35:59.604] <TB1> INFO: 2830245 events read in total (123811ms).
[11:36:30.458] <TB1> INFO: 3529930 events read in total (154665ms).
[11:36:56.973] <TB1> INFO: 4139200 events read in total (181180ms).
[11:36:57.075] <TB1> INFO: Test took 182156ms.
[11:37:21.994] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 189 (-1/-1) hits flags = 528 (plus default)
[11:37:22.007] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:37:22.008] <TB1> INFO: run 1 of 1
[11:37:22.285] <TB1> INFO: Expecting 3952000 events.
[11:37:53.621] <TB1> INFO: 724615 events read in total (30744ms).
[11:38:24.702] <TB1> INFO: 1445375 events read in total (61825ms).
[11:38:55.849] <TB1> INFO: 2162100 events read in total (92972ms).
[11:39:26.623] <TB1> INFO: 2875145 events read in total (123746ms).
[11:39:57.574] <TB1> INFO: 3585180 events read in total (154697ms).
[11:40:13.601] <TB1> INFO: 3952000 events read in total (170724ms).
[11:40:13.690] <TB1> INFO: Test took 171683ms.
[11:40:42.542] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 186 (-1/-1) hits flags = 528 (plus default)
[11:40:42.555] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:40:42.555] <TB1> INFO: run 1 of 1
[11:40:42.798] <TB1> INFO: Expecting 3889600 events.
[11:41:14.025] <TB1> INFO: 728680 events read in total (30635ms).
[11:41:45.309] <TB1> INFO: 1453340 events read in total (61919ms).
[11:42:16.630] <TB1> INFO: 2174105 events read in total (93240ms).
[11:42:48.006] <TB1> INFO: 2890755 events read in total (124616ms).
[11:43:19.321] <TB1> INFO: 3604315 events read in total (155931ms).
[11:43:31.546] <TB1> INFO: 3889600 events read in total (168156ms).
[11:43:31.603] <TB1> INFO: Test took 169048ms.
[11:43:55.586] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 187 (-1/-1) hits flags = 528 (plus default)
[11:43:55.599] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:43:55.599] <TB1> INFO: run 1 of 1
[11:43:55.875] <TB1> INFO: Expecting 3910400 events.
[11:44:27.187] <TB1> INFO: 727280 events read in total (30720ms).
[11:44:58.610] <TB1> INFO: 1450500 events read in total (62143ms).
[11:45:29.958] <TB1> INFO: 2169850 events read in total (93491ms).
[11:46:01.304] <TB1> INFO: 2885160 events read in total (124837ms).
[11:46:31.862] <TB1> INFO: 3597175 events read in total (155395ms).
[11:46:45.642] <TB1> INFO: 3910400 events read in total (169175ms).
[11:46:45.734] <TB1> INFO: Test took 170134ms.
[11:47:08.544] <TB1> INFO: PixTestTrim::trimBitTest() done
[11:47:08.545] <TB1> INFO: PixTestTrim::doTest() done, duration: 2439 seconds
[11:47:08.546] <TB1> INFO: Decoding statistics:
[11:47:08.546] <TB1> INFO: General information:
[11:47:08.546] <TB1> INFO: 16bit words read: 0
[11:47:08.546] <TB1> INFO: valid events total: 0
[11:47:08.546] <TB1> INFO: empty events: 0
[11:47:08.546] <TB1> INFO: valid events with pixels: 0
[11:47:08.546] <TB1> INFO: valid pixel hits: 0
[11:47:08.546] <TB1> INFO: Event errors: 0
[11:47:08.546] <TB1> INFO: start marker: 0
[11:47:08.546] <TB1> INFO: stop marker: 0
[11:47:08.546] <TB1> INFO: overflow: 0
[11:47:08.546] <TB1> INFO: invalid 5bit words: 0
[11:47:08.546] <TB1> INFO: invalid XOR eye diagram: 0
[11:47:08.546] <TB1> INFO: frame (failed synchr.): 0
[11:47:08.546] <TB1> INFO: idle data (no TBM trl): 0
[11:47:08.546] <TB1> INFO: no data (only TBM hdr): 0
[11:47:08.546] <TB1> INFO: TBM errors: 0
[11:47:08.546] <TB1> INFO: flawed TBM headers: 0
[11:47:08.546] <TB1> INFO: flawed TBM trailers: 0
[11:47:08.546] <TB1> INFO: event ID mismatches: 0
[11:47:08.546] <TB1> INFO: ROC errors: 0
[11:47:08.546] <TB1> INFO: missing ROC header(s): 0
[11:47:08.546] <TB1> INFO: misplaced readback start: 0
[11:47:08.546] <TB1> INFO: Pixel decoding errors: 0
[11:47:08.546] <TB1> INFO: pixel data incomplete: 0
[11:47:08.546] <TB1> INFO: pixel address: 0
[11:47:08.546] <TB1> INFO: pulse height fill bit: 0
[11:47:08.546] <TB1> INFO: buffer corruption: 0
[11:47:09.259] <TB1> INFO: ######################################################################
[11:47:09.259] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[11:47:09.259] <TB1> INFO: ######################################################################
[11:47:09.555] <TB1> INFO: Expecting 41600 events.
[11:47:13.076] <TB1> INFO: 41600 events read in total (2929ms).
[11:47:13.077] <TB1> INFO: Test took 3816ms.
[11:47:13.548] <TB1> INFO: Expecting 41600 events.
[11:47:17.230] <TB1> INFO: 41600 events read in total (3090ms).
[11:47:17.232] <TB1> INFO: Test took 3951ms.
[11:47:17.580] <TB1> INFO: Expecting 41600 events.
[11:47:21.179] <TB1> INFO: 41600 events read in total (3008ms).
[11:47:21.179] <TB1> INFO: Test took 3919ms.
[11:47:21.470] <TB1> INFO: Expecting 41600 events.
[11:47:25.018] <TB1> INFO: 41600 events read in total (2956ms).
[11:47:25.019] <TB1> INFO: Test took 3814ms.
[11:47:25.308] <TB1> INFO: Expecting 41600 events.
[11:47:28.909] <TB1> INFO: 41600 events read in total (3009ms).
[11:47:28.910] <TB1> INFO: Test took 3867ms.
[11:47:29.201] <TB1> INFO: Expecting 41600 events.
[11:47:32.934] <TB1> INFO: 41600 events read in total (3141ms).
[11:47:32.935] <TB1> INFO: Test took 4001ms.
[11:47:33.286] <TB1> INFO: Expecting 41600 events.
[11:47:36.815] <TB1> INFO: 41600 events read in total (2937ms).
[11:47:36.816] <TB1> INFO: Test took 3853ms.
[11:47:37.112] <TB1> INFO: Expecting 41600 events.
[11:47:40.603] <TB1> INFO: 41600 events read in total (2900ms).
[11:47:40.604] <TB1> INFO: Test took 3763ms.
[11:47:40.911] <TB1> INFO: Expecting 41600 events.
[11:47:44.421] <TB1> INFO: 41600 events read in total (2918ms).
[11:47:44.422] <TB1> INFO: Test took 3791ms.
[11:47:44.711] <TB1> INFO: Expecting 41600 events.
[11:47:48.192] <TB1> INFO: 41600 events read in total (2889ms).
[11:47:48.193] <TB1> INFO: Test took 3747ms.
[11:47:48.482] <TB1> INFO: Expecting 41600 events.
[11:47:52.087] <TB1> INFO: 41600 events read in total (3013ms).
[11:47:52.087] <TB1> INFO: Test took 3870ms.
[11:47:52.376] <TB1> INFO: Expecting 41600 events.
[11:47:55.959] <TB1> INFO: 41600 events read in total (2991ms).
[11:47:55.960] <TB1> INFO: Test took 3848ms.
[11:47:56.252] <TB1> INFO: Expecting 41600 events.
[11:47:59.842] <TB1> INFO: 41600 events read in total (2998ms).
[11:47:59.842] <TB1> INFO: Test took 3855ms.
[11:48:00.134] <TB1> INFO: Expecting 41600 events.
[11:48:03.695] <TB1> INFO: 41600 events read in total (2969ms).
[11:48:03.696] <TB1> INFO: Test took 3826ms.
[11:48:03.985] <TB1> INFO: Expecting 41600 events.
[11:48:07.520] <TB1> INFO: 41600 events read in total (2943ms).
[11:48:07.521] <TB1> INFO: Test took 3801ms.
[11:48:07.814] <TB1> INFO: Expecting 41600 events.
[11:48:11.337] <TB1> INFO: 41600 events read in total (2931ms).
[11:48:11.338] <TB1> INFO: Test took 3788ms.
[11:48:11.668] <TB1> INFO: Expecting 41600 events.
[11:48:15.196] <TB1> INFO: 41600 events read in total (2936ms).
[11:48:15.197] <TB1> INFO: Test took 3830ms.
[11:48:15.489] <TB1> INFO: Expecting 41600 events.
[11:48:18.972] <TB1> INFO: 41600 events read in total (2892ms).
[11:48:18.973] <TB1> INFO: Test took 3749ms.
[11:48:19.266] <TB1> INFO: Expecting 41600 events.
[11:48:22.862] <TB1> INFO: 41600 events read in total (3005ms).
[11:48:22.863] <TB1> INFO: Test took 3863ms.
[11:48:23.152] <TB1> INFO: Expecting 41600 events.
[11:48:26.666] <TB1> INFO: 41600 events read in total (2922ms).
[11:48:26.667] <TB1> INFO: Test took 3780ms.
[11:48:26.956] <TB1> INFO: Expecting 41600 events.
[11:48:30.454] <TB1> INFO: 41600 events read in total (2907ms).
[11:48:30.455] <TB1> INFO: Test took 3764ms.
[11:48:30.757] <TB1> INFO: Expecting 41600 events.
[11:48:34.258] <TB1> INFO: 41600 events read in total (2910ms).
[11:48:34.259] <TB1> INFO: Test took 3780ms.
[11:48:34.551] <TB1> INFO: Expecting 41600 events.
[11:48:38.046] <TB1> INFO: 41600 events read in total (2904ms).
[11:48:38.047] <TB1> INFO: Test took 3761ms.
[11:48:38.358] <TB1> INFO: Expecting 41600 events.
[11:48:41.901] <TB1> INFO: 41600 events read in total (2951ms).
[11:48:41.902] <TB1> INFO: Test took 3828ms.
[11:48:42.191] <TB1> INFO: Expecting 41600 events.
[11:48:45.744] <TB1> INFO: 41600 events read in total (2961ms).
[11:48:45.745] <TB1> INFO: Test took 3819ms.
[11:48:46.034] <TB1> INFO: Expecting 41600 events.
[11:48:49.541] <TB1> INFO: 41600 events read in total (2915ms).
[11:48:49.542] <TB1> INFO: Test took 3773ms.
[11:48:49.835] <TB1> INFO: Expecting 41600 events.
[11:48:53.521] <TB1> INFO: 41600 events read in total (3094ms).
[11:48:53.522] <TB1> INFO: Test took 3953ms.
[11:48:53.810] <TB1> INFO: Expecting 41600 events.
[11:48:57.321] <TB1> INFO: 41600 events read in total (2919ms).
[11:48:57.322] <TB1> INFO: Test took 3777ms.
[11:48:57.611] <TB1> INFO: Expecting 41600 events.
[11:49:01.114] <TB1> INFO: 41600 events read in total (2911ms).
[11:49:01.115] <TB1> INFO: Test took 3769ms.
[11:49:01.412] <TB1> INFO: Expecting 41600 events.
[11:49:04.912] <TB1> INFO: 41600 events read in total (2908ms).
[11:49:04.912] <TB1> INFO: Test took 3771ms.
[11:49:05.203] <TB1> INFO: Expecting 2560 events.
[11:49:06.087] <TB1> INFO: 2560 events read in total (292ms).
[11:49:06.088] <TB1> INFO: Test took 1163ms.
[11:49:06.396] <TB1> INFO: Expecting 2560 events.
[11:49:07.288] <TB1> INFO: 2560 events read in total (300ms).
[11:49:07.288] <TB1> INFO: Test took 1199ms.
[11:49:07.595] <TB1> INFO: Expecting 2560 events.
[11:49:08.487] <TB1> INFO: 2560 events read in total (300ms).
[11:49:08.487] <TB1> INFO: Test took 1198ms.
[11:49:08.795] <TB1> INFO: Expecting 2560 events.
[11:49:09.687] <TB1> INFO: 2560 events read in total (301ms).
[11:49:09.688] <TB1> INFO: Test took 1201ms.
[11:49:09.996] <TB1> INFO: Expecting 2560 events.
[11:49:10.885] <TB1> INFO: 2560 events read in total (296ms).
[11:49:10.885] <TB1> INFO: Test took 1197ms.
[11:49:11.193] <TB1> INFO: Expecting 2560 events.
[11:49:12.074] <TB1> INFO: 2560 events read in total (289ms).
[11:49:12.074] <TB1> INFO: Test took 1189ms.
[11:49:12.382] <TB1> INFO: Expecting 2560 events.
[11:49:13.263] <TB1> INFO: 2560 events read in total (289ms).
[11:49:13.263] <TB1> INFO: Test took 1188ms.
[11:49:13.572] <TB1> INFO: Expecting 2560 events.
[11:49:14.452] <TB1> INFO: 2560 events read in total (288ms).
[11:49:14.453] <TB1> INFO: Test took 1189ms.
[11:49:14.760] <TB1> INFO: Expecting 2560 events.
[11:49:15.642] <TB1> INFO: 2560 events read in total (290ms).
[11:49:15.642] <TB1> INFO: Test took 1188ms.
[11:49:15.951] <TB1> INFO: Expecting 2560 events.
[11:49:16.838] <TB1> INFO: 2560 events read in total (296ms).
[11:49:16.838] <TB1> INFO: Test took 1196ms.
[11:49:17.147] <TB1> INFO: Expecting 2560 events.
[11:49:18.038] <TB1> INFO: 2560 events read in total (300ms).
[11:49:18.039] <TB1> INFO: Test took 1200ms.
[11:49:18.346] <TB1> INFO: Expecting 2560 events.
[11:49:19.239] <TB1> INFO: 2560 events read in total (301ms).
[11:49:19.239] <TB1> INFO: Test took 1200ms.
[11:49:19.546] <TB1> INFO: Expecting 2560 events.
[11:49:20.440] <TB1> INFO: 2560 events read in total (302ms).
[11:49:20.441] <TB1> INFO: Test took 1201ms.
[11:49:20.748] <TB1> INFO: Expecting 2560 events.
[11:49:21.641] <TB1> INFO: 2560 events read in total (301ms).
[11:49:21.641] <TB1> INFO: Test took 1199ms.
[11:49:21.949] <TB1> INFO: Expecting 2560 events.
[11:49:22.833] <TB1> INFO: 2560 events read in total (292ms).
[11:49:22.833] <TB1> INFO: Test took 1191ms.
[11:49:23.141] <TB1> INFO: Expecting 2560 events.
[11:49:24.027] <TB1> INFO: 2560 events read in total (294ms).
[11:49:24.027] <TB1> INFO: Test took 1193ms.
[11:49:24.030] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:49:24.337] <TB1> INFO: Expecting 655360 events.
[11:49:39.306] <TB1> INFO: 655360 events read in total (14378ms).
[11:49:39.318] <TB1> INFO: Expecting 655360 events.
[11:49:54.088] <TB1> INFO: 655360 events read in total (14367ms).
[11:49:54.104] <TB1> INFO: Expecting 655360 events.
[11:50:08.981] <TB1> INFO: 655360 events read in total (14474ms).
[11:50:08.001] <TB1> INFO: Expecting 655360 events.
[11:50:23.617] <TB1> INFO: 655360 events read in total (14213ms).
[11:50:23.642] <TB1> INFO: Expecting 655360 events.
[11:50:38.292] <TB1> INFO: 655360 events read in total (14247ms).
[11:50:38.327] <TB1> INFO: Expecting 655360 events.
[11:50:52.929] <TB1> INFO: 655360 events read in total (14199ms).
[11:50:52.972] <TB1> INFO: Expecting 655360 events.
[11:51:07.507] <TB1> INFO: 655360 events read in total (14133ms).
[11:51:07.546] <TB1> INFO: Expecting 655360 events.
[11:51:22.043] <TB1> INFO: 655360 events read in total (14094ms).
[11:51:22.086] <TB1> INFO: Expecting 655360 events.
[11:51:36.611] <TB1> INFO: 655360 events read in total (14122ms).
[11:51:36.671] <TB1> INFO: Expecting 655360 events.
[11:51:51.326] <TB1> INFO: 655360 events read in total (14252ms).
[11:51:51.390] <TB1> INFO: Expecting 655360 events.
[11:52:05.942] <TB1> INFO: 655360 events read in total (14149ms).
[11:52:06.014] <TB1> INFO: Expecting 655360 events.
[11:52:20.597] <TB1> INFO: 655360 events read in total (14180ms).
[11:52:20.657] <TB1> INFO: Expecting 655360 events.
[11:52:35.225] <TB1> INFO: 655360 events read in total (14165ms).
[11:52:35.301] <TB1> INFO: Expecting 655360 events.
[11:52:49.889] <TB1> INFO: 655360 events read in total (14185ms).
[11:52:50.021] <TB1> INFO: Expecting 655360 events.
[11:53:04.655] <TB1> INFO: 655360 events read in total (14231ms).
[11:53:04.854] <TB1> INFO: Expecting 655360 events.
[11:53:19.362] <TB1> INFO: 655360 events read in total (14104ms).
[11:53:19.483] <TB1> INFO: Test took 235453ms.
[11:53:19.576] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:53:19.835] <TB1> INFO: Expecting 655360 events.
[11:53:34.453] <TB1> INFO: 655360 events read in total (14026ms).
[11:53:34.466] <TB1> INFO: Expecting 655360 events.
[11:53:48.746] <TB1> INFO: 655360 events read in total (13877ms).
[11:53:48.762] <TB1> INFO: Expecting 655360 events.
[11:54:03.245] <TB1> INFO: 655360 events read in total (14080ms).
[11:54:03.265] <TB1> INFO: Expecting 655360 events.
[11:54:17.676] <TB1> INFO: 655360 events read in total (14008ms).
[11:54:17.701] <TB1> INFO: Expecting 655360 events.
[11:54:32.282] <TB1> INFO: 655360 events read in total (14178ms).
[11:54:32.314] <TB1> INFO: Expecting 655360 events.
[11:54:46.522] <TB1> INFO: 655360 events read in total (13805ms).
[11:54:46.555] <TB1> INFO: Expecting 655360 events.
[11:55:01.051] <TB1> INFO: 655360 events read in total (14093ms).
[11:55:01.089] <TB1> INFO: Expecting 655360 events.
[11:55:15.666] <TB1> INFO: 655360 events read in total (14174ms).
[11:55:15.708] <TB1> INFO: Expecting 655360 events.
[11:55:30.264] <TB1> INFO: 655360 events read in total (14153ms).
[11:55:30.310] <TB1> INFO: Expecting 655360 events.
[11:55:44.715] <TB1> INFO: 655360 events read in total (14001ms).
[11:55:44.767] <TB1> INFO: Expecting 655360 events.
[11:55:59.243] <TB1> INFO: 655360 events read in total (14073ms).
[11:55:59.298] <TB1> INFO: Expecting 655360 events.
[11:56:13.883] <TB1> INFO: 655360 events read in total (14182ms).
[11:56:13.959] <TB1> INFO: Expecting 655360 events.
[11:56:28.550] <TB1> INFO: 655360 events read in total (14187ms).
[11:56:28.628] <TB1> INFO: Expecting 655360 events.
[11:56:43.221] <TB1> INFO: 655360 events read in total (14190ms).
[11:56:43.347] <TB1> INFO: Expecting 655360 events.
[11:56:57.955] <TB1> INFO: 655360 events read in total (14205ms).
[11:56:58.125] <TB1> INFO: Expecting 655360 events.
[11:57:12.923] <TB1> INFO: 655360 events read in total (14395ms).
[11:57:13.089] <TB1> INFO: Test took 233513ms.
[11:57:13.267] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.274] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.281] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.286] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.292] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.298] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.304] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[11:57:13.310] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[11:57:13.315] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.321] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[11:57:13.327] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[11:57:13.333] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[11:57:13.338] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[11:57:13.344] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.349] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.355] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[11:57:13.361] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[11:57:13.366] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[11:57:13.372] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[11:57:13.378] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[11:57:13.383] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[11:57:13.389] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[11:57:13.395] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[11:57:13.400] <TB1> INFO: safety margin for low PH: adding 9, margin is now 29
[11:57:13.406] <TB1> INFO: safety margin for low PH: adding 10, margin is now 30
[11:57:13.412] <TB1> INFO: safety margin for low PH: adding 11, margin is now 31
[11:57:13.417] <TB1> INFO: safety margin for low PH: adding 12, margin is now 32
[11:57:13.423] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.429] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.435] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.441] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.447] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.452] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.458] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[11:57:13.464] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[11:57:13.470] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[11:57:13.505] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C0.dat
[11:57:13.505] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C1.dat
[11:57:13.505] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C2.dat
[11:57:13.505] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C3.dat
[11:57:13.505] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C4.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C5.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C6.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C7.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C8.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C9.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C10.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C11.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C12.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C13.dat
[11:57:13.506] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C14.dat
[11:57:13.507] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//dacParameters35_C15.dat
[11:57:13.754] <TB1> INFO: Expecting 41600 events.
[11:57:16.919] <TB1> INFO: 41600 events read in total (2573ms).
[11:57:16.920] <TB1> INFO: Test took 3411ms.
[11:57:17.372] <TB1> INFO: Expecting 41600 events.
[11:57:20.469] <TB1> INFO: 41600 events read in total (2505ms).
[11:57:20.470] <TB1> INFO: Test took 3337ms.
[11:57:20.927] <TB1> INFO: Expecting 41600 events.
[11:57:24.081] <TB1> INFO: 41600 events read in total (2562ms).
[11:57:24.082] <TB1> INFO: Test took 3398ms.
[11:57:24.300] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:24.389] <TB1> INFO: Expecting 2560 events.
[11:57:25.274] <TB1> INFO: 2560 events read in total (293ms).
[11:57:25.275] <TB1> INFO: Test took 975ms.
[11:57:25.278] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:25.582] <TB1> INFO: Expecting 2560 events.
[11:57:26.476] <TB1> INFO: 2560 events read in total (302ms).
[11:57:26.477] <TB1> INFO: Test took 1199ms.
[11:57:26.480] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:26.785] <TB1> INFO: Expecting 2560 events.
[11:57:27.679] <TB1> INFO: 2560 events read in total (302ms).
[11:57:27.679] <TB1> INFO: Test took 1199ms.
[11:57:27.682] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:27.987] <TB1> INFO: Expecting 2560 events.
[11:57:28.879] <TB1> INFO: 2560 events read in total (300ms).
[11:57:28.879] <TB1> INFO: Test took 1197ms.
[11:57:28.882] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:29.187] <TB1> INFO: Expecting 2560 events.
[11:57:30.082] <TB1> INFO: 2560 events read in total (303ms).
[11:57:30.082] <TB1> INFO: Test took 1200ms.
[11:57:30.085] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:30.390] <TB1> INFO: Expecting 2560 events.
[11:57:31.284] <TB1> INFO: 2560 events read in total (302ms).
[11:57:31.284] <TB1> INFO: Test took 1199ms.
[11:57:31.287] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:31.592] <TB1> INFO: Expecting 2560 events.
[11:57:32.485] <TB1> INFO: 2560 events read in total (302ms).
[11:57:32.485] <TB1> INFO: Test took 1198ms.
[11:57:32.489] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:32.794] <TB1> INFO: Expecting 2560 events.
[11:57:33.678] <TB1> INFO: 2560 events read in total (292ms).
[11:57:33.679] <TB1> INFO: Test took 1190ms.
[11:57:33.681] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:33.987] <TB1> INFO: Expecting 2560 events.
[11:57:34.875] <TB1> INFO: 2560 events read in total (296ms).
[11:57:34.876] <TB1> INFO: Test took 1195ms.
[11:57:34.879] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:35.184] <TB1> INFO: Expecting 2560 events.
[11:57:36.075] <TB1> INFO: 2560 events read in total (299ms).
[11:57:36.075] <TB1> INFO: Test took 1196ms.
[11:57:36.079] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:36.383] <TB1> INFO: Expecting 2560 events.
[11:57:37.275] <TB1> INFO: 2560 events read in total (300ms).
[11:57:37.275] <TB1> INFO: Test took 1196ms.
[11:57:37.278] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:37.583] <TB1> INFO: Expecting 2560 events.
[11:57:38.463] <TB1> INFO: 2560 events read in total (289ms).
[11:57:38.464] <TB1> INFO: Test took 1186ms.
[11:57:38.468] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:38.772] <TB1> INFO: Expecting 2560 events.
[11:57:39.660] <TB1> INFO: 2560 events read in total (296ms).
[11:57:39.661] <TB1> INFO: Test took 1194ms.
[11:57:39.663] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:39.970] <TB1> INFO: Expecting 2560 events.
[11:57:40.858] <TB1> INFO: 2560 events read in total (297ms).
[11:57:40.859] <TB1> INFO: Test took 1196ms.
[11:57:40.863] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:41.167] <TB1> INFO: Expecting 2560 events.
[11:57:42.054] <TB1> INFO: 2560 events read in total (295ms).
[11:57:42.054] <TB1> INFO: Test took 1191ms.
[11:57:42.058] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:42.363] <TB1> INFO: Expecting 2560 events.
[11:57:43.256] <TB1> INFO: 2560 events read in total (301ms).
[11:57:43.256] <TB1> INFO: Test took 1198ms.
[11:57:43.259] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:43.565] <TB1> INFO: Expecting 2560 events.
[11:57:44.454] <TB1> INFO: 2560 events read in total (297ms).
[11:57:44.455] <TB1> INFO: Test took 1197ms.
[11:57:44.458] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:44.762] <TB1> INFO: Expecting 2560 events.
[11:57:45.652] <TB1> INFO: 2560 events read in total (298ms).
[11:57:45.652] <TB1> INFO: Test took 1195ms.
[11:57:45.655] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:45.960] <TB1> INFO: Expecting 2560 events.
[11:57:46.852] <TB1> INFO: 2560 events read in total (300ms).
[11:57:46.852] <TB1> INFO: Test took 1197ms.
[11:57:46.855] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:47.160] <TB1> INFO: Expecting 2560 events.
[11:57:48.047] <TB1> INFO: 2560 events read in total (295ms).
[11:57:48.048] <TB1> INFO: Test took 1193ms.
[11:57:48.050] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:48.357] <TB1> INFO: Expecting 2560 events.
[11:57:49.242] <TB1> INFO: 2560 events read in total (294ms).
[11:57:49.242] <TB1> INFO: Test took 1192ms.
[11:57:49.245] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:49.550] <TB1> INFO: Expecting 2560 events.
[11:57:50.442] <TB1> INFO: 2560 events read in total (300ms).
[11:57:50.443] <TB1> INFO: Test took 1199ms.
[11:57:50.445] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:50.751] <TB1> INFO: Expecting 2560 events.
[11:57:51.640] <TB1> INFO: 2560 events read in total (297ms).
[11:57:51.641] <TB1> INFO: Test took 1196ms.
[11:57:51.644] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:51.949] <TB1> INFO: Expecting 2560 events.
[11:57:52.837] <TB1> INFO: 2560 events read in total (296ms).
[11:57:52.838] <TB1> INFO: Test took 1194ms.
[11:57:52.840] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:53.146] <TB1> INFO: Expecting 2560 events.
[11:57:54.032] <TB1> INFO: 2560 events read in total (295ms).
[11:57:54.032] <TB1> INFO: Test took 1192ms.
[11:57:54.035] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:54.342] <TB1> INFO: Expecting 2560 events.
[11:57:55.227] <TB1> INFO: 2560 events read in total (293ms).
[11:57:55.228] <TB1> INFO: Test took 1193ms.
[11:57:55.232] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:55.535] <TB1> INFO: Expecting 2560 events.
[11:57:56.427] <TB1> INFO: 2560 events read in total (300ms).
[11:57:56.428] <TB1> INFO: Test took 1196ms.
[11:57:56.431] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:56.736] <TB1> INFO: Expecting 2560 events.
[11:57:57.624] <TB1> INFO: 2560 events read in total (296ms).
[11:57:57.624] <TB1> INFO: Test took 1194ms.
[11:57:57.628] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:57.932] <TB1> INFO: Expecting 2560 events.
[11:57:58.826] <TB1> INFO: 2560 events read in total (302ms).
[11:57:58.826] <TB1> INFO: Test took 1198ms.
[11:57:58.830] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:57:59.134] <TB1> INFO: Expecting 2560 events.
[11:58:00.019] <TB1> INFO: 2560 events read in total (293ms).
[11:58:00.019] <TB1> INFO: Test took 1189ms.
[11:58:00.021] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:00.328] <TB1> INFO: Expecting 2560 events.
[11:58:01.214] <TB1> INFO: 2560 events read in total (295ms).
[11:58:01.214] <TB1> INFO: Test took 1193ms.
[11:58:01.218] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[11:58:01.522] <TB1> INFO: Expecting 2560 events.
[11:58:02.415] <TB1> INFO: 2560 events read in total (301ms).
[11:58:02.416] <TB1> INFO: Test took 1199ms.
[11:58:02.897] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 653 seconds
[11:58:02.897] <TB1> INFO: PH scale (per ROC): 78 60 57 48 54 52 51 51 42 57 63 44 37 55 36 53
[11:58:02.897] <TB1> INFO: PH offset (per ROC): 117 116 133 102 123 112 142 100 112 134 123 86 101 123 101 109
[11:58:02.906] <TB1> INFO: Decoding statistics:
[11:58:02.906] <TB1> INFO: General information:
[11:58:02.906] <TB1> INFO: 16bit words read: 127880
[11:58:02.906] <TB1> INFO: valid events total: 20480
[11:58:02.906] <TB1> INFO: empty events: 17980
[11:58:02.906] <TB1> INFO: valid events with pixels: 2500
[11:58:02.906] <TB1> INFO: valid pixel hits: 2500
[11:58:02.906] <TB1> INFO: Event errors: 0
[11:58:02.906] <TB1> INFO: start marker: 0
[11:58:02.906] <TB1> INFO: stop marker: 0
[11:58:02.906] <TB1> INFO: overflow: 0
[11:58:02.906] <TB1> INFO: invalid 5bit words: 0
[11:58:02.906] <TB1> INFO: invalid XOR eye diagram: 0
[11:58:02.906] <TB1> INFO: frame (failed synchr.): 0
[11:58:02.906] <TB1> INFO: idle data (no TBM trl): 0
[11:58:02.906] <TB1> INFO: no data (only TBM hdr): 0
[11:58:02.906] <TB1> INFO: TBM errors: 0
[11:58:02.906] <TB1> INFO: flawed TBM headers: 0
[11:58:02.906] <TB1> INFO: flawed TBM trailers: 0
[11:58:02.906] <TB1> INFO: event ID mismatches: 0
[11:58:02.906] <TB1> INFO: ROC errors: 0
[11:58:02.906] <TB1> INFO: missing ROC header(s): 0
[11:58:02.906] <TB1> INFO: misplaced readback start: 0
[11:58:02.906] <TB1> INFO: Pixel decoding errors: 0
[11:58:02.906] <TB1> INFO: pixel data incomplete: 0
[11:58:02.906] <TB1> INFO: pixel address: 0
[11:58:02.906] <TB1> INFO: pulse height fill bit: 0
[11:58:02.906] <TB1> INFO: buffer corruption: 0
[11:58:03.067] <TB1> INFO: ######################################################################
[11:58:03.067] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[11:58:03.067] <TB1> INFO: ######################################################################
[11:58:03.081] <TB1> INFO: scanning low vcal = 10
[11:58:03.317] <TB1> INFO: Expecting 41600 events.
[11:58:06.915] <TB1> INFO: 41600 events read in total (3006ms).
[11:58:06.915] <TB1> INFO: Test took 3834ms.
[11:58:06.917] <TB1> INFO: scanning low vcal = 20
[11:58:07.214] <TB1> INFO: Expecting 41600 events.
[11:58:10.812] <TB1> INFO: 41600 events read in total (3006ms).
[11:58:10.812] <TB1> INFO: Test took 3895ms.
[11:58:10.814] <TB1> INFO: scanning low vcal = 30
[11:58:11.113] <TB1> INFO: Expecting 41600 events.
[11:58:14.783] <TB1> INFO: 41600 events read in total (3078ms).
[11:58:14.785] <TB1> INFO: Test took 3971ms.
[11:58:14.788] <TB1> INFO: scanning low vcal = 40
[11:58:15.065] <TB1> INFO: Expecting 41600 events.
[11:58:19.045] <TB1> INFO: 41600 events read in total (3388ms).
[11:58:19.046] <TB1> INFO: Test took 4258ms.
[11:58:19.049] <TB1> INFO: scanning low vcal = 50
[11:58:19.327] <TB1> INFO: Expecting 41600 events.
[11:58:23.316] <TB1> INFO: 41600 events read in total (3398ms).
[11:58:23.317] <TB1> INFO: Test took 4268ms.
[11:58:23.321] <TB1> INFO: scanning low vcal = 60
[11:58:23.598] <TB1> INFO: Expecting 41600 events.
[11:58:27.587] <TB1> INFO: 41600 events read in total (3397ms).
[11:58:27.588] <TB1> INFO: Test took 4267ms.
[11:58:27.590] <TB1> INFO: scanning low vcal = 70
[11:58:27.868] <TB1> INFO: Expecting 41600 events.
[11:58:31.848] <TB1> INFO: 41600 events read in total (3388ms).
[11:58:31.849] <TB1> INFO: Test took 4259ms.
[11:58:31.852] <TB1> INFO: scanning low vcal = 80
[11:58:32.129] <TB1> INFO: Expecting 41600 events.
[11:58:36.142] <TB1> INFO: 41600 events read in total (3421ms).
[11:58:36.143] <TB1> INFO: Test took 4291ms.
[11:58:36.145] <TB1> INFO: scanning low vcal = 90
[11:58:36.427] <TB1> INFO: Expecting 41600 events.
[11:58:40.428] <TB1> INFO: 41600 events read in total (3410ms).
[11:58:40.429] <TB1> INFO: Test took 4283ms.
[11:58:40.433] <TB1> INFO: scanning low vcal = 100
[11:58:40.709] <TB1> INFO: Expecting 41600 events.
[11:58:44.685] <TB1> INFO: 41600 events read in total (3384ms).
[11:58:44.686] <TB1> INFO: Test took 4253ms.
[11:58:44.689] <TB1> INFO: scanning low vcal = 110
[11:58:44.967] <TB1> INFO: Expecting 41600 events.
[11:58:48.983] <TB1> INFO: 41600 events read in total (3424ms).
[11:58:48.984] <TB1> INFO: Test took 4295ms.
[11:58:48.987] <TB1> INFO: scanning low vcal = 120
[11:58:49.264] <TB1> INFO: Expecting 41600 events.
[11:58:53.279] <TB1> INFO: 41600 events read in total (3423ms).
[11:58:53.280] <TB1> INFO: Test took 4293ms.
[11:58:53.283] <TB1> INFO: scanning low vcal = 130
[11:58:53.560] <TB1> INFO: Expecting 41600 events.
[11:58:57.517] <TB1> INFO: 41600 events read in total (3365ms).
[11:58:57.518] <TB1> INFO: Test took 4235ms.
[11:58:57.521] <TB1> INFO: scanning low vcal = 140
[11:58:57.801] <TB1> INFO: Expecting 41600 events.
[11:59:01.759] <TB1> INFO: 41600 events read in total (3366ms).
[11:59:01.760] <TB1> INFO: Test took 4239ms.
[11:59:01.762] <TB1> INFO: scanning low vcal = 150
[11:59:02.040] <TB1> INFO: Expecting 41600 events.
[11:59:05.990] <TB1> INFO: 41600 events read in total (3358ms).
[11:59:05.990] <TB1> INFO: Test took 4227ms.
[11:59:05.993] <TB1> INFO: scanning low vcal = 160
[11:59:06.271] <TB1> INFO: Expecting 41600 events.
[11:59:10.240] <TB1> INFO: 41600 events read in total (3377ms).
[11:59:10.240] <TB1> INFO: Test took 4247ms.
[11:59:10.244] <TB1> INFO: scanning low vcal = 170
[11:59:10.521] <TB1> INFO: Expecting 41600 events.
[11:59:14.478] <TB1> INFO: 41600 events read in total (3365ms).
[11:59:14.479] <TB1> INFO: Test took 4235ms.
[11:59:14.484] <TB1> INFO: scanning low vcal = 180
[11:59:14.759] <TB1> INFO: Expecting 41600 events.
[11:59:18.735] <TB1> INFO: 41600 events read in total (3385ms).
[11:59:18.736] <TB1> INFO: Test took 4251ms.
[11:59:18.739] <TB1> INFO: scanning low vcal = 190
[11:59:19.016] <TB1> INFO: Expecting 41600 events.
[11:59:22.984] <TB1> INFO: 41600 events read in total (3376ms).
[11:59:22.984] <TB1> INFO: Test took 4244ms.
[11:59:22.988] <TB1> INFO: scanning low vcal = 200
[11:59:23.265] <TB1> INFO: Expecting 41600 events.
[11:59:27.262] <TB1> INFO: 41600 events read in total (3405ms).
[11:59:27.263] <TB1> INFO: Test took 4274ms.
[11:59:27.266] <TB1> INFO: scanning low vcal = 210
[11:59:27.543] <TB1> INFO: Expecting 41600 events.
[11:59:31.532] <TB1> INFO: 41600 events read in total (3397ms).
[11:59:31.533] <TB1> INFO: Test took 4267ms.
[11:59:31.537] <TB1> INFO: scanning low vcal = 220
[11:59:31.814] <TB1> INFO: Expecting 41600 events.
[11:59:35.788] <TB1> INFO: 41600 events read in total (3382ms).
[11:59:35.789] <TB1> INFO: Test took 4252ms.
[11:59:35.792] <TB1> INFO: scanning low vcal = 230
[11:59:36.069] <TB1> INFO: Expecting 41600 events.
[11:59:40.093] <TB1> INFO: 41600 events read in total (3432ms).
[11:59:40.094] <TB1> INFO: Test took 4302ms.
[11:59:40.097] <TB1> INFO: scanning low vcal = 240
[11:59:40.375] <TB1> INFO: Expecting 41600 events.
[11:59:44.409] <TB1> INFO: 41600 events read in total (3442ms).
[11:59:44.410] <TB1> INFO: Test took 4312ms.
[11:59:44.413] <TB1> INFO: scanning low vcal = 250
[11:59:44.690] <TB1> INFO: Expecting 41600 events.
[11:59:48.684] <TB1> INFO: 41600 events read in total (3402ms).
[11:59:48.685] <TB1> INFO: Test took 4272ms.
[11:59:48.690] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[11:59:48.965] <TB1> INFO: Expecting 41600 events.
[11:59:52.941] <TB1> INFO: 41600 events read in total (3384ms).
[11:59:52.942] <TB1> INFO: Test took 4252ms.
[11:59:52.945] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[11:59:53.222] <TB1> INFO: Expecting 41600 events.
[11:59:57.168] <TB1> INFO: 41600 events read in total (3355ms).
[11:59:57.169] <TB1> INFO: Test took 4224ms.
[11:59:57.172] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[11:59:57.448] <TB1> INFO: Expecting 41600 events.
[12:00:01.398] <TB1> INFO: 41600 events read in total (3358ms).
[12:00:01.399] <TB1> INFO: Test took 4227ms.
[12:00:01.402] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[12:00:01.679] <TB1> INFO: Expecting 41600 events.
[12:00:05.620] <TB1> INFO: 41600 events read in total (3350ms).
[12:00:05.621] <TB1> INFO: Test took 4218ms.
[12:00:05.624] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:00:05.900] <TB1> INFO: Expecting 41600 events.
[12:00:09.850] <TB1> INFO: 41600 events read in total (3358ms).
[12:00:09.851] <TB1> INFO: Test took 4227ms.
[12:00:10.269] <TB1> INFO: PixTestGainPedestal::measure() done
[12:00:44.750] <TB1> INFO: PixTestGainPedestal::fit() done
[12:00:44.750] <TB1> INFO: non-linearity mean: 0.987 0.985 0.984 0.948 0.975 0.970 0.980 0.943 0.948 0.983 0.988 0.918 0.932 0.981 0.950 0.974
[12:00:44.751] <TB1> INFO: non-linearity RMS: 0.003 0.004 0.004 0.062 0.006 0.014 0.005 0.098 0.130 0.004 0.004 0.074 0.156 0.004 0.140 0.008
[12:00:44.751] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[12:00:44.764] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[12:00:44.776] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[12:00:44.789] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[12:00:44.802] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[12:00:44.816] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[12:00:44.828] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[12:00:44.841] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[12:00:44.854] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[12:00:44.868] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[12:00:44.881] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[12:00:44.894] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[12:00:44.907] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[12:00:44.920] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[12:00:44.933] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[12:00:44.946] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1029_FullQualification_2016-10-20_09h44m_1476949484//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[12:00:44.959] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 161 seconds
[12:00:44.959] <TB1> INFO: Decoding statistics:
[12:00:44.959] <TB1> INFO: General information:
[12:00:44.959] <TB1> INFO: 16bit words read: 3327814
[12:00:44.959] <TB1> INFO: valid events total: 332800
[12:00:44.959] <TB1> INFO: empty events: 0
[12:00:44.959] <TB1> INFO: valid events with pixels: 332800
[12:00:44.959] <TB1> INFO: valid pixel hits: 665507
[12:00:44.959] <TB1> INFO: Event errors: 0
[12:00:44.959] <TB1> INFO: start marker: 0
[12:00:44.959] <TB1> INFO: stop marker: 0
[12:00:44.959] <TB1> INFO: overflow: 0
[12:00:44.959] <TB1> INFO: invalid 5bit words: 0
[12:00:44.959] <TB1> INFO: invalid XOR eye diagram: 0
[12:00:44.959] <TB1> INFO: frame (failed synchr.): 0
[12:00:44.959] <TB1> INFO: idle data (no TBM trl): 0
[12:00:44.959] <TB1> INFO: no data (only TBM hdr): 0
[12:00:44.959] <TB1> INFO: TBM errors: 0
[12:00:44.959] <TB1> INFO: flawed TBM headers: 0
[12:00:44.959] <TB1> INFO: flawed TBM trailers: 0
[12:00:44.959] <TB1> INFO: event ID mismatches: 0
[12:00:44.959] <TB1> INFO: ROC errors: 0
[12:00:44.959] <TB1> INFO: missing ROC header(s): 0
[12:00:44.959] <TB1> INFO: misplaced readback start: 0
[12:00:44.959] <TB1> INFO: Pixel decoding errors: 0
[12:00:44.959] <TB1> INFO: pixel data incomplete: 0
[12:00:44.959] <TB1> INFO: pixel address: 0
[12:00:44.959] <TB1> INFO: pulse height fill bit: 0
[12:00:44.959] <TB1> INFO: buffer corruption: 0
[12:00:44.974] <TB1> INFO: Decoding statistics:
[12:00:44.974] <TB1> INFO: General information:
[12:00:44.974] <TB1> INFO: 16bit words read: 3457230
[12:00:44.974] <TB1> INFO: valid events total: 353536
[12:00:44.974] <TB1> INFO: empty events: 18236
[12:00:44.974] <TB1> INFO: valid events with pixels: 335300
[12:00:44.974] <TB1> INFO: valid pixel hits: 668007
[12:00:44.974] <TB1> INFO: Event errors: 0
[12:00:44.974] <TB1> INFO: start marker: 0
[12:00:44.974] <TB1> INFO: stop marker: 0
[12:00:44.974] <TB1> INFO: overflow: 0
[12:00:44.974] <TB1> INFO: invalid 5bit words: 0
[12:00:44.974] <TB1> INFO: invalid XOR eye diagram: 0
[12:00:44.974] <TB1> INFO: frame (failed synchr.): 0
[12:00:44.974] <TB1> INFO: idle data (no TBM trl): 0
[12:00:44.974] <TB1> INFO: no data (only TBM hdr): 0
[12:00:44.974] <TB1> INFO: TBM errors: 0
[12:00:44.974] <TB1> INFO: flawed TBM headers: 0
[12:00:44.974] <TB1> INFO: flawed TBM trailers: 0
[12:00:44.974] <TB1> INFO: event ID mismatches: 0
[12:00:44.974] <TB1> INFO: ROC errors: 0
[12:00:44.974] <TB1> INFO: missing ROC header(s): 0
[12:00:44.974] <TB1> INFO: misplaced readback start: 0
[12:00:44.974] <TB1> INFO: Pixel decoding errors: 0
[12:00:44.974] <TB1> INFO: pixel data incomplete: 0
[12:00:44.974] <TB1> INFO: pixel address: 0
[12:00:44.974] <TB1> INFO: pulse height fill bit: 0
[12:00:44.974] <TB1> INFO: buffer corruption: 0
[12:00:44.974] <TB1> INFO: enter test to run
[12:00:44.974] <TB1> INFO: test: exit no parameter change
[12:00:45.113] <TB1> QUIET: Connection to board 154 closed.
[12:00:45.114] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud