Test Date: 2016-10-26 17:20
Analysis date: 2016-10-28 09:35
Logfile
LogfileView
[18:13:10.624] <TB1> INFO: *** Welcome to pxar ***
[18:13:10.624] <TB1> INFO: *** Today: 2016/10/26
[18:13:10.629] <TB1> INFO: *** Version: c8ba-dirty
[18:13:10.630] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C15.dat
[18:13:10.630] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//tbmParameters_C1b.dat
[18:13:10.630] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//defaultMaskFile.dat
[18:13:10.630] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters_C15.dat
[18:13:10.691] <TB1> INFO: clk: 4
[18:13:10.691] <TB1> INFO: ctr: 4
[18:13:10.691] <TB1> INFO: sda: 19
[18:13:10.691] <TB1> INFO: tin: 9
[18:13:10.691] <TB1> INFO: level: 15
[18:13:10.691] <TB1> INFO: triggerdelay: 0
[18:13:10.691] <TB1> QUIET: Instanciating API for pxar v2.7.6+61~g7f4a123
[18:13:10.691] <TB1> INFO: Log level: INFO
[18:13:10.699] <TB1> INFO: Found DTB DTB_WXC03A
[18:13:10.711] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[18:13:10.713] <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:
------------------------------------------------------
[18:13:10.715] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[18:13:12.204] <TB1> INFO: DUT info:
[18:13:12.204] <TB1> INFO: The DUT currently contains the following objects:
[18:13:12.204] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[18:13:12.204] <TB1> INFO: TBM Core alpha (0): 7 registers set
[18:13:12.204] <TB1> INFO: TBM Core beta (1): 7 registers set
[18:13:12.204] <TB1> INFO: TBM Core alpha (2): 7 registers set
[18:13:12.204] <TB1> INFO: TBM Core beta (3): 7 registers set
[18:13:12.204] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[18:13:12.204] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.204] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:13:12.605] <TB1> INFO: enter 'restricted' command line mode
[18:13:12.605] <TB1> INFO: enter test to run
[18:13:12.605] <TB1> INFO: test: pretest no parameter change
[18:13:12.605] <TB1> INFO: running: pretest
[18:13:12.611] <TB1> INFO: ######################################################################
[18:13:12.611] <TB1> INFO: PixTestPretest::doTest()
[18:13:12.611] <TB1> INFO: ######################################################################
[18:13:12.612] <TB1> INFO: ----------------------------------------------------------------------
[18:13:12.612] <TB1> INFO: PixTestPretest::programROC()
[18:13:12.612] <TB1> INFO: ----------------------------------------------------------------------
[18:13:30.626] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[18:13:30.626] <TB1> INFO: IA differences per ROC: 17.7 20.9 17.7 19.3 16.9 20.1 20.1 17.7 18.5 18.5 20.1 22.5 20.9 19.3 19.3 19.3
[18:13:30.681] <TB1> INFO: ----------------------------------------------------------------------
[18:13:30.681] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[18:13:30.681] <TB1> INFO: ----------------------------------------------------------------------
[18:13:36.072] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 387.5 mA = 24.2188 mA/ROC
[18:13:36.072] <TB1> INFO: i(loss) [mA/ROC]: 20.1 20.1 19.3 20.1 19.3 19.3 20.1 20.1 19.3 20.1 19.3 19.3 19.3 20.1 19.3 19.3
[18:13:36.105] <TB1> INFO: ----------------------------------------------------------------------
[18:13:36.106] <TB1> INFO: PixTestPretest::findTiming()
[18:13:36.106] <TB1> INFO: ----------------------------------------------------------------------
[18:13:36.106] <TB1> INFO: PixTestCmd::init()
[18:13:36.682] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[18:14:08.313] <TB1> INFO: TBM phases: 160MHz: 7, 400MHz: 6, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[18:14:08.313] <TB1> INFO: (success/tries = 100/100), width = 4
[18:14:09.820] <TB1> INFO: ----------------------------------------------------------------------
[18:14:09.820] <TB1> INFO: PixTestPretest::findWorkingPixel()
[18:14:09.820] <TB1> INFO: ----------------------------------------------------------------------
[18:14:09.914] <TB1> INFO: Expecting 231680 events.
[18:14:19.978] <TB1> INFO: 231680 events read in total (9472ms).
[18:14:19.987] <TB1> INFO: Test took 10163ms.
[18:14:20.232] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[18:14:20.266] <TB1> INFO: ----------------------------------------------------------------------
[18:14:20.266] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[18:14:20.266] <TB1> INFO: ----------------------------------------------------------------------
[18:14:20.360] <TB1> INFO: Expecting 231680 events.
[18:14:30.248] <TB1> INFO: 231680 events read in total (9296ms).
[18:14:30.257] <TB1> INFO: Test took 9986ms.
[18:14:30.515] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[18:14:30.515] <TB1> INFO: CalDel: 90 108 98 94 101 98 108 109 77 87 99 111 92 119 98 90
[18:14:30.515] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 52 51 51 51 51 51
[18:14:30.519] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C0.dat
[18:14:30.519] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C1.dat
[18:14:30.520] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C2.dat
[18:14:30.520] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C3.dat
[18:14:30.520] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C4.dat
[18:14:30.520] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C5.dat
[18:14:30.521] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C6.dat
[18:14:30.521] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C7.dat
[18:14:30.521] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C8.dat
[18:14:30.521] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C9.dat
[18:14:30.521] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C10.dat
[18:14:30.522] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C11.dat
[18:14:30.522] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C12.dat
[18:14:30.522] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C13.dat
[18:14:30.522] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C14.dat
[18:14:30.522] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters_C15.dat
[18:14:30.522] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//tbmParameters_C0a.dat
[18:14:30.523] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//tbmParameters_C0b.dat
[18:14:30.523] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//tbmParameters_C1a.dat
[18:14:30.523] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//tbmParameters_C1b.dat
[18:14:30.523] <TB1> INFO: PixTestPretest::doTest() done, duration: 77 seconds
[18:14:30.573] <TB1> INFO: enter test to run
[18:14:30.573] <TB1> INFO: test: FullTest no parameter change
[18:14:30.573] <TB1> INFO: running: fulltest
[18:14:30.574] <TB1> INFO: ######################################################################
[18:14:30.574] <TB1> INFO: PixTestFullTest::doTest()
[18:14:30.574] <TB1> INFO: ######################################################################
[18:14:30.575] <TB1> INFO: ######################################################################
[18:14:30.575] <TB1> INFO: PixTestAlive::doTest()
[18:14:30.575] <TB1> INFO: ######################################################################
[18:14:30.576] <TB1> INFO: ----------------------------------------------------------------------
[18:14:30.576] <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)
[18:14:30.576] <TB1> INFO: ----------------------------------------------------------------------
[18:14:30.817] <TB1> INFO: Expecting 41600 events.
[18:14:34.284] <TB1> INFO: 41600 events read in total (2875ms).
[18:14:34.285] <TB1> INFO: Test took 3708ms.
[18:14:34.518] <TB1> INFO: PixTestAlive::aliveTest() done
[18:14:34.518] <TB1> INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 1 1 1 0 0 0 1 0 0
[18:14:34.520] <TB1> INFO: ----------------------------------------------------------------------
[18:14:34.520] <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)
[18:14:34.520] <TB1> INFO: ----------------------------------------------------------------------
[18:14:34.762] <TB1> INFO: Expecting 41600 events.
[18:14:37.760] <TB1> INFO: 41600 events read in total (2406ms).
[18:14:37.760] <TB1> INFO: Test took 3238ms.
[18:14:37.761] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[18:14:37.998] <TB1> INFO: PixTestAlive::maskTest() done
[18:14:37.998] <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
[18:14:37.000] <TB1> INFO: ----------------------------------------------------------------------
[18:14:37.000] <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)
[18:14:37.000] <TB1> INFO: ----------------------------------------------------------------------
[18:14:38.243] <TB1> INFO: Expecting 41600 events.
[18:14:41.733] <TB1> INFO: 41600 events read in total (2898ms).
[18:14:41.734] <TB1> INFO: Test took 3732ms.
[18:14:41.971] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[18:14:41.971] <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
[18:14:41.971] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[18:14:41.971] <TB1> INFO: Decoding statistics:
[18:14:41.971] <TB1> INFO: General information:
[18:14:41.971] <TB1> INFO: 16bit words read: 0
[18:14:41.971] <TB1> INFO: valid events total: 0
[18:14:41.971] <TB1> INFO: empty events: 0
[18:14:41.971] <TB1> INFO: valid events with pixels: 0
[18:14:41.971] <TB1> INFO: valid pixel hits: 0
[18:14:41.971] <TB1> INFO: Event errors: 0
[18:14:41.971] <TB1> INFO: start marker: 0
[18:14:41.971] <TB1> INFO: stop marker: 0
[18:14:41.971] <TB1> INFO: overflow: 0
[18:14:41.971] <TB1> INFO: invalid 5bit words: 0
[18:14:41.971] <TB1> INFO: invalid XOR eye diagram: 0
[18:14:41.971] <TB1> INFO: frame (failed synchr.): 0
[18:14:41.971] <TB1> INFO: idle data (no TBM trl): 0
[18:14:41.971] <TB1> INFO: no data (only TBM hdr): 0
[18:14:41.971] <TB1> INFO: TBM errors: 0
[18:14:41.971] <TB1> INFO: flawed TBM headers: 0
[18:14:41.971] <TB1> INFO: flawed TBM trailers: 0
[18:14:41.971] <TB1> INFO: event ID mismatches: 0
[18:14:41.971] <TB1> INFO: ROC errors: 0
[18:14:41.971] <TB1> INFO: missing ROC header(s): 0
[18:14:41.971] <TB1> INFO: misplaced readback start: 0
[18:14:41.971] <TB1> INFO: Pixel decoding errors: 0
[18:14:41.971] <TB1> INFO: pixel data incomplete: 0
[18:14:41.972] <TB1> INFO: pixel address: 0
[18:14:41.972] <TB1> INFO: pulse height fill bit: 0
[18:14:41.972] <TB1> INFO: buffer corruption: 0
[18:14:41.980] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C15.dat
[18:14:41.981] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr_C15.dat
[18:14:41.981] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr_C0.dat for reading PH calibration constants

[18:14:41.981] <TB1> INFO: ######################################################################
[18:14:41.981] <TB1> INFO: PixTestReadback::doTest()
[18:14:41.981] <TB1> INFO: ######################################################################
[18:14:41.981] <TB1> INFO: ----------------------------------------------------------------------
[18:14:41.981] <TB1> INFO: PixTestReadback::CalibrateVd()
[18:14:41.981] <TB1> INFO: ----------------------------------------------------------------------
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C0.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C1.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C2.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C3.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C4.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C5.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C6.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C7.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C8.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C9.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C10.dat
[18:14:51.949] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C11.dat
[18:14:51.950] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C12.dat
[18:14:51.950] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C13.dat
[18:14:51.950] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C14.dat
[18:14:51.950] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C15.dat
[18:14:51.981] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[18:14:51.981] <TB1> INFO: ----------------------------------------------------------------------
[18:14:51.981] <TB1> INFO: PixTestReadback::CalibrateVa()
[18:14:51.981] <TB1> INFO: ----------------------------------------------------------------------
[18:15:01.910] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C0.dat
[18:15:01.910] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C1.dat
[18:15:01.910] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C2.dat
[18:15:01.910] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C3.dat
[18:15:01.910] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C4.dat
[18:15:01.910] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C5.dat
[18:15:01.910] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C6.dat
[18:15:01.911] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C7.dat
[18:15:01.911] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C8.dat
[18:15:01.911] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C9.dat
[18:15:01.911] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C10.dat
[18:15:01.911] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C11.dat
[18:15:01.911] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C12.dat
[18:15:01.911] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C13.dat
[18:15:01.911] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C14.dat
[18:15:01.911] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C15.dat
[18:15:01.942] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[18:15:01.942] <TB1> INFO: ----------------------------------------------------------------------
[18:15:01.942] <TB1> INFO: PixTestReadback::readbackVbg()
[18:15:01.942] <TB1> INFO: ----------------------------------------------------------------------
[18:15:09.614] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[18:15:09.614] <TB1> INFO: ----------------------------------------------------------------------
[18:15:09.614] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[18:15:09.614] <TB1> INFO: ----------------------------------------------------------------------
[18:15:09.614] <TB1> INFO: Vbg will be calibrated using Vd calibration
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 152calibrated Vbg = 1.18129 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 151.9calibrated Vbg = 1.18879 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 150.9calibrated Vbg = 1.18003 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 149.7calibrated Vbg = 1.17595 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 155.7calibrated Vbg = 1.17926 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 163.4calibrated Vbg = 1.18642 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 149calibrated Vbg = 1.18715 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 150.2calibrated Vbg = 1.1871 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 154.4calibrated Vbg = 1.17925 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 157.4calibrated Vbg = 1.17695 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 159.2calibrated Vbg = 1.17117 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 154.5calibrated Vbg = 1.17125 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 159.5calibrated Vbg = 1.1764 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 148.4calibrated Vbg = 1.17863 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 160calibrated Vbg = 1.17797 :::*/*/*/*/
[18:15:09.614] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 153.4calibrated Vbg = 1.17924 :::*/*/*/*/
[18:15:09.619] <TB1> INFO: ----------------------------------------------------------------------
[18:15:09.619] <TB1> INFO: PixTestReadback::CalibrateIa()
[18:15:09.619] <TB1> INFO: ----------------------------------------------------------------------
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C0.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C1.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C2.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C3.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C4.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C5.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C6.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C7.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C8.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C9.dat
[18:17:50.481] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C10.dat
[18:17:50.482] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C11.dat
[18:17:50.482] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C12.dat
[18:17:50.482] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C13.dat
[18:17:50.482] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C14.dat
[18:17:50.482] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//readbackCal_C15.dat
[18:17:50.510] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[18:17:50.511] <TB1> INFO: PixTestReadback::doTest() done
[18:17:50.511] <TB1> INFO: Decoding statistics:
[18:17:50.511] <TB1> INFO: General information:
[18:17:50.511] <TB1> INFO: 16bit words read: 1536
[18:17:50.511] <TB1> INFO: valid events total: 256
[18:17:50.511] <TB1> INFO: empty events: 256
[18:17:50.511] <TB1> INFO: valid events with pixels: 0
[18:17:50.511] <TB1> INFO: valid pixel hits: 0
[18:17:50.511] <TB1> INFO: Event errors: 0
[18:17:50.511] <TB1> INFO: start marker: 0
[18:17:50.511] <TB1> INFO: stop marker: 0
[18:17:50.511] <TB1> INFO: overflow: 0
[18:17:50.511] <TB1> INFO: invalid 5bit words: 0
[18:17:50.511] <TB1> INFO: invalid XOR eye diagram: 0
[18:17:50.511] <TB1> INFO: frame (failed synchr.): 0
[18:17:50.511] <TB1> INFO: idle data (no TBM trl): 0
[18:17:50.511] <TB1> INFO: no data (only TBM hdr): 0
[18:17:50.511] <TB1> INFO: TBM errors: 0
[18:17:50.511] <TB1> INFO: flawed TBM headers: 0
[18:17:50.511] <TB1> INFO: flawed TBM trailers: 0
[18:17:50.511] <TB1> INFO: event ID mismatches: 0
[18:17:50.511] <TB1> INFO: ROC errors: 0
[18:17:50.511] <TB1> INFO: missing ROC header(s): 0
[18:17:50.511] <TB1> INFO: misplaced readback start: 0
[18:17:50.511] <TB1> INFO: Pixel decoding errors: 0
[18:17:50.511] <TB1> INFO: pixel data incomplete: 0
[18:17:50.511] <TB1> INFO: pixel address: 0
[18:17:50.511] <TB1> INFO: pulse height fill bit: 0
[18:17:50.511] <TB1> INFO: buffer corruption: 0
[18:17:50.567] <TB1> INFO: ######################################################################
[18:17:50.567] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[18:17:50.567] <TB1> INFO: ######################################################################
[18:17:50.569] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[18:17:50.735] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:17:50.735] <TB1> INFO: run 1 of 1
[18:17:50.975] <TB1> INFO: Expecting 3120000 events.
[18:18:22.006] <TB1> INFO: 662085 events read in total (30439ms).
[18:18:34.169] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (198) != TBM ID (129)

[18:18:34.307] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 198 198 129 198 198 198 198 198

[18:18:34.307] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (199)

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

[18:18:34.307] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ca 8000 4181 260 25ef 4181 260 25ef e022 c000

[18:18:34.307] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c4 80b1 4180 260 25ef 4180 260 25ef e022 c000

[18:18:34.307] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c5 80c0 4180 260 25ef 4180 260 25ef e022 c000

[18:18:34.307] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4181 25ef 4380 260 25ef e022 c000

[18:18:34.307] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c7 8040 4180 260 25ef 4180 260 25ef e022 c000

[18:18:34.307] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c8 80b1 4180 260 25ef 4380 260 25ef e022 c000

[18:18:34.307] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0c9 80c0 4181 260 25ef 4181 260 25ef e022 c000

[18:18:52.151] <TB1> INFO: 1323430 events read in total (60584ms).
[18:19:04.239] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (39) != TBM ID (129)

[18:19:04.375] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 39 39 129 39 39 39 39 39

[18:19:04.375] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (40)

[18:19:04.376] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:19:04.376] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02b 8040 4181 4c0 29ef 4181 4c0 29ef e022 c000

[18:19:04.376] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a025 80c0 4180 4c0 29ef 4180 4c0 29ef e022 c000

[18:19:04.376] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a026 8000 4180 4c0 29ef 4180 4c0 29ef e022 c000

[18:19:04.376] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4181 29ef 4180 4c0 29ef e022 c000

[18:19:04.376] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a028 80b1 4180 4c0 29ef 4180 4c0 29ef e022 c000

[18:19:04.376] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a029 80c0 4181 4c0 29ef 4181 4c0 29ef e022 c000

[18:19:04.376] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02a 8000 4380 4c0 29ef 4380 4c0 29ef e022 c000

[18:19:21.927] <TB1> INFO: 1980710 events read in total (90360ms).
[18:19:33.988] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (167) != TBM ID (129)

[18:19:34.130] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 167 167 129 167 167 167 167 167

[18:19:34.130] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (168)

[18:19:34.133] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:19:34.133] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ab 8040 4180 820 21ef 4180 820 21ef e022 c000

[18:19:34.133] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a5 80c0 4180 820 21ec 4180 820 21ef e022 c000

[18:19:34.133] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a6 8000 4180 820 21e8 4180 820 21ef e022 c000

[18:19:34.133] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4181 21ed 4180 820 21ef e022 c000

[18:19:34.133] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a8 80b1 4181 820 21ed 4381 820 21ef e022 c000

[18:19:34.133] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0a9 80c0 4180 820 21e9 4180 820 21ef e022 c000

[18:19:34.133] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0aa 8000 4380 820 21ec 4380 820 21ef e022 c000

[18:19:51.929] <TB1> INFO: 2636390 events read in total (120362ms).
[18:20:00.907] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (231) != TBM ID (129)

[18:20:01.045] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 231 231 129 231 231 231 231 231

[18:20:01.045] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (232)

[18:20:01.046] <TB1> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:20:01.046] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0eb 8040 4181 4181 e022 c000

[18:20:01.046] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e5 80c0 4180 4180 e022 c000

[18:20:01.046] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e6 8000 4180 4180 e022 c000

[18:20:01.046] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4181 4181 e022 c000

[18:20:01.046] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e8 80b1 4180 4180 e022 c000

[18:20:01.046] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0e9 80c0 4180 4180 e022 c000

[18:20:01.046] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0ea 8000 4180 4180 e022 c000

[18:20:13.652] <TB1> INFO: 3120000 events read in total (142085ms).
[18:20:13.748] <TB1> INFO: Test took 143014ms.
[18:20:38.310] <TB1> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 167 seconds
[18:20:38.310] <TB1> INFO: number of dead bumps (per ROC): 2 0 2 0 0 0 1 1 0 1 0 22 24 6 1 0
[18:20:38.310] <TB1> INFO: separation cut (per ROC): 105 102 105 103 103 108 108 105 105 102 106 117 102 105 105 102
[18:20:38.310] <TB1> INFO: Decoding statistics:
[18:20:38.310] <TB1> INFO: General information:
[18:20:38.310] <TB1> INFO: 16bit words read: 0
[18:20:38.310] <TB1> INFO: valid events total: 0
[18:20:38.310] <TB1> INFO: empty events: 0
[18:20:38.310] <TB1> INFO: valid events with pixels: 0
[18:20:38.310] <TB1> INFO: valid pixel hits: 0
[18:20:38.310] <TB1> INFO: Event errors: 0
[18:20:38.310] <TB1> INFO: start marker: 0
[18:20:38.310] <TB1> INFO: stop marker: 0
[18:20:38.310] <TB1> INFO: overflow: 0
[18:20:38.310] <TB1> INFO: invalid 5bit words: 0
[18:20:38.310] <TB1> INFO: invalid XOR eye diagram: 0
[18:20:38.310] <TB1> INFO: frame (failed synchr.): 0
[18:20:38.310] <TB1> INFO: idle data (no TBM trl): 0
[18:20:38.310] <TB1> INFO: no data (only TBM hdr): 0
[18:20:38.310] <TB1> INFO: TBM errors: 0
[18:20:38.310] <TB1> INFO: flawed TBM headers: 0
[18:20:38.310] <TB1> INFO: flawed TBM trailers: 0
[18:20:38.310] <TB1> INFO: event ID mismatches: 0
[18:20:38.310] <TB1> INFO: ROC errors: 0
[18:20:38.310] <TB1> INFO: missing ROC header(s): 0
[18:20:38.310] <TB1> INFO: misplaced readback start: 0
[18:20:38.310] <TB1> INFO: Pixel decoding errors: 0
[18:20:38.310] <TB1> INFO: pixel data incomplete: 0
[18:20:38.310] <TB1> INFO: pixel address: 0
[18:20:38.310] <TB1> INFO: pulse height fill bit: 0
[18:20:38.310] <TB1> INFO: buffer corruption: 0
[18:20:38.353] <TB1> INFO: ######################################################################
[18:20:38.353] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[18:20:38.353] <TB1> INFO: ######################################################################
[18:20:38.354] <TB1> INFO: ----------------------------------------------------------------------
[18:20:38.354] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[18:20:38.354] <TB1> INFO: ----------------------------------------------------------------------
[18:20:38.354] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[18:20:38.368] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[18:20:38.369] <TB1> INFO: run 1 of 1
[18:20:38.693] <TB1> INFO: Expecting 36608000 events.
[18:21:02.377] <TB1> INFO: 663400 events read in total (23092ms).
[18:21:25.279] <TB1> INFO: 1315750 events read in total (45994ms).
[18:21:48.140] <TB1> INFO: 1968050 events read in total (68855ms).
[18:22:10.957] <TB1> INFO: 2618700 events read in total (91672ms).
[18:22:33.801] <TB1> INFO: 3270450 events read in total (114516ms).
[18:22:56.454] <TB1> INFO: 3922700 events read in total (137169ms).
[18:23:19.009] <TB1> INFO: 4573650 events read in total (159724ms).
[18:23:41.374] <TB1> INFO: 5223200 events read in total (182089ms).
[18:24:03.918] <TB1> INFO: 5873150 events read in total (204633ms).
[18:24:26.616] <TB1> INFO: 6525700 events read in total (227331ms).
[18:24:49.042] <TB1> INFO: 7175800 events read in total (249757ms).
[18:25:11.593] <TB1> INFO: 7822300 events read in total (272308ms).
[18:25:33.864] <TB1> INFO: 8469500 events read in total (294579ms).
[18:25:56.364] <TB1> INFO: 9117400 events read in total (317079ms).
[18:26:18.707] <TB1> INFO: 9762850 events read in total (339422ms).
[18:26:41.365] <TB1> INFO: 10412850 events read in total (362080ms).
[18:27:03.993] <TB1> INFO: 11061100 events read in total (384708ms).
[18:27:26.655] <TB1> INFO: 11708300 events read in total (407370ms).
[18:27:48.886] <TB1> INFO: 12352100 events read in total (429601ms).
[18:28:11.642] <TB1> INFO: 12997400 events read in total (452357ms).
[18:28:34.109] <TB1> INFO: 13643050 events read in total (474824ms).
[18:28:56.736] <TB1> INFO: 14288550 events read in total (497451ms).
[18:29:19.378] <TB1> INFO: 14931700 events read in total (520093ms).
[18:29:41.826] <TB1> INFO: 15574600 events read in total (542541ms).
[18:30:04.490] <TB1> INFO: 16219200 events read in total (565205ms).
[18:30:26.877] <TB1> INFO: 16864350 events read in total (587592ms).
[18:30:49.086] <TB1> INFO: 17506800 events read in total (609801ms).
[18:31:11.373] <TB1> INFO: 18146750 events read in total (632088ms).
[18:31:34.131] <TB1> INFO: 18788700 events read in total (654846ms).
[18:31:56.437] <TB1> INFO: 19429600 events read in total (677152ms).
[18:32:18.826] <TB1> INFO: 20069900 events read in total (699541ms).
[18:32:41.348] <TB1> INFO: 20710250 events read in total (722063ms).
[18:33:04.062] <TB1> INFO: 21350000 events read in total (744777ms).
[18:33:26.557] <TB1> INFO: 21991150 events read in total (767272ms).
[18:33:49.068] <TB1> INFO: 22632150 events read in total (789783ms).
[18:34:11.511] <TB1> INFO: 23272500 events read in total (812226ms).
[18:34:33.994] <TB1> INFO: 23911050 events read in total (834709ms).
[18:34:56.366] <TB1> INFO: 24549600 events read in total (857081ms).
[18:35:18.516] <TB1> INFO: 25187000 events read in total (879231ms).
[18:35:41.157] <TB1> INFO: 25827450 events read in total (901872ms).
[18:36:03.644] <TB1> INFO: 26468700 events read in total (924359ms).
[18:36:26.147] <TB1> INFO: 27108000 events read in total (946862ms).
[18:36:48.707] <TB1> INFO: 27745550 events read in total (969422ms).
[18:37:11.086] <TB1> INFO: 28383350 events read in total (991801ms).
[18:37:33.684] <TB1> INFO: 29020100 events read in total (1014399ms).
[18:37:56.155] <TB1> INFO: 29655650 events read in total (1036870ms).
[18:38:18.445] <TB1> INFO: 30292550 events read in total (1059160ms).
[18:38:40.832] <TB1> INFO: 30927150 events read in total (1081547ms).
[18:39:03.228] <TB1> INFO: 31564700 events read in total (1103943ms).
[18:39:25.430] <TB1> INFO: 32202600 events read in total (1126145ms).
[18:39:48.105] <TB1> INFO: 32839800 events read in total (1148820ms).
[18:40:10.602] <TB1> INFO: 33478700 events read in total (1171317ms).
[18:40:33.153] <TB1> INFO: 34115850 events read in total (1193868ms).
[18:40:55.882] <TB1> INFO: 34755150 events read in total (1216597ms).
[18:41:18.180] <TB1> INFO: 35392100 events read in total (1238895ms).
[18:41:40.523] <TB1> INFO: 36034950 events read in total (1261238ms).
[18:42:00.346] <TB1> INFO: 36608000 events read in total (1281061ms).
[18:42:00.448] <TB1> INFO: Test took 1282079ms.
[18:42:00.977] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:03.007] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:04.999] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:07.065] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:09.039] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:10.964] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:13.066] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:15.036] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:16.631] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:18.231] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:19.774] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:21.488] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:22.001] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:25.012] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:26.769] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:28.606] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:42:30.443] <TB1> INFO: PixTestScurves::scurves() done
[18:42:30.443] <TB1> INFO: Vcal mean: 109.26 100.24 103.43 98.02 108.16 111.40 109.89 104.68 109.97 108.57 118.95 113.99 105.28 110.94 112.84 99.12
[18:42:30.443] <TB1> INFO: Vcal RMS: 4.38 5.35 6.44 5.10 5.24 5.01 4.90 5.55 4.79 4.99 5.83 6.24 5.11 5.65 4.84 4.77
[18:42:30.443] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1312 seconds
[18:42:30.443] <TB1> INFO: Decoding statistics:
[18:42:30.443] <TB1> INFO: General information:
[18:42:30.443] <TB1> INFO: 16bit words read: 0
[18:42:30.443] <TB1> INFO: valid events total: 0
[18:42:30.443] <TB1> INFO: empty events: 0
[18:42:30.443] <TB1> INFO: valid events with pixels: 0
[18:42:30.443] <TB1> INFO: valid pixel hits: 0
[18:42:30.443] <TB1> INFO: Event errors: 0
[18:42:30.443] <TB1> INFO: start marker: 0
[18:42:30.443] <TB1> INFO: stop marker: 0
[18:42:30.443] <TB1> INFO: overflow: 0
[18:42:30.443] <TB1> INFO: invalid 5bit words: 0
[18:42:30.443] <TB1> INFO: invalid XOR eye diagram: 0
[18:42:30.443] <TB1> INFO: frame (failed synchr.): 0
[18:42:30.443] <TB1> INFO: idle data (no TBM trl): 0
[18:42:30.443] <TB1> INFO: no data (only TBM hdr): 0
[18:42:30.443] <TB1> INFO: TBM errors: 0
[18:42:30.443] <TB1> INFO: flawed TBM headers: 0
[18:42:30.443] <TB1> INFO: flawed TBM trailers: 0
[18:42:30.443] <TB1> INFO: event ID mismatches: 0
[18:42:30.443] <TB1> INFO: ROC errors: 0
[18:42:30.443] <TB1> INFO: missing ROC header(s): 0
[18:42:30.443] <TB1> INFO: misplaced readback start: 0
[18:42:30.443] <TB1> INFO: Pixel decoding errors: 0
[18:42:30.443] <TB1> INFO: pixel data incomplete: 0
[18:42:30.443] <TB1> INFO: pixel address: 0
[18:42:30.443] <TB1> INFO: pulse height fill bit: 0
[18:42:30.443] <TB1> INFO: buffer corruption: 0
[18:42:30.513] <TB1> INFO: ######################################################################
[18:42:30.513] <TB1> INFO: PixTestTrim::doTest()
[18:42:30.513] <TB1> INFO: ######################################################################
[18:42:30.514] <TB1> INFO: ----------------------------------------------------------------------
[18:42:30.514] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[18:42:30.514] <TB1> INFO: ----------------------------------------------------------------------
[18:42:30.557] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[18:42:30.557] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[18:42:30.570] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:42:30.570] <TB1> INFO: run 1 of 1
[18:42:30.807] <TB1> INFO: Expecting 5025280 events.
[18:43:00.774] <TB1> INFO: 811728 events read in total (29358ms).
[18:43:30.783] <TB1> INFO: 1621512 events read in total (59367ms).
[18:44:00.967] <TB1> INFO: 2428160 events read in total (89552ms).
[18:44:30.845] <TB1> INFO: 3232936 events read in total (119429ms).
[18:45:00.620] <TB1> INFO: 4034872 events read in total (149204ms).
[18:45:30.624] <TB1> INFO: 4834320 events read in total (179208ms).
[18:45:37.995] <TB1> INFO: 5025280 events read in total (186579ms).
[18:45:38.072] <TB1> INFO: Test took 187502ms.
[18:45:56.456] <TB1> INFO: ROC 0 VthrComp = 123
[18:45:56.456] <TB1> INFO: ROC 1 VthrComp = 107
[18:45:56.456] <TB1> INFO: ROC 2 VthrComp = 106
[18:45:56.456] <TB1> INFO: ROC 3 VthrComp = 111
[18:45:56.456] <TB1> INFO: ROC 4 VthrComp = 109
[18:45:56.456] <TB1> INFO: ROC 5 VthrComp = 122
[18:45:56.456] <TB1> INFO: ROC 6 VthrComp = 123
[18:45:56.456] <TB1> INFO: ROC 7 VthrComp = 115
[18:45:56.457] <TB1> INFO: ROC 8 VthrComp = 125
[18:45:56.457] <TB1> INFO: ROC 9 VthrComp = 118
[18:45:56.457] <TB1> INFO: ROC 10 VthrComp = 125
[18:45:56.457] <TB1> INFO: ROC 11 VthrComp = 121
[18:45:56.457] <TB1> INFO: ROC 12 VthrComp = 119
[18:45:56.457] <TB1> INFO: ROC 13 VthrComp = 115
[18:45:56.457] <TB1> INFO: ROC 14 VthrComp = 122
[18:45:56.457] <TB1> INFO: ROC 15 VthrComp = 112
[18:45:56.712] <TB1> INFO: Expecting 41600 events.
[18:46:00.354] <TB1> INFO: 41600 events read in total (3050ms).
[18:46:00.354] <TB1> INFO: Test took 3896ms.
[18:46:00.365] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[18:46:00.365] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[18:46:00.380] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:46:00.380] <TB1> INFO: run 1 of 1
[18:46:00.658] <TB1> INFO: Expecting 5025280 events.
[18:46:26.497] <TB1> INFO: 588016 events read in total (25248ms).
[18:46:52.075] <TB1> INFO: 1175336 events read in total (50827ms).
[18:47:17.820] <TB1> INFO: 1763176 events read in total (76571ms).
[18:47:43.588] <TB1> INFO: 2350064 events read in total (102339ms).
[18:48:09.269] <TB1> INFO: 2935808 events read in total (128020ms).
[18:48:34.898] <TB1> INFO: 3519912 events read in total (153649ms).
[18:49:00.700] <TB1> INFO: 4103536 events read in total (179451ms).
[18:49:25.968] <TB1> INFO: 4686200 events read in total (204719ms).
[18:49:40.745] <TB1> INFO: 5025280 events read in total (219496ms).
[18:49:40.825] <TB1> INFO: Test took 220446ms.
[18:50:08.994] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 57.334 for pixel 7/0 mean/min/max = 44.9162/32.4297/57.4026
[18:50:08.995] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 59.8748 for pixel 19/79 mean/min/max = 47.2507/34.5688/59.9327
[18:50:08.995] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 63.8111 for pixel 0/74 mean/min/max = 48.2157/32.4399/63.9915
[18:50:08.996] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 56.6169 for pixel 44/10 mean/min/max = 45.4694/34.2377/56.701
[18:50:08.996] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 61.5353 for pixel 19/1 mean/min/max = 48.1279/34.5842/61.6716
[18:50:08.996] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 57.9294 for pixel 24/18 mean/min/max = 44.7011/31.3217/58.0805
[18:50:08.997] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 58.0282 for pixel 10/71 mean/min/max = 45.1685/32.0717/58.2653
[18:50:08.997] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 58.7343 for pixel 0/2 mean/min/max = 45.2351/31.6832/58.7871
[18:50:08.998] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 55.83 for pixel 9/56 mean/min/max = 44.0103/32.1017/55.9188
[18:50:08.998] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 57.3287 for pixel 16/8 mean/min/max = 44.796/32.2009/57.3911
[18:50:08.999] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 60.3667 for pixel 19/77 mean/min/max = 45.9577/31.5246/60.3908
[18:50:08.999] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 61.1559 for pixel 51/72 mean/min/max = 46.2905/31.3144/61.2666
[18:50:08.000] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 56.0633 for pixel 14/79 mean/min/max = 43.8472/31.6008/56.0936
[18:50:08.000] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 60.5034 for pixel 18/4 mean/min/max = 46.1363/31.7422/60.5303
[18:50:08.001] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 58.1069 for pixel 28/75 mean/min/max = 45.2693/32.4007/58.1379
[18:50:08.001] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 55.3944 for pixel 47/71 mean/min/max = 43.8033/32.1598/55.4469
[18:50:08.002] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:50:09.090] <TB1> INFO: Expecting 411648 events.
[18:50:18.494] <TB1> INFO: 411648 events read in total (8812ms).
[18:50:18.503] <TB1> INFO: Expecting 411648 events.
[18:50:27.635] <TB1> INFO: 411648 events read in total (8729ms).
[18:50:27.646] <TB1> INFO: Expecting 411648 events.
[18:50:36.752] <TB1> INFO: 411648 events read in total (8703ms).
[18:50:36.766] <TB1> INFO: Expecting 411648 events.
[18:50:46.163] <TB1> INFO: 411648 events read in total (8994ms).
[18:50:46.180] <TB1> INFO: Expecting 411648 events.
[18:50:55.594] <TB1> INFO: 411648 events read in total (9011ms).
[18:50:55.618] <TB1> INFO: Expecting 411648 events.
[18:51:05.072] <TB1> INFO: 411648 events read in total (9051ms).
[18:51:05.099] <TB1> INFO: Expecting 411648 events.
[18:51:14.531] <TB1> INFO: 411648 events read in total (9029ms).
[18:51:14.557] <TB1> INFO: Expecting 411648 events.
[18:51:23.946] <TB1> INFO: 411648 events read in total (8986ms).
[18:51:23.978] <TB1> INFO: Expecting 411648 events.
[18:51:33.425] <TB1> INFO: 411648 events read in total (9044ms).
[18:51:33.465] <TB1> INFO: Expecting 411648 events.
[18:51:42.863] <TB1> INFO: 411648 events read in total (8995ms).
[18:51:42.904] <TB1> INFO: Expecting 411648 events.
[18:51:52.379] <TB1> INFO: 411648 events read in total (9072ms).
[18:51:52.416] <TB1> INFO: Expecting 411648 events.
[18:52:01.767] <TB1> INFO: 411648 events read in total (8948ms).
[18:52:01.808] <TB1> INFO: Expecting 411648 events.
[18:52:11.250] <TB1> INFO: 411648 events read in total (9039ms).
[18:52:11.324] <TB1> INFO: Expecting 411648 events.
[18:52:20.714] <TB1> INFO: 411648 events read in total (8987ms).
[18:52:20.775] <TB1> INFO: Expecting 411648 events.
[18:52:30.144] <TB1> INFO: 411648 events read in total (8966ms).
[18:52:30.226] <TB1> INFO: Expecting 411648 events.
[18:52:39.549] <TB1> INFO: 411648 events read in total (8920ms).
[18:52:39.604] <TB1> INFO: Test took 150603ms.
[18:52:40.455] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[18:52:40.469] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:52:40.469] <TB1> INFO: run 1 of 1
[18:52:40.707] <TB1> INFO: Expecting 5025280 events.
[18:53:07.605] <TB1> INFO: 584792 events read in total (26306ms).
[18:53:33.657] <TB1> INFO: 1169288 events read in total (52358ms).
[18:53:59.529] <TB1> INFO: 1753584 events read in total (78230ms).
[18:54:25.667] <TB1> INFO: 2336368 events read in total (104368ms).
[18:54:51.798] <TB1> INFO: 2918592 events read in total (130499ms).
[18:55:17.724] <TB1> INFO: 3500720 events read in total (156425ms).
[18:55:43.708] <TB1> INFO: 4083680 events read in total (182409ms).
[18:56:09.571] <TB1> INFO: 4666984 events read in total (208272ms).
[18:56:25.425] <TB1> INFO: 5025280 events read in total (224126ms).
[18:56:25.569] <TB1> INFO: Test took 225100ms.
[18:56:48.208] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.689429 .. 147.083627
[18:56:48.448] <TB1> INFO: Expecting 208000 events.
[18:56:57.995] <TB1> INFO: 208000 events read in total (8955ms).
[18:56:57.996] <TB1> INFO: Test took 9786ms.
[18:56:58.076] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 0 .. 157 (-1/-1) hits flags = 528 (plus default)
[18:56:58.090] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:56:58.090] <TB1> INFO: run 1 of 1
[18:56:58.368] <TB1> INFO: Expecting 5258240 events.
[18:57:24.277] <TB1> INFO: 584368 events read in total (25318ms).
[18:57:49.843] <TB1> INFO: 1169072 events read in total (50884ms).
[18:58:15.197] <TB1> INFO: 1753928 events read in total (76238ms).
[18:58:41.161] <TB1> INFO: 2338544 events read in total (102202ms).
[18:59:07.207] <TB1> INFO: 2923296 events read in total (128248ms).
[18:59:32.757] <TB1> INFO: 3507552 events read in total (153798ms).
[18:59:58.288] <TB1> INFO: 4091040 events read in total (179329ms).
[19:00:23.981] <TB1> INFO: 4673840 events read in total (205022ms).
[19:00:49.488] <TB1> INFO: 5257120 events read in total (230529ms).
[19:00:49.958] <TB1> INFO: 5258240 events read in total (230999ms).
[19:00:50.132] <TB1> INFO: Test took 232042ms.
[19:01:18.490] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 26.749515 .. 46.128745
[19:01:18.750] <TB1> INFO: Expecting 208000 events.
[19:01:28.341] <TB1> INFO: 208000 events read in total (8999ms).
[19:01:28.342] <TB1> INFO: Test took 9851ms.
[19:01:28.392] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 56 (-1/-1) hits flags = 528 (plus default)
[19:01:28.405] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:01:28.405] <TB1> INFO: run 1 of 1
[19:01:28.684] <TB1> INFO: Expecting 1364480 events.
[19:01:57.232] <TB1> INFO: 658864 events read in total (27957ms).
[19:02:24.964] <TB1> INFO: 1315704 events read in total (55689ms).
[19:02:27.460] <TB1> INFO: 1364480 events read in total (58186ms).
[19:02:27.491] <TB1> INFO: Test took 59086ms.
[19:02:42.146] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 24.009855 .. 44.374611
[19:02:42.473] <TB1> INFO: Expecting 208000 events.
[19:02:52.308] <TB1> INFO: 208000 events read in total (9243ms).
[19:02:52.310] <TB1> INFO: Test took 10161ms.
[19:02:52.358] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 14 .. 54 (-1/-1) hits flags = 528 (plus default)
[19:02:52.372] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:02:52.372] <TB1> INFO: run 1 of 1
[19:02:52.650] <TB1> INFO: Expecting 1364480 events.
[19:03:20.918] <TB1> INFO: 675336 events read in total (27676ms).
[19:03:49.688] <TB1> INFO: 1349896 events read in total (56447ms).
[19:03:50.719] <TB1> INFO: 1364480 events read in total (57478ms).
[19:03:50.752] <TB1> INFO: Test took 58380ms.
[19:04:05.620] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 22.520383 .. 42.223642
[19:04:05.946] <TB1> INFO: Expecting 208000 events.
[19:04:15.570] <TB1> INFO: 208000 events read in total (9032ms).
[19:04:15.572] <TB1> INFO: Test took 9949ms.
[19:04:15.639] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 12 .. 52 (-1/-1) hits flags = 528 (plus default)
[19:04:15.654] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:04:15.654] <TB1> INFO: run 1 of 1
[19:04:15.937] <TB1> INFO: Expecting 1364480 events.
[19:04:44.642] <TB1> INFO: 692776 events read in total (28114ms).
[19:05:13.420] <TB1> INFO: 1364480 events read in total (56892ms).
[19:05:13.457] <TB1> INFO: Test took 57803ms.
[19:05:28.290] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[19:05:28.291] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[19:05:28.304] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[19:05:28.304] <TB1> INFO: run 1 of 1
[19:05:28.539] <TB1> INFO: Expecting 1364480 events.
[19:05:57.152] <TB1> INFO: 667360 events read in total (28022ms).
[19:06:25.021] <TB1> INFO: 1334344 events read in total (55891ms).
[19:06:26.687] <TB1> INFO: 1364480 events read in total (57558ms).
[19:06:26.721] <TB1> INFO: Test took 58417ms.
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C0.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C1.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C2.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C3.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C4.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C5.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C6.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C7.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C8.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C9.dat
[19:06:41.669] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C10.dat
[19:06:41.670] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C11.dat
[19:06:41.670] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C12.dat
[19:06:41.670] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C13.dat
[19:06:41.670] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C14.dat
[19:06:41.670] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C15.dat
[19:06:41.670] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C0.dat
[19:06:41.675] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C1.dat
[19:06:41.680] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C2.dat
[19:06:41.685] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C3.dat
[19:06:41.690] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C4.dat
[19:06:41.695] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C5.dat
[19:06:41.699] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C6.dat
[19:06:41.704] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C7.dat
[19:06:41.709] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C8.dat
[19:06:41.714] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C9.dat
[19:06:41.719] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C10.dat
[19:06:41.724] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C11.dat
[19:06:41.728] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C12.dat
[19:06:41.733] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C13.dat
[19:06:41.738] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C14.dat
[19:06:41.743] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//trimParameters35_C15.dat
[19:06:41.747] <TB1> INFO: PixTestTrim::trimTest() done
[19:06:41.747] <TB1> INFO: vtrim: 115 133 132 119 129 132 139 124 139 121 137 116 122 136 133 126
[19:06:41.747] <TB1> INFO: vthrcomp: 123 107 106 111 109 122 123 115 125 118 125 121 119 115 122 112
[19:06:41.747] <TB1> INFO: vcal mean: 35.00 34.97 34.91 35.00 35.00 34.95 35.00 34.97 34.95 34.91 34.98 34.93 34.97 34.93 34.92 34.97
[19:06:41.747] <TB1> INFO: vcal RMS: 0.98 0.90 1.15 1.02 1.00 0.97 1.02 0.94 1.12 1.14 1.12 1.00 0.97 1.15 1.00 0.95
[19:06:41.747] <TB1> INFO: bits mean: 9.73 8.68 8.74 9.38 8.39 10.07 9.73 8.98 9.96 9.85 9.41 9.37 10.27 9.57 9.65 10.10
[19:06:41.747] <TB1> INFO: bits RMS: 2.59 2.56 2.76 2.41 2.69 2.63 2.63 2.98 2.56 2.59 2.83 2.86 2.49 2.72 2.65 2.45
[19:06:41.756] <TB1> INFO: ----------------------------------------------------------------------
[19:06:41.756] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[19:06:41.756] <TB1> INFO: ----------------------------------------------------------------------
[19:06:41.758] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[19:06:41.771] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:06:41.771] <TB1> INFO: run 1 of 1
[19:06:42.008] <TB1> INFO: Expecting 4160000 events.
[19:07:14.184] <TB1> INFO: 729635 events read in total (31584ms).
[19:07:45.310] <TB1> INFO: 1451355 events read in total (62710ms).
[19:08:16.584] <TB1> INFO: 2167890 events read in total (93984ms).
[19:08:47.898] <TB1> INFO: 2880200 events read in total (125298ms).
[19:09:19.022] <TB1> INFO: 3589400 events read in total (156422ms).
[19:09:44.311] <TB1> INFO: 4160000 events read in total (181711ms).
[19:09:44.458] <TB1> INFO: Test took 182687ms.
[19:10:14.287] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 187 (-1/-1) hits flags = 528 (plus default)
[19:10:14.301] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:10:14.301] <TB1> INFO: run 1 of 1
[19:10:14.539] <TB1> INFO: Expecting 3910400 events.
[19:10:46.205] <TB1> INFO: 720790 events read in total (31075ms).
[19:11:17.616] <TB1> INFO: 1434155 events read in total (62486ms).
[19:11:48.273] <TB1> INFO: 2141665 events read in total (93144ms).
[19:12:19.240] <TB1> INFO: 2846370 events read in total (124111ms).
[19:12:50.055] <TB1> INFO: 3547835 events read in total (154925ms).
[19:13:06.161] <TB1> INFO: 3910400 events read in total (171031ms).
[19:13:06.298] <TB1> INFO: Test took 171997ms.
[19:13:33.400] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 176 (-1/-1) hits flags = 528 (plus default)
[19:13:33.414] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:13:33.414] <TB1> INFO: run 1 of 1
[19:13:33.726] <TB1> INFO: Expecting 3681600 events.
[19:14:05.661] <TB1> INFO: 736660 events read in total (31343ms).
[19:14:37.524] <TB1> INFO: 1464675 events read in total (63206ms).
[19:15:09.758] <TB1> INFO: 2186405 events read in total (95440ms).
[19:15:41.382] <TB1> INFO: 2904945 events read in total (127064ms).
[19:16:12.879] <TB1> INFO: 3621235 events read in total (158561ms).
[19:16:15.880] <TB1> INFO: 3681600 events read in total (161562ms).
[19:16:15.984] <TB1> INFO: Test took 162570ms.
[19:16:40.275] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 175 (-1/-1) hits flags = 528 (plus default)
[19:16:40.289] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:16:40.289] <TB1> INFO: run 1 of 1
[19:16:40.563] <TB1> INFO: Expecting 3660800 events.
[19:17:12.619] <TB1> INFO: 738180 events read in total (31464ms).
[19:17:43.413] <TB1> INFO: 1467650 events read in total (62258ms).
[19:18:14.728] <TB1> INFO: 2190990 events read in total (93573ms).
[19:18:45.844] <TB1> INFO: 2910485 events read in total (124689ms).
[19:19:16.853] <TB1> INFO: 3629080 events read in total (155698ms).
[19:19:18.614] <TB1> INFO: 3660800 events read in total (157459ms).
[19:19:18.669] <TB1> INFO: Test took 158380ms.
[19:19:44.943] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 175 (-1/-1) hits flags = 528 (plus default)
[19:19:44.957] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:19:44.957] <TB1> INFO: run 1 of 1
[19:19:45.209] <TB1> INFO: Expecting 3660800 events.
[19:20:17.032] <TB1> INFO: 738075 events read in total (31232ms).
[19:20:48.209] <TB1> INFO: 1467435 events read in total (62409ms).
[19:21:19.019] <TB1> INFO: 2190550 events read in total (93219ms).
[19:21:50.242] <TB1> INFO: 2910030 events read in total (124442ms).
[19:22:21.364] <TB1> INFO: 3628650 events read in total (155564ms).
[19:22:23.100] <TB1> INFO: 3660800 events read in total (157300ms).
[19:22:23.182] <TB1> INFO: Test took 158225ms.
[19:22:48.141] <TB1> INFO: PixTestTrim::trimBitTest() done
[19:22:48.142] <TB1> INFO: PixTestTrim::doTest() done, duration: 2417 seconds
[19:22:48.142] <TB1> INFO: Decoding statistics:
[19:22:48.142] <TB1> INFO: General information:
[19:22:48.142] <TB1> INFO: 16bit words read: 0
[19:22:48.142] <TB1> INFO: valid events total: 0
[19:22:48.142] <TB1> INFO: empty events: 0
[19:22:48.143] <TB1> INFO: valid events with pixels: 0
[19:22:48.143] <TB1> INFO: valid pixel hits: 0
[19:22:48.143] <TB1> INFO: Event errors: 0
[19:22:48.143] <TB1> INFO: start marker: 0
[19:22:48.143] <TB1> INFO: stop marker: 0
[19:22:48.143] <TB1> INFO: overflow: 0
[19:22:48.143] <TB1> INFO: invalid 5bit words: 0
[19:22:48.143] <TB1> INFO: invalid XOR eye diagram: 0
[19:22:48.143] <TB1> INFO: frame (failed synchr.): 0
[19:22:48.143] <TB1> INFO: idle data (no TBM trl): 0
[19:22:48.143] <TB1> INFO: no data (only TBM hdr): 0
[19:22:48.143] <TB1> INFO: TBM errors: 0
[19:22:48.143] <TB1> INFO: flawed TBM headers: 0
[19:22:48.143] <TB1> INFO: flawed TBM trailers: 0
[19:22:48.143] <TB1> INFO: event ID mismatches: 0
[19:22:48.143] <TB1> INFO: ROC errors: 0
[19:22:48.143] <TB1> INFO: missing ROC header(s): 0
[19:22:48.143] <TB1> INFO: misplaced readback start: 0
[19:22:48.143] <TB1> INFO: Pixel decoding errors: 0
[19:22:48.143] <TB1> INFO: pixel data incomplete: 0
[19:22:48.143] <TB1> INFO: pixel address: 0
[19:22:48.143] <TB1> INFO: pulse height fill bit: 0
[19:22:48.143] <TB1> INFO: buffer corruption: 0
[19:22:48.814] <TB1> INFO: ######################################################################
[19:22:48.815] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[19:22:48.815] <TB1> INFO: ######################################################################
[19:22:49.093] <TB1> INFO: Expecting 41600 events.
[19:22:52.663] <TB1> INFO: 41600 events read in total (2978ms).
[19:22:52.664] <TB1> INFO: Test took 3848ms.
[19:22:53.111] <TB1> INFO: Expecting 41600 events.
[19:22:56.703] <TB1> INFO: 41600 events read in total (3000ms).
[19:22:56.704] <TB1> INFO: Test took 3835ms.
[19:22:57.058] <TB1> INFO: Expecting 41600 events.
[19:23:00.747] <TB1> INFO: 41600 events read in total (3097ms).
[19:23:00.749] <TB1> INFO: Test took 4021ms.
[19:23:01.038] <TB1> INFO: Expecting 41600 events.
[19:23:04.669] <TB1> INFO: 41600 events read in total (3039ms).
[19:23:04.670] <TB1> INFO: Test took 3896ms.
[19:23:04.962] <TB1> INFO: Expecting 41600 events.
[19:23:08.436] <TB1> INFO: 41600 events read in total (2882ms).
[19:23:08.437] <TB1> INFO: Test took 3740ms.
[19:23:08.726] <TB1> INFO: Expecting 41600 events.
[19:23:12.248] <TB1> INFO: 41600 events read in total (2931ms).
[19:23:12.249] <TB1> INFO: Test took 3788ms.
[19:23:12.538] <TB1> INFO: Expecting 41600 events.
[19:23:15.000] <TB1> INFO: 41600 events read in total (2870ms).
[19:23:15.001] <TB1> INFO: Test took 3728ms.
[19:23:16.290] <TB1> INFO: Expecting 41600 events.
[19:23:19.751] <TB1> INFO: 41600 events read in total (2869ms).
[19:23:19.751] <TB1> INFO: Test took 3725ms.
[19:23:20.041] <TB1> INFO: Expecting 41600 events.
[19:23:23.543] <TB1> INFO: 41600 events read in total (2911ms).
[19:23:23.544] <TB1> INFO: Test took 3768ms.
[19:23:23.833] <TB1> INFO: Expecting 41600 events.
[19:23:27.345] <TB1> INFO: 41600 events read in total (2920ms).
[19:23:27.346] <TB1> INFO: Test took 3778ms.
[19:23:27.636] <TB1> INFO: Expecting 41600 events.
[19:23:31.129] <TB1> INFO: 41600 events read in total (2902ms).
[19:23:31.130] <TB1> INFO: Test took 3759ms.
[19:23:31.419] <TB1> INFO: Expecting 41600 events.
[19:23:34.986] <TB1> INFO: 41600 events read in total (2976ms).
[19:23:34.986] <TB1> INFO: Test took 3832ms.
[19:23:35.281] <TB1> INFO: Expecting 41600 events.
[19:23:38.819] <TB1> INFO: 41600 events read in total (2946ms).
[19:23:38.819] <TB1> INFO: Test took 3808ms.
[19:23:39.110] <TB1> INFO: Expecting 41600 events.
[19:23:42.764] <TB1> INFO: 41600 events read in total (3062ms).
[19:23:42.765] <TB1> INFO: Test took 3919ms.
[19:23:43.054] <TB1> INFO: Expecting 41600 events.
[19:23:46.644] <TB1> INFO: 41600 events read in total (2998ms).
[19:23:46.645] <TB1> INFO: Test took 3856ms.
[19:23:46.934] <TB1> INFO: Expecting 41600 events.
[19:23:50.544] <TB1> INFO: 41600 events read in total (3019ms).
[19:23:50.545] <TB1> INFO: Test took 3876ms.
[19:23:50.838] <TB1> INFO: Expecting 41600 events.
[19:23:54.356] <TB1> INFO: 41600 events read in total (2927ms).
[19:23:54.357] <TB1> INFO: Test took 3786ms.
[19:23:54.649] <TB1> INFO: Expecting 41600 events.
[19:23:58.157] <TB1> INFO: 41600 events read in total (2917ms).
[19:23:58.158] <TB1> INFO: Test took 3774ms.
[19:23:58.447] <TB1> INFO: Expecting 41600 events.
[19:24:01.980] <TB1> INFO: 41600 events read in total (2941ms).
[19:24:01.981] <TB1> INFO: Test took 3799ms.
[19:24:02.272] <TB1> INFO: Expecting 41600 events.
[19:24:05.745] <TB1> INFO: 41600 events read in total (2882ms).
[19:24:05.745] <TB1> INFO: Test took 3738ms.
[19:24:06.035] <TB1> INFO: Expecting 41600 events.
[19:24:09.498] <TB1> INFO: 41600 events read in total (2871ms).
[19:24:09.498] <TB1> INFO: Test took 3728ms.
[19:24:09.788] <TB1> INFO: Expecting 41600 events.
[19:24:13.242] <TB1> INFO: 41600 events read in total (2862ms).
[19:24:13.243] <TB1> INFO: Test took 3720ms.
[19:24:13.534] <TB1> INFO: Expecting 41600 events.
[19:24:17.004] <TB1> INFO: 41600 events read in total (2878ms).
[19:24:17.005] <TB1> INFO: Test took 3735ms.
[19:24:17.296] <TB1> INFO: Expecting 41600 events.
[19:24:20.766] <TB1> INFO: 41600 events read in total (2878ms).
[19:24:20.767] <TB1> INFO: Test took 3735ms.
[19:24:21.056] <TB1> INFO: Expecting 41600 events.
[19:24:24.638] <TB1> INFO: 41600 events read in total (2990ms).
[19:24:24.639] <TB1> INFO: Test took 3848ms.
[19:24:24.928] <TB1> INFO: Expecting 41600 events.
[19:24:28.394] <TB1> INFO: 41600 events read in total (2875ms).
[19:24:28.395] <TB1> INFO: Test took 3732ms.
[19:24:28.684] <TB1> INFO: Expecting 41600 events.
[19:24:32.393] <TB1> INFO: 41600 events read in total (3117ms).
[19:24:32.394] <TB1> INFO: Test took 3975ms.
[19:24:32.684] <TB1> INFO: Expecting 41600 events.
[19:24:36.303] <TB1> INFO: 41600 events read in total (3027ms).
[19:24:36.304] <TB1> INFO: Test took 3885ms.
[19:24:36.611] <TB1> INFO: Expecting 41600 events.
[19:24:40.187] <TB1> INFO: 41600 events read in total (2984ms).
[19:24:40.188] <TB1> INFO: Test took 3855ms.
[19:24:40.478] <TB1> INFO: Expecting 41600 events.
[19:24:44.117] <TB1> INFO: 41600 events read in total (3047ms).
[19:24:44.117] <TB1> INFO: Test took 3903ms.
[19:24:44.411] <TB1> INFO: Expecting 2560 events.
[19:24:45.294] <TB1> INFO: 2560 events read in total (292ms).
[19:24:45.295] <TB1> INFO: Test took 1161ms.
[19:24:45.603] <TB1> INFO: Expecting 2560 events.
[19:24:46.496] <TB1> INFO: 2560 events read in total (301ms).
[19:24:46.496] <TB1> INFO: Test took 1200ms.
[19:24:46.804] <TB1> INFO: Expecting 2560 events.
[19:24:47.687] <TB1> INFO: 2560 events read in total (291ms).
[19:24:47.688] <TB1> INFO: Test took 1191ms.
[19:24:47.996] <TB1> INFO: Expecting 2560 events.
[19:24:48.879] <TB1> INFO: 2560 events read in total (292ms).
[19:24:48.879] <TB1> INFO: Test took 1191ms.
[19:24:49.187] <TB1> INFO: Expecting 2560 events.
[19:24:50.068] <TB1> INFO: 2560 events read in total (289ms).
[19:24:50.069] <TB1> INFO: Test took 1189ms.
[19:24:50.376] <TB1> INFO: Expecting 2560 events.
[19:24:51.267] <TB1> INFO: 2560 events read in total (300ms).
[19:24:51.267] <TB1> INFO: Test took 1198ms.
[19:24:51.575] <TB1> INFO: Expecting 2560 events.
[19:24:52.459] <TB1> INFO: 2560 events read in total (292ms).
[19:24:52.459] <TB1> INFO: Test took 1191ms.
[19:24:52.767] <TB1> INFO: Expecting 2560 events.
[19:24:53.647] <TB1> INFO: 2560 events read in total (289ms).
[19:24:53.647] <TB1> INFO: Test took 1187ms.
[19:24:53.956] <TB1> INFO: Expecting 2560 events.
[19:24:54.845] <TB1> INFO: 2560 events read in total (297ms).
[19:24:54.845] <TB1> INFO: Test took 1197ms.
[19:24:55.152] <TB1> INFO: Expecting 2560 events.
[19:24:56.034] <TB1> INFO: 2560 events read in total (290ms).
[19:24:56.034] <TB1> INFO: Test took 1189ms.
[19:24:56.343] <TB1> INFO: Expecting 2560 events.
[19:24:57.225] <TB1> INFO: 2560 events read in total (290ms).
[19:24:57.226] <TB1> INFO: Test took 1191ms.
[19:24:57.532] <TB1> INFO: Expecting 2560 events.
[19:24:58.423] <TB1> INFO: 2560 events read in total (299ms).
[19:24:58.424] <TB1> INFO: Test took 1198ms.
[19:24:58.732] <TB1> INFO: Expecting 2560 events.
[19:24:59.619] <TB1> INFO: 2560 events read in total (296ms).
[19:24:59.619] <TB1> INFO: Test took 1195ms.
[19:24:59.926] <TB1> INFO: Expecting 2560 events.
[19:25:00.820] <TB1> INFO: 2560 events read in total (302ms).
[19:25:00.820] <TB1> INFO: Test took 1200ms.
[19:25:01.129] <TB1> INFO: Expecting 2560 events.
[19:25:02.022] <TB1> INFO: 2560 events read in total (301ms).
[19:25:02.023] <TB1> INFO: Test took 1202ms.
[19:25:02.330] <TB1> INFO: Expecting 2560 events.
[19:25:03.221] <TB1> INFO: 2560 events read in total (300ms).
[19:25:03.221] <TB1> INFO: Test took 1198ms.
[19:25:03.225] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:25:03.530] <TB1> INFO: Expecting 655360 events.
[19:25:18.643] <TB1> INFO: 655360 events read in total (14521ms).
[19:25:18.655] <TB1> INFO: Expecting 655360 events.
[19:25:33.515] <TB1> INFO: 655360 events read in total (14457ms).
[19:25:33.538] <TB1> INFO: Expecting 655360 events.
[19:25:48.308] <TB1> INFO: 655360 events read in total (14366ms).
[19:25:48.331] <TB1> INFO: Expecting 655360 events.
[19:26:03.057] <TB1> INFO: 655360 events read in total (14323ms).
[19:26:03.081] <TB1> INFO: Expecting 655360 events.
[19:26:17.744] <TB1> INFO: 655360 events read in total (14260ms).
[19:26:17.773] <TB1> INFO: Expecting 655360 events.
[19:26:32.549] <TB1> INFO: 655360 events read in total (14373ms).
[19:26:32.583] <TB1> INFO: Expecting 655360 events.
[19:26:47.673] <TB1> INFO: 655360 events read in total (14687ms).
[19:26:47.722] <TB1> INFO: Expecting 655360 events.
[19:27:02.409] <TB1> INFO: 655360 events read in total (14284ms).
[19:27:02.458] <TB1> INFO: Expecting 655360 events.
[19:27:17.150] <TB1> INFO: 655360 events read in total (14289ms).
[19:27:17.198] <TB1> INFO: Expecting 655360 events.
[19:27:31.902] <TB1> INFO: 655360 events read in total (14301ms).
[19:27:31.954] <TB1> INFO: Expecting 655360 events.
[19:27:46.782] <TB1> INFO: 655360 events read in total (14425ms).
[19:27:46.847] <TB1> INFO: Expecting 655360 events.
[19:28:01.511] <TB1> INFO: 655360 events read in total (14261ms).
[19:28:01.587] <TB1> INFO: Expecting 655360 events.
[19:28:16.292] <TB1> INFO: 655360 events read in total (14301ms).
[19:28:16.371] <TB1> INFO: Expecting 655360 events.
[19:28:31.073] <TB1> INFO: 655360 events read in total (14299ms).
[19:28:31.161] <TB1> INFO: Expecting 655360 events.
[19:28:45.711] <TB1> INFO: 655360 events read in total (14147ms).
[19:28:45.802] <TB1> INFO: Expecting 655360 events.
[19:29:00.414] <TB1> INFO: 655360 events read in total (14209ms).
[19:29:00.522] <TB1> INFO: Test took 237298ms.
[19:29:00.617] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:29:00.874] <TB1> INFO: Expecting 655360 events.
[19:29:15.644] <TB1> INFO: 655360 events read in total (14178ms).
[19:29:15.659] <TB1> INFO: Expecting 655360 events.
[19:29:30.204] <TB1> INFO: 655360 events read in total (14142ms).
[19:29:30.220] <TB1> INFO: Expecting 655360 events.
[19:29:44.925] <TB1> INFO: 655360 events read in total (14301ms).
[19:29:44.946] <TB1> INFO: Expecting 655360 events.
[19:29:59.572] <TB1> INFO: 655360 events read in total (14223ms).
[19:29:59.604] <TB1> INFO: Expecting 655360 events.
[19:30:14.163] <TB1> INFO: 655360 events read in total (14156ms).
[19:30:14.193] <TB1> INFO: Expecting 655360 events.
[19:30:28.798] <TB1> INFO: 655360 events read in total (14202ms).
[19:30:28.833] <TB1> INFO: Expecting 655360 events.
[19:30:43.286] <TB1> INFO: 655360 events read in total (14050ms).
[19:30:43.324] <TB1> INFO: Expecting 655360 events.
[19:30:58.039] <TB1> INFO: 655360 events read in total (14312ms).
[19:30:58.081] <TB1> INFO: Expecting 655360 events.
[19:31:12.709] <TB1> INFO: 655360 events read in total (14225ms).
[19:31:12.756] <TB1> INFO: Expecting 655360 events.
[19:31:27.408] <TB1> INFO: 655360 events read in total (14249ms).
[19:31:27.476] <TB1> INFO: Expecting 655360 events.
[19:31:41.825] <TB1> INFO: 655360 events read in total (13946ms).
[19:31:41.891] <TB1> INFO: Expecting 655360 events.
[19:31:56.586] <TB1> INFO: 655360 events read in total (14291ms).
[19:31:56.690] <TB1> INFO: Expecting 655360 events.
[19:32:11.433] <TB1> INFO: 655360 events read in total (14340ms).
[19:32:11.514] <TB1> INFO: Expecting 655360 events.
[19:32:26.209] <TB1> INFO: 655360 events read in total (14291ms).
[19:32:26.323] <TB1> INFO: Expecting 655360 events.
[19:32:41.070] <TB1> INFO: 655360 events read in total (14343ms).
[19:32:41.179] <TB1> INFO: Expecting 655360 events.
[19:32:55.770] <TB1> INFO: 655360 events read in total (14188ms).
[19:32:55.869] <TB1> INFO: Test took 235252ms.
[19:32:56.046] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.051] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:32:56.057] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[19:32:56.063] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[19:32:56.069] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[19:32:56.075] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[19:32:56.081] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[19:32:56.087] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[19:32:56.093] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[19:32:56.100] <TB1> INFO: safety margin for low PH: adding 9, margin is now 29
[19:32:56.106] <TB1> INFO: safety margin for low PH: adding 10, margin is now 30
[19:32:56.111] <TB1> INFO: safety margin for low PH: adding 11, margin is now 31
[19:32:56.118] <TB1> INFO: safety margin for low PH: adding 12, margin is now 32
[19:32:56.123] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.129] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:32:56.135] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.140] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.146] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.152] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:32:56.158] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.164] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.172] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:32:56.180] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[19:32:56.186] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.192] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.198] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.204] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.209] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:32:56.215] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[19:32:56.221] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[19:32:56.227] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[19:32:56.232] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.238] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:32:56.244] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[19:32:56.249] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[19:32:56.255] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.261] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[19:32:56.267] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.272] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.278] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[19:32:56.312] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C0.dat
[19:32:56.312] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C1.dat
[19:32:56.312] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C2.dat
[19:32:56.312] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C3.dat
[19:32:56.312] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C4.dat
[19:32:56.312] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C5.dat
[19:32:56.312] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C6.dat
[19:32:56.313] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C7.dat
[19:32:56.313] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C8.dat
[19:32:56.313] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C9.dat
[19:32:56.313] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C10.dat
[19:32:56.313] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C11.dat
[19:32:56.313] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C12.dat
[19:32:56.313] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C13.dat
[19:32:56.313] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C14.dat
[19:32:56.313] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//dacParameters35_C15.dat
[19:32:56.555] <TB1> INFO: Expecting 41600 events.
[19:32:59.708] <TB1> INFO: 41600 events read in total (2561ms).
[19:32:59.709] <TB1> INFO: Test took 3392ms.
[19:33:00.160] <TB1> INFO: Expecting 41600 events.
[19:33:03.280] <TB1> INFO: 41600 events read in total (2528ms).
[19:33:03.281] <TB1> INFO: Test took 3361ms.
[19:33:03.759] <TB1> INFO: Expecting 41600 events.
[19:33:06.950] <TB1> INFO: 41600 events read in total (2599ms).
[19:33:06.951] <TB1> INFO: Test took 3456ms.
[19:33:07.168] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:07.257] <TB1> INFO: Expecting 2560 events.
[19:33:08.149] <TB1> INFO: 2560 events read in total (300ms).
[19:33:08.149] <TB1> INFO: Test took 981ms.
[19:33:08.151] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:08.458] <TB1> INFO: Expecting 2560 events.
[19:33:09.348] <TB1> INFO: 2560 events read in total (298ms).
[19:33:09.348] <TB1> INFO: Test took 1197ms.
[19:33:09.351] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:09.656] <TB1> INFO: Expecting 2560 events.
[19:33:10.548] <TB1> INFO: 2560 events read in total (300ms).
[19:33:10.549] <TB1> INFO: Test took 1198ms.
[19:33:10.552] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:10.856] <TB1> INFO: Expecting 2560 events.
[19:33:11.743] <TB1> INFO: 2560 events read in total (295ms).
[19:33:11.743] <TB1> INFO: Test took 1191ms.
[19:33:11.746] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:12.052] <TB1> INFO: Expecting 2560 events.
[19:33:12.936] <TB1> INFO: 2560 events read in total (293ms).
[19:33:12.937] <TB1> INFO: Test took 1191ms.
[19:33:12.939] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:13.245] <TB1> INFO: Expecting 2560 events.
[19:33:14.128] <TB1> INFO: 2560 events read in total (291ms).
[19:33:14.129] <TB1> INFO: Test took 1190ms.
[19:33:14.131] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:14.437] <TB1> INFO: Expecting 2560 events.
[19:33:15.327] <TB1> INFO: 2560 events read in total (298ms).
[19:33:15.328] <TB1> INFO: Test took 1197ms.
[19:33:15.330] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:15.636] <TB1> INFO: Expecting 2560 events.
[19:33:16.526] <TB1> INFO: 2560 events read in total (298ms).
[19:33:16.526] <TB1> INFO: Test took 1196ms.
[19:33:16.528] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:16.835] <TB1> INFO: Expecting 2560 events.
[19:33:17.717] <TB1> INFO: 2560 events read in total (290ms).
[19:33:17.718] <TB1> INFO: Test took 1190ms.
[19:33:17.722] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:18.025] <TB1> INFO: Expecting 2560 events.
[19:33:18.914] <TB1> INFO: 2560 events read in total (297ms).
[19:33:18.915] <TB1> INFO: Test took 1194ms.
[19:33:18.918] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:19.223] <TB1> INFO: Expecting 2560 events.
[19:33:20.113] <TB1> INFO: 2560 events read in total (298ms).
[19:33:20.113] <TB1> INFO: Test took 1195ms.
[19:33:20.116] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:20.421] <TB1> INFO: Expecting 2560 events.
[19:33:21.304] <TB1> INFO: 2560 events read in total (291ms).
[19:33:21.305] <TB1> INFO: Test took 1189ms.
[19:33:21.307] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:21.613] <TB1> INFO: Expecting 2560 events.
[19:33:22.492] <TB1> INFO: 2560 events read in total (287ms).
[19:33:22.493] <TB1> INFO: Test took 1186ms.
[19:33:22.495] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:22.801] <TB1> INFO: Expecting 2560 events.
[19:33:23.679] <TB1> INFO: 2560 events read in total (286ms).
[19:33:23.679] <TB1> INFO: Test took 1184ms.
[19:33:23.681] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:23.988] <TB1> INFO: Expecting 2560 events.
[19:33:24.869] <TB1> INFO: 2560 events read in total (289ms).
[19:33:24.870] <TB1> INFO: Test took 1189ms.
[19:33:24.872] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:25.178] <TB1> INFO: Expecting 2560 events.
[19:33:26.059] <TB1> INFO: 2560 events read in total (289ms).
[19:33:26.059] <TB1> INFO: Test took 1187ms.
[19:33:26.062] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:26.368] <TB1> INFO: Expecting 2560 events.
[19:33:27.250] <TB1> INFO: 2560 events read in total (290ms).
[19:33:27.250] <TB1> INFO: Test took 1188ms.
[19:33:27.252] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:27.559] <TB1> INFO: Expecting 2560 events.
[19:33:28.440] <TB1> INFO: 2560 events read in total (289ms).
[19:33:28.440] <TB1> INFO: Test took 1188ms.
[19:33:28.443] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:28.749] <TB1> INFO: Expecting 2560 events.
[19:33:29.632] <TB1> INFO: 2560 events read in total (291ms).
[19:33:29.633] <TB1> INFO: Test took 1190ms.
[19:33:29.635] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:29.940] <TB1> INFO: Expecting 2560 events.
[19:33:30.819] <TB1> INFO: 2560 events read in total (288ms).
[19:33:30.819] <TB1> INFO: Test took 1184ms.
[19:33:30.823] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:31.128] <TB1> INFO: Expecting 2560 events.
[19:33:32.019] <TB1> INFO: 2560 events read in total (299ms).
[19:33:32.019] <TB1> INFO: Test took 1196ms.
[19:33:32.023] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:32.327] <TB1> INFO: Expecting 2560 events.
[19:33:33.219] <TB1> INFO: 2560 events read in total (300ms).
[19:33:33.219] <TB1> INFO: Test took 1197ms.
[19:33:33.222] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:33.528] <TB1> INFO: Expecting 2560 events.
[19:33:34.408] <TB1> INFO: 2560 events read in total (288ms).
[19:33:34.408] <TB1> INFO: Test took 1186ms.
[19:33:34.410] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:34.717] <TB1> INFO: Expecting 2560 events.
[19:33:35.606] <TB1> INFO: 2560 events read in total (297ms).
[19:33:35.606] <TB1> INFO: Test took 1196ms.
[19:33:35.608] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:35.915] <TB1> INFO: Expecting 2560 events.
[19:33:36.806] <TB1> INFO: 2560 events read in total (300ms).
[19:33:36.806] <TB1> INFO: Test took 1198ms.
[19:33:36.809] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:37.115] <TB1> INFO: Expecting 2560 events.
[19:33:37.999] <TB1> INFO: 2560 events read in total (292ms).
[19:33:37.000] <TB1> INFO: Test took 1191ms.
[19:33:37.002] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:38.308] <TB1> INFO: Expecting 2560 events.
[19:33:39.193] <TB1> INFO: 2560 events read in total (293ms).
[19:33:39.193] <TB1> INFO: Test took 1191ms.
[19:33:39.195] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:39.502] <TB1> INFO: Expecting 2560 events.
[19:33:40.392] <TB1> INFO: 2560 events read in total (299ms).
[19:33:40.392] <TB1> INFO: Test took 1197ms.
[19:33:40.395] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:40.700] <TB1> INFO: Expecting 2560 events.
[19:33:41.585] <TB1> INFO: 2560 events read in total (293ms).
[19:33:41.585] <TB1> INFO: Test took 1190ms.
[19:33:41.588] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:41.893] <TB1> INFO: Expecting 2560 events.
[19:33:42.779] <TB1> INFO: 2560 events read in total (294ms).
[19:33:42.779] <TB1> INFO: Test took 1191ms.
[19:33:42.781] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:43.088] <TB1> INFO: Expecting 2560 events.
[19:33:43.972] <TB1> INFO: 2560 events read in total (293ms).
[19:33:43.972] <TB1> INFO: Test took 1191ms.
[19:33:43.976] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:33:44.280] <TB1> INFO: Expecting 2560 events.
[19:33:45.172] <TB1> INFO: 2560 events read in total (300ms).
[19:33:45.172] <TB1> INFO: Test took 1197ms.
[19:33:45.646] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 656 seconds
[19:33:45.646] <TB1> INFO: PH scale (per ROC): 43 67 69 64 37 46 61 65 47 62 38 43 48 30 58 55
[19:33:45.646] <TB1> INFO: PH offset (per ROC): 112 122 116 134 99 99 130 124 108 135 99 108 106 100 131 111
[19:33:45.657] <TB1> INFO: Decoding statistics:
[19:33:45.657] <TB1> INFO: General information:
[19:33:45.657] <TB1> INFO: 16bit words read: 127882
[19:33:45.657] <TB1> INFO: valid events total: 20480
[19:33:45.657] <TB1> INFO: empty events: 17979
[19:33:45.657] <TB1> INFO: valid events with pixels: 2501
[19:33:45.657] <TB1> INFO: valid pixel hits: 2501
[19:33:45.657] <TB1> INFO: Event errors: 0
[19:33:45.657] <TB1> INFO: start marker: 0
[19:33:45.657] <TB1> INFO: stop marker: 0
[19:33:45.657] <TB1> INFO: overflow: 0
[19:33:45.657] <TB1> INFO: invalid 5bit words: 0
[19:33:45.657] <TB1> INFO: invalid XOR eye diagram: 0
[19:33:45.657] <TB1> INFO: frame (failed synchr.): 0
[19:33:45.657] <TB1> INFO: idle data (no TBM trl): 0
[19:33:45.657] <TB1> INFO: no data (only TBM hdr): 0
[19:33:45.657] <TB1> INFO: TBM errors: 0
[19:33:45.657] <TB1> INFO: flawed TBM headers: 0
[19:33:45.658] <TB1> INFO: flawed TBM trailers: 0
[19:33:45.658] <TB1> INFO: event ID mismatches: 0
[19:33:45.658] <TB1> INFO: ROC errors: 0
[19:33:45.658] <TB1> INFO: missing ROC header(s): 0
[19:33:45.658] <TB1> INFO: misplaced readback start: 0
[19:33:45.658] <TB1> INFO: Pixel decoding errors: 0
[19:33:45.658] <TB1> INFO: pixel data incomplete: 0
[19:33:45.658] <TB1> INFO: pixel address: 0
[19:33:45.658] <TB1> INFO: pulse height fill bit: 0
[19:33:45.658] <TB1> INFO: buffer corruption: 0
[19:33:45.842] <TB1> INFO: ######################################################################
[19:33:45.842] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[19:33:45.842] <TB1> INFO: ######################################################################
[19:33:45.858] <TB1> INFO: scanning low vcal = 10
[19:33:46.094] <TB1> INFO: Expecting 41600 events.
[19:33:49.725] <TB1> INFO: 41600 events read in total (3040ms).
[19:33:49.726] <TB1> INFO: Test took 3868ms.
[19:33:49.728] <TB1> INFO: scanning low vcal = 20
[19:33:50.021] <TB1> INFO: Expecting 41600 events.
[19:33:53.598] <TB1> INFO: 41600 events read in total (2985ms).
[19:33:53.599] <TB1> INFO: Test took 3871ms.
[19:33:53.601] <TB1> INFO: scanning low vcal = 30
[19:33:53.894] <TB1> INFO: Expecting 41600 events.
[19:33:57.550] <TB1> INFO: 41600 events read in total (3064ms).
[19:33:57.551] <TB1> INFO: Test took 3950ms.
[19:33:57.553] <TB1> INFO: scanning low vcal = 40
[19:33:57.830] <TB1> INFO: Expecting 41600 events.
[19:34:01.813] <TB1> INFO: 41600 events read in total (3391ms).
[19:34:01.815] <TB1> INFO: Test took 4262ms.
[19:34:01.818] <TB1> INFO: scanning low vcal = 50
[19:34:02.097] <TB1> INFO: Expecting 41600 events.
[19:34:06.130] <TB1> INFO: 41600 events read in total (3441ms).
[19:34:06.130] <TB1> INFO: Test took 4312ms.
[19:34:06.134] <TB1> INFO: scanning low vcal = 60
[19:34:06.411] <TB1> INFO: Expecting 41600 events.
[19:34:10.417] <TB1> INFO: 41600 events read in total (3415ms).
[19:34:10.418] <TB1> INFO: Test took 4284ms.
[19:34:10.421] <TB1> INFO: scanning low vcal = 70
[19:34:10.698] <TB1> INFO: Expecting 41600 events.
[19:34:14.743] <TB1> INFO: 41600 events read in total (3453ms).
[19:34:14.744] <TB1> INFO: Test took 4323ms.
[19:34:14.747] <TB1> INFO: scanning low vcal = 80
[19:34:15.024] <TB1> INFO: Expecting 41600 events.
[19:34:19.042] <TB1> INFO: 41600 events read in total (3426ms).
[19:34:19.043] <TB1> INFO: Test took 4296ms.
[19:34:19.046] <TB1> INFO: scanning low vcal = 90
[19:34:19.324] <TB1> INFO: Expecting 41600 events.
[19:34:23.362] <TB1> INFO: 41600 events read in total (3447ms).
[19:34:23.363] <TB1> INFO: Test took 4317ms.
[19:34:23.366] <TB1> INFO: scanning low vcal = 100
[19:34:23.643] <TB1> INFO: Expecting 41600 events.
[19:34:27.648] <TB1> INFO: 41600 events read in total (3413ms).
[19:34:27.648] <TB1> INFO: Test took 4281ms.
[19:34:27.651] <TB1> INFO: scanning low vcal = 110
[19:34:27.929] <TB1> INFO: Expecting 41600 events.
[19:34:31.941] <TB1> INFO: 41600 events read in total (3420ms).
[19:34:31.942] <TB1> INFO: Test took 4290ms.
[19:34:31.946] <TB1> INFO: scanning low vcal = 120
[19:34:32.222] <TB1> INFO: Expecting 41600 events.
[19:34:36.246] <TB1> INFO: 41600 events read in total (3432ms).
[19:34:36.247] <TB1> INFO: Test took 4301ms.
[19:34:36.250] <TB1> INFO: scanning low vcal = 130
[19:34:36.526] <TB1> INFO: Expecting 41600 events.
[19:34:40.520] <TB1> INFO: 41600 events read in total (3402ms).
[19:34:40.521] <TB1> INFO: Test took 4271ms.
[19:34:40.523] <TB1> INFO: scanning low vcal = 140
[19:34:40.801] <TB1> INFO: Expecting 41600 events.
[19:34:44.855] <TB1> INFO: 41600 events read in total (3462ms).
[19:34:44.856] <TB1> INFO: Test took 4332ms.
[19:34:44.858] <TB1> INFO: scanning low vcal = 150
[19:34:45.136] <TB1> INFO: Expecting 41600 events.
[19:34:49.182] <TB1> INFO: 41600 events read in total (3454ms).
[19:34:49.183] <TB1> INFO: Test took 4324ms.
[19:34:49.186] <TB1> INFO: scanning low vcal = 160
[19:34:49.464] <TB1> INFO: Expecting 41600 events.
[19:34:53.519] <TB1> INFO: 41600 events read in total (3463ms).
[19:34:53.520] <TB1> INFO: Test took 4334ms.
[19:34:53.523] <TB1> INFO: scanning low vcal = 170
[19:34:53.805] <TB1> INFO: Expecting 41600 events.
[19:34:57.848] <TB1> INFO: 41600 events read in total (3451ms).
[19:34:57.849] <TB1> INFO: Test took 4326ms.
[19:34:57.854] <TB1> INFO: scanning low vcal = 180
[19:34:58.130] <TB1> INFO: Expecting 41600 events.
[19:35:02.141] <TB1> INFO: 41600 events read in total (3419ms).
[19:35:02.142] <TB1> INFO: Test took 4288ms.
[19:35:02.145] <TB1> INFO: scanning low vcal = 190
[19:35:02.422] <TB1> INFO: Expecting 41600 events.
[19:35:06.451] <TB1> INFO: 41600 events read in total (3437ms).
[19:35:06.452] <TB1> INFO: Test took 4307ms.
[19:35:06.456] <TB1> INFO: scanning low vcal = 200
[19:35:06.733] <TB1> INFO: Expecting 41600 events.
[19:35:10.758] <TB1> INFO: 41600 events read in total (3434ms).
[19:35:10.758] <TB1> INFO: Test took 4302ms.
[19:35:10.761] <TB1> INFO: scanning low vcal = 210
[19:35:11.040] <TB1> INFO: Expecting 41600 events.
[19:35:15.076] <TB1> INFO: 41600 events read in total (3445ms).
[19:35:15.077] <TB1> INFO: Test took 4316ms.
[19:35:15.080] <TB1> INFO: scanning low vcal = 220
[19:35:15.357] <TB1> INFO: Expecting 41600 events.
[19:35:19.410] <TB1> INFO: 41600 events read in total (3462ms).
[19:35:19.410] <TB1> INFO: Test took 4330ms.
[19:35:19.413] <TB1> INFO: scanning low vcal = 230
[19:35:19.690] <TB1> INFO: Expecting 41600 events.
[19:35:23.694] <TB1> INFO: 41600 events read in total (3412ms).
[19:35:23.695] <TB1> INFO: Test took 4282ms.
[19:35:23.698] <TB1> INFO: scanning low vcal = 240
[19:35:23.974] <TB1> INFO: Expecting 41600 events.
[19:35:28.008] <TB1> INFO: 41600 events read in total (3442ms).
[19:35:28.009] <TB1> INFO: Test took 4311ms.
[19:35:28.012] <TB1> INFO: scanning low vcal = 250
[19:35:28.289] <TB1> INFO: Expecting 41600 events.
[19:35:32.298] <TB1> INFO: 41600 events read in total (3417ms).
[19:35:32.299] <TB1> INFO: Test took 4286ms.
[19:35:32.303] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[19:35:32.579] <TB1> INFO: Expecting 41600 events.
[19:35:36.605] <TB1> INFO: 41600 events read in total (3434ms).
[19:35:36.605] <TB1> INFO: Test took 4302ms.
[19:35:36.608] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[19:35:36.885] <TB1> INFO: Expecting 41600 events.
[19:35:40.927] <TB1> INFO: 41600 events read in total (3450ms).
[19:35:40.928] <TB1> INFO: Test took 4319ms.
[19:35:40.931] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[19:35:41.207] <TB1> INFO: Expecting 41600 events.
[19:35:45.219] <TB1> INFO: 41600 events read in total (3420ms).
[19:35:45.220] <TB1> INFO: Test took 4289ms.
[19:35:45.223] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[19:35:45.499] <TB1> INFO: Expecting 41600 events.
[19:35:49.533] <TB1> INFO: 41600 events read in total (3442ms).
[19:35:49.534] <TB1> INFO: Test took 4311ms.
[19:35:49.537] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[19:35:49.813] <TB1> INFO: Expecting 41600 events.
[19:35:53.819] <TB1> INFO: 41600 events read in total (3414ms).
[19:35:53.820] <TB1> INFO: Test took 4283ms.
[19:35:54.232] <TB1> INFO: PixTestGainPedestal::measure() done
[19:36:26.533] <TB1> INFO: PixTestGainPedestal::fit() done
[19:36:26.533] <TB1> INFO: non-linearity mean: 0.904 0.981 0.978 0.979 0.986 0.923 0.979 0.983 0.912 0.981 0.942 0.921 0.904 1.063 0.979 0.963
[19:36:26.533] <TB1> INFO: non-linearity RMS: 0.144 0.004 0.005 0.005 0.188 0.076 0.003 0.004 0.095 0.006 0.175 0.103 0.130 0.097 0.005 0.016
[19:36:26.533] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C0.dat
[19:36:26.547] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C1.dat
[19:36:26.560] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C2.dat
[19:36:26.573] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C3.dat
[19:36:26.586] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C4.dat
[19:36:26.599] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C5.dat
[19:36:26.612] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C6.dat
[19:36:26.625] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C7.dat
[19:36:26.638] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C8.dat
[19:36:26.651] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C9.dat
[19:36:26.664] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C10.dat
[19:36:26.677] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C11.dat
[19:36:26.689] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C12.dat
[19:36:26.703] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C13.dat
[19:36:26.716] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C14.dat
[19:36:26.728] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//001_Fulltest_m20//phCalibrationFitErr35_C15.dat
[19:36:26.741] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 160 seconds
[19:36:26.741] <TB1> INFO: Decoding statistics:
[19:36:26.741] <TB1> INFO: General information:
[19:36:26.741] <TB1> INFO: 16bit words read: 3327836
[19:36:26.741] <TB1> INFO: valid events total: 332800
[19:36:26.741] <TB1> INFO: empty events: 0
[19:36:26.741] <TB1> INFO: valid events with pixels: 332800
[19:36:26.741] <TB1> INFO: valid pixel hits: 665518
[19:36:26.741] <TB1> INFO: Event errors: 0
[19:36:26.741] <TB1> INFO: start marker: 0
[19:36:26.741] <TB1> INFO: stop marker: 0
[19:36:26.741] <TB1> INFO: overflow: 0
[19:36:26.741] <TB1> INFO: invalid 5bit words: 0
[19:36:26.741] <TB1> INFO: invalid XOR eye diagram: 0
[19:36:26.741] <TB1> INFO: frame (failed synchr.): 0
[19:36:26.741] <TB1> INFO: idle data (no TBM trl): 0
[19:36:26.741] <TB1> INFO: no data (only TBM hdr): 0
[19:36:26.741] <TB1> INFO: TBM errors: 0
[19:36:26.742] <TB1> INFO: flawed TBM headers: 0
[19:36:26.742] <TB1> INFO: flawed TBM trailers: 0
[19:36:26.742] <TB1> INFO: event ID mismatches: 0
[19:36:26.742] <TB1> INFO: ROC errors: 0
[19:36:26.742] <TB1> INFO: missing ROC header(s): 0
[19:36:26.742] <TB1> INFO: misplaced readback start: 0
[19:36:26.742] <TB1> INFO: Pixel decoding errors: 0
[19:36:26.742] <TB1> INFO: pixel data incomplete: 0
[19:36:26.742] <TB1> INFO: pixel address: 0
[19:36:26.742] <TB1> INFO: pulse height fill bit: 0
[19:36:26.742] <TB1> INFO: buffer corruption: 0
[19:36:26.757] <TB1> INFO: Decoding statistics:
[19:36:26.757] <TB1> INFO: General information:
[19:36:26.757] <TB1> INFO: 16bit words read: 3457254
[19:36:26.757] <TB1> INFO: valid events total: 353536
[19:36:26.758] <TB1> INFO: empty events: 18235
[19:36:26.758] <TB1> INFO: valid events with pixels: 335301
[19:36:26.758] <TB1> INFO: valid pixel hits: 668019
[19:36:26.758] <TB1> INFO: Event errors: 0
[19:36:26.758] <TB1> INFO: start marker: 0
[19:36:26.758] <TB1> INFO: stop marker: 0
[19:36:26.758] <TB1> INFO: overflow: 0
[19:36:26.758] <TB1> INFO: invalid 5bit words: 0
[19:36:26.758] <TB1> INFO: invalid XOR eye diagram: 0
[19:36:26.758] <TB1> INFO: frame (failed synchr.): 0
[19:36:26.758] <TB1> INFO: idle data (no TBM trl): 0
[19:36:26.758] <TB1> INFO: no data (only TBM hdr): 0
[19:36:26.758] <TB1> INFO: TBM errors: 0
[19:36:26.758] <TB1> INFO: flawed TBM headers: 0
[19:36:26.758] <TB1> INFO: flawed TBM trailers: 0
[19:36:26.758] <TB1> INFO: event ID mismatches: 0
[19:36:26.758] <TB1> INFO: ROC errors: 0
[19:36:26.758] <TB1> INFO: missing ROC header(s): 0
[19:36:26.758] <TB1> INFO: misplaced readback start: 0
[19:36:26.758] <TB1> INFO: Pixel decoding errors: 0
[19:36:26.758] <TB1> INFO: pixel data incomplete: 0
[19:36:26.758] <TB1> INFO: pixel address: 0
[19:36:26.758] <TB1> INFO: pulse height fill bit: 0
[19:36:26.758] <TB1> INFO: buffer corruption: 0
[19:36:26.758] <TB1> INFO: enter test to run
[19:36:26.758] <TB1> INFO: test: exit no parameter change
[19:36:26.899] <TB1> QUIET: Connection to board 154 closed.
[19:36:26.901] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud