Test Date: 2016-10-19 19:52
Analysis date: 2016-10-20 16:31
Logfile
LogfileView
[22:23:37.335] <TB1> INFO: *** Welcome to pxar ***
[22:23:37.335] <TB1> INFO: *** Today: 2016/10/19
[22:23:37.341] <TB1> INFO: *** Version: c8ba-dirty
[22:23:37.341] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C15.dat
[22:23:37.341] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//tbmParameters_C1b.dat
[22:23:37.341] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//defaultMaskFile.dat
[22:23:37.341] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters_C15.dat
[22:23:37.403] <TB1> INFO: clk: 4
[22:23:37.403] <TB1> INFO: ctr: 4
[22:23:37.403] <TB1> INFO: sda: 19
[22:23:37.403] <TB1> INFO: tin: 9
[22:23:37.403] <TB1> INFO: level: 15
[22:23:37.403] <TB1> INFO: triggerdelay: 0
[22:23:37.403] <TB1> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[22:23:37.403] <TB1> INFO: Log level: INFO
[22:23:37.411] <TB1> INFO: Found DTB DTB_WXC03A
[22:23:37.422] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[22:23:37.424] <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:
------------------------------------------------------
[22:23:37.426] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[22:23:38.986] <TB1> INFO: DUT info:
[22:23:38.986] <TB1> INFO: The DUT currently contains the following objects:
[22:23:38.986] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[22:23:38.986] <TB1> INFO: TBM Core alpha (0): 7 registers set
[22:23:38.986] <TB1> INFO: TBM Core beta (1): 7 registers set
[22:23:38.986] <TB1> INFO: TBM Core alpha (2): 7 registers set
[22:23:38.986] <TB1> INFO: TBM Core beta (3): 7 registers set
[22:23:38.986] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[22:23:38.986] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:38.986] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[22:23:39.387] <TB1> INFO: enter 'restricted' command line mode
[22:23:39.387] <TB1> INFO: enter test to run
[22:23:39.387] <TB1> INFO: test: pretest no parameter change
[22:23:39.387] <TB1> INFO: running: pretest
[22:23:39.392] <TB1> INFO: ######################################################################
[22:23:39.392] <TB1> INFO: PixTestPretest::doTest()
[22:23:39.392] <TB1> INFO: ######################################################################
[22:23:39.393] <TB1> INFO: ----------------------------------------------------------------------
[22:23:39.393] <TB1> INFO: PixTestPretest::programROC()
[22:23:39.393] <TB1> INFO: ----------------------------------------------------------------------
[22:23:57.407] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[22:23:57.407] <TB1> INFO: IA differences per ROC: 19.3 19.3 18.5 20.1 21.7 19.3 19.3 20.1 20.1 20.1 18.5 19.3 20.1 19.3 19.3 18.5
[22:23:57.463] <TB1> INFO: ----------------------------------------------------------------------
[22:23:57.463] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[22:23:57.463] <TB1> INFO: ----------------------------------------------------------------------
[22:24:18.767] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 381 mA = 23.8125 mA/ROC
[22:24:18.767] <TB1> INFO: i(loss) [mA/ROC]: 19.2 18.4 17.6 19.2 18.4 19.2 18.4 18.4 19.2 18.4 18.4 18.4 17.6 18.4 18.4 20.1
[22:24:18.804] <TB1> INFO: ----------------------------------------------------------------------
[22:24:18.804] <TB1> INFO: PixTestPretest::findTiming()
[22:24:18.804] <TB1> INFO: ----------------------------------------------------------------------
[22:24:18.804] <TB1> INFO: PixTestCmd::init()
[22:24:19.371] <TB1> WARNING: Not unmasking DUT, not setting Calibrate bits!

[22:24:51.353] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[22:24:51.353] <TB1> INFO: (success/tries = 100/100), width = 4
[22:24:52.857] <TB1> INFO: ----------------------------------------------------------------------
[22:24:52.857] <TB1> INFO: PixTestPretest::findWorkingPixel()
[22:24:52.857] <TB1> INFO: ----------------------------------------------------------------------
[22:24:52.952] <TB1> INFO: Expecting 231680 events.
[22:25:02.919] <TB1> INFO: 231680 events read in total (9375ms).
[22:25:02.927] <TB1> INFO: Test took 10065ms.
[22:25:03.176] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[22:25:03.216] <TB1> INFO: ----------------------------------------------------------------------
[22:25:03.216] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[22:25:03.216] <TB1> INFO: ----------------------------------------------------------------------
[22:25:03.310] <TB1> INFO: Expecting 231680 events.
[22:25:13.258] <TB1> INFO: 231680 events read in total (9356ms).
[22:25:13.267] <TB1> INFO: Test took 10046ms.
[22:25:13.538] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[22:25:13.538] <TB1> INFO: CalDel: 95 106 96 92 112 113 105 90 108 106 98 83 97 93 88 107
[22:25:13.538] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[22:25:13.542] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C0.dat
[22:25:13.542] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C1.dat
[22:25:13.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C2.dat
[22:25:13.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C3.dat
[22:25:13.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C4.dat
[22:25:13.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C5.dat
[22:25:13.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C6.dat
[22:25:13.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C7.dat
[22:25:13.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C8.dat
[22:25:13.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C9.dat
[22:25:13.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C10.dat
[22:25:13.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C11.dat
[22:25:13.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C12.dat
[22:25:13.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C13.dat
[22:25:13.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C14.dat
[22:25:13.544] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters_C15.dat
[22:25:13.544] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//tbmParameters_C0a.dat
[22:25:13.544] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//tbmParameters_C0b.dat
[22:25:13.545] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//tbmParameters_C1a.dat
[22:25:13.545] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//tbmParameters_C1b.dat
[22:25:13.545] <TB1> INFO: PixTestPretest::doTest() done, duration: 94 seconds
[22:25:13.598] <TB1> INFO: enter test to run
[22:25:13.598] <TB1> INFO: test: FullTest no parameter change
[22:25:13.598] <TB1> INFO: running: fulltest
[22:25:13.598] <TB1> INFO: ######################################################################
[22:25:13.598] <TB1> INFO: PixTestFullTest::doTest()
[22:25:13.598] <TB1> INFO: ######################################################################
[22:25:13.599] <TB1> INFO: ######################################################################
[22:25:13.599] <TB1> INFO: PixTestAlive::doTest()
[22:25:13.599] <TB1> INFO: ######################################################################
[22:25:13.600] <TB1> INFO: ----------------------------------------------------------------------
[22:25:13.600] <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)
[22:25:13.600] <TB1> INFO: ----------------------------------------------------------------------
[22:25:13.841] <TB1> INFO: Expecting 41600 events.
[22:25:17.429] <TB1> INFO: 41600 events read in total (2996ms).
[22:25:17.429] <TB1> INFO: Test took 3827ms.
[22:25:17.657] <TB1> INFO: PixTestAlive::aliveTest() done
[22:25:17.657] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0
[22:25:17.659] <TB1> INFO: ----------------------------------------------------------------------
[22:25:17.659] <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)
[22:25:17.659] <TB1> INFO: ----------------------------------------------------------------------
[22:25:17.902] <TB1> INFO: Expecting 41600 events.
[22:25:20.915] <TB1> INFO: 41600 events read in total (2421ms).
[22:25:20.916] <TB1> INFO: Test took 3255ms.
[22:25:20.916] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[22:25:21.154] <TB1> INFO: PixTestAlive::maskTest() done
[22:25:21.154] <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
[22:25:21.156] <TB1> INFO: ----------------------------------------------------------------------
[22:25:21.156] <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)
[22:25:21.156] <TB1> INFO: ----------------------------------------------------------------------
[22:25:21.397] <TB1> INFO: Expecting 41600 events.
[22:25:24.971] <TB1> INFO: 41600 events read in total (2982ms).
[22:25:24.972] <TB1> INFO: Test took 3813ms.
[22:25:25.206] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[22:25:25.206] <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
[22:25:25.207] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[22:25:25.207] <TB1> INFO: Decoding statistics:
[22:25:25.207] <TB1> INFO: General information:
[22:25:25.207] <TB1> INFO: 16bit words read: 0
[22:25:25.207] <TB1> INFO: valid events total: 0
[22:25:25.207] <TB1> INFO: empty events: 0
[22:25:25.207] <TB1> INFO: valid events with pixels: 0
[22:25:25.207] <TB1> INFO: valid pixel hits: 0
[22:25:25.207] <TB1> INFO: Event errors: 0
[22:25:25.207] <TB1> INFO: start marker: 0
[22:25:25.207] <TB1> INFO: stop marker: 0
[22:25:25.207] <TB1> INFO: overflow: 0
[22:25:25.207] <TB1> INFO: invalid 5bit words: 0
[22:25:25.207] <TB1> INFO: invalid XOR eye diagram: 0
[22:25:25.207] <TB1> INFO: frame (failed synchr.): 0
[22:25:25.207] <TB1> INFO: idle data (no TBM trl): 0
[22:25:25.207] <TB1> INFO: no data (only TBM hdr): 0
[22:25:25.207] <TB1> INFO: TBM errors: 0
[22:25:25.207] <TB1> INFO: flawed TBM headers: 0
[22:25:25.207] <TB1> INFO: flawed TBM trailers: 0
[22:25:25.207] <TB1> INFO: event ID mismatches: 0
[22:25:25.207] <TB1> INFO: ROC errors: 0
[22:25:25.207] <TB1> INFO: missing ROC header(s): 0
[22:25:25.207] <TB1> INFO: misplaced readback start: 0
[22:25:25.207] <TB1> INFO: Pixel decoding errors: 0
[22:25:25.207] <TB1> INFO: pixel data incomplete: 0
[22:25:25.207] <TB1> INFO: pixel address: 0
[22:25:25.207] <TB1> INFO: pulse height fill bit: 0
[22:25:25.207] <TB1> INFO: buffer corruption: 0
[22:25:25.216] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C15.dat
[22:25:25.217] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr_C15.dat
[22:25:25.217] <TB1> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[22:25:25.217] <TB1> INFO: ######################################################################
[22:25:25.217] <TB1> INFO: PixTestReadback::doTest()
[22:25:25.217] <TB1> INFO: ######################################################################
[22:25:25.217] <TB1> INFO: ----------------------------------------------------------------------
[22:25:25.217] <TB1> INFO: PixTestReadback::CalibrateVd()
[22:25:25.217] <TB1> INFO: ----------------------------------------------------------------------
[22:25:35.192] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C0.dat
[22:25:35.192] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C1.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C2.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C3.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C4.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C5.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C6.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C7.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C8.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C9.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C10.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C11.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C12.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C13.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C14.dat
[22:25:35.193] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C15.dat
[22:25:35.222] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[22:25:35.222] <TB1> INFO: ----------------------------------------------------------------------
[22:25:35.222] <TB1> INFO: PixTestReadback::CalibrateVa()
[22:25:35.222] <TB1> INFO: ----------------------------------------------------------------------
[22:25:45.163] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C0.dat
[22:25:45.163] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C1.dat
[22:25:45.163] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C2.dat
[22:25:45.163] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C3.dat
[22:25:45.163] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C4.dat
[22:25:45.163] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C5.dat
[22:25:45.163] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C6.dat
[22:25:45.164] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C7.dat
[22:25:45.164] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C8.dat
[22:25:45.164] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C9.dat
[22:25:45.164] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C10.dat
[22:25:45.164] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C11.dat
[22:25:45.164] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C12.dat
[22:25:45.164] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C13.dat
[22:25:45.164] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C14.dat
[22:25:45.164] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C15.dat
[22:25:45.194] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[22:25:45.194] <TB1> INFO: ----------------------------------------------------------------------
[22:25:45.194] <TB1> INFO: PixTestReadback::readbackVbg()
[22:25:45.194] <TB1> INFO: ----------------------------------------------------------------------
[22:25:52.867] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[22:25:52.867] <TB1> INFO: ----------------------------------------------------------------------
[22:25:52.867] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[22:25:52.867] <TB1> INFO: ----------------------------------------------------------------------
[22:25:52.867] <TB1> INFO: Vbg will be calibrated using Vd calibration
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 156.5calibrated Vbg = 1.20374 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 146.2calibrated Vbg = 1.20355 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 158.9calibrated Vbg = 1.19692 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 142.8calibrated Vbg = 1.19586 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 150.1calibrated Vbg = 1.19216 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 158.8calibrated Vbg = 1.19447 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 155calibrated Vbg = 1.20323 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 150.3calibrated Vbg = 1.2012 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 162.2calibrated Vbg = 1.19782 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 149.8calibrated Vbg = 1.19097 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 150.3calibrated Vbg = 1.18929 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 154.1calibrated Vbg = 1.18569 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 155.2calibrated Vbg = 1.1946 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 157calibrated Vbg = 1.1976 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 156.5calibrated Vbg = 1.19526 :::*/*/*/*/
[22:25:52.867] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 158.7calibrated Vbg = 1.20209 :::*/*/*/*/
[22:25:52.870] <TB1> INFO: ----------------------------------------------------------------------
[22:25:52.870] <TB1> INFO: PixTestReadback::CalibrateIa()
[22:25:52.870] <TB1> INFO: ----------------------------------------------------------------------
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C0.dat
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C1.dat
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C2.dat
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C3.dat
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C4.dat
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C5.dat
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C6.dat
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C7.dat
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C8.dat
[22:28:33.714] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C9.dat
[22:28:33.715] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C10.dat
[22:28:33.715] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C11.dat
[22:28:33.715] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C12.dat
[22:28:33.715] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C13.dat
[22:28:33.715] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C14.dat
[22:28:33.715] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//readbackCal_C15.dat
[22:28:33.745] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[22:28:33.748] <TB1> INFO: PixTestReadback::doTest() done
[22:28:33.748] <TB1> INFO: Decoding statistics:
[22:28:33.748] <TB1> INFO: General information:
[22:28:33.748] <TB1> INFO: 16bit words read: 1536
[22:28:33.748] <TB1> INFO: valid events total: 256
[22:28:33.749] <TB1> INFO: empty events: 256
[22:28:33.749] <TB1> INFO: valid events with pixels: 0
[22:28:33.749] <TB1> INFO: valid pixel hits: 0
[22:28:33.749] <TB1> INFO: Event errors: 0
[22:28:33.749] <TB1> INFO: start marker: 0
[22:28:33.749] <TB1> INFO: stop marker: 0
[22:28:33.749] <TB1> INFO: overflow: 0
[22:28:33.749] <TB1> INFO: invalid 5bit words: 0
[22:28:33.749] <TB1> INFO: invalid XOR eye diagram: 0
[22:28:33.749] <TB1> INFO: frame (failed synchr.): 0
[22:28:33.749] <TB1> INFO: idle data (no TBM trl): 0
[22:28:33.749] <TB1> INFO: no data (only TBM hdr): 0
[22:28:33.749] <TB1> INFO: TBM errors: 0
[22:28:33.749] <TB1> INFO: flawed TBM headers: 0
[22:28:33.749] <TB1> INFO: flawed TBM trailers: 0
[22:28:33.749] <TB1> INFO: event ID mismatches: 0
[22:28:33.749] <TB1> INFO: ROC errors: 0
[22:28:33.749] <TB1> INFO: missing ROC header(s): 0
[22:28:33.749] <TB1> INFO: misplaced readback start: 0
[22:28:33.749] <TB1> INFO: Pixel decoding errors: 0
[22:28:33.749] <TB1> INFO: pixel data incomplete: 0
[22:28:33.749] <TB1> INFO: pixel address: 0
[22:28:33.749] <TB1> INFO: pulse height fill bit: 0
[22:28:33.749] <TB1> INFO: buffer corruption: 0
[22:28:33.801] <TB1> INFO: ######################################################################
[22:28:33.801] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[22:28:33.801] <TB1> INFO: ######################################################################
[22:28:33.805] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[22:28:33.817] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[22:28:33.817] <TB1> INFO: run 1 of 1
[22:28:34.053] <TB1> INFO: Expecting 3120000 events.
[22:29:05.552] <TB1> INFO: 682415 events read in total (30907ms).
[22:29:18.188] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (48) != TBM ID (129)

[22:29:18.325] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 48 48 129 48 48 48 48 48

[22:29:18.325] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (49)

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

[22:29:18.325] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a034 80b1 40c0 266 2bed 41c0 266 2bef e022 c000

[22:29:18.325] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02e 8000 4080 266 2bed 4180 266 2bef e022 c000

[22:29:18.325] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02f 8040 40c3 266 2bef 40c3 266 2bef e022 c000

[22:29:18.325] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4081 4081 2bef 4180 266 2bef e022 c000

[22:29:18.325] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a031 80c0 41c1 266 2bef 4181 266 2bef e022 c000

[22:29:18.326] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a032 8000 41c0 266 2bef 4180 266 2bef e022 c000

[22:29:18.326] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a033 8040 40c0 266 2bed 41c1 266 2bef e022 c000

[22:29:36.860] <TB1> INFO: 1370615 events read in total (62215ms).
[22:29:49.468] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (120) != TBM ID (129)

[22:29:49.610] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 120 120 129 120 120 120 120 120

[22:29:49.610] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (121)

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

[22:29:49.611] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07c 80b1 41c1 41c1 e022 c000

[22:29:49.611] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a076 8000 4180 4180 e022 c000

[22:29:49.611] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a077 8040 40c0 41c0 e022 c000

[22:29:49.611] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4081 4081 e022 c000

[22:29:49.611] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a079 80c0 4181 4181 e022 c000

[22:29:49.611] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07a 8000 40c0 40c0 e022 c000

[22:29:49.611] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07b 8040 40c0 40c0 e022 c000

[22:30:08.264] <TB1> INFO: 2057200 events read in total (93619ms).
[22:30:20.883] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (113) != TBM ID (129)

[22:30:21.020] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 113 113 129 113 113 113 113 113

[22:30:21.020] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (114)

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

[22:30:21.022] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a075 80c0 41c0 844 2def 41c0 844 2def e022 c000

[22:30:21.022] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06f 8040 41c3 844 2def 41c3 844 2def e022 c000

[22:30:21.022] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a070 80b1 41c0 844 2def 4180 844 2def e022 c000

[22:30:21.022] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4081 4081 2def 4181 844 2def e022 c000

[22:30:21.022] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a072 8000 4080 844 2def 41c0 844 2def e022 c000

[22:30:21.022] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a073 8040 41c0 844 2def 41c1 844 2def e022 c000

[22:30:21.022] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a074 80b1 40c0 844 2def 40c0 844 2def e022 c000

[22:30:39.735] <TB1> INFO: 2744495 events read in total (125090ms).
[22:30:46.765] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (48) != TBM ID (129)

[22:30:46.903] <TB1> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 48 48 129 48 48 48 48 48

[22:30:46.903] <TB1> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (49)

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

[22:30:46.903] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a034 80b1 40c0 40c0 e022 c000

[22:30:46.903] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02e 8000 40c0 40c0 e022 c000

[22:30:46.903] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a02f 8040 40c3 40c3 e022 c000

[22:30:46.903] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4081 4081 e022 c000

[22:30:46.903] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a031 80c0 4181 4181 e022 c000

[22:30:46.903] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a032 8000 4180 4180 e022 c000

[22:30:46.903] <TB1> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a033 8040 4180 4181 e022 c000

[22:30:57.135] <TB1> INFO: 3120000 events read in total (142490ms).
[22:30:57.213] <TB1> INFO: Test took 143397ms.
[22:31:21.242] <TB1> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 167 seconds
[22:31:21.242] <TB1> INFO: number of dead bumps (per ROC): 3 2 1 0 2 1 0 0 1 33 0 0 2 1 0 0
[22:31:21.242] <TB1> INFO: separation cut (per ROC): 101 115 103 103 118 113 103 120 103 95 113 109 100 100 118 117
[22:31:21.242] <TB1> INFO: Decoding statistics:
[22:31:21.242] <TB1> INFO: General information:
[22:31:21.242] <TB1> INFO: 16bit words read: 0
[22:31:21.242] <TB1> INFO: valid events total: 0
[22:31:21.242] <TB1> INFO: empty events: 0
[22:31:21.242] <TB1> INFO: valid events with pixels: 0
[22:31:21.242] <TB1> INFO: valid pixel hits: 0
[22:31:21.242] <TB1> INFO: Event errors: 0
[22:31:21.242] <TB1> INFO: start marker: 0
[22:31:21.242] <TB1> INFO: stop marker: 0
[22:31:21.242] <TB1> INFO: overflow: 0
[22:31:21.242] <TB1> INFO: invalid 5bit words: 0
[22:31:21.242] <TB1> INFO: invalid XOR eye diagram: 0
[22:31:21.242] <TB1> INFO: frame (failed synchr.): 0
[22:31:21.242] <TB1> INFO: idle data (no TBM trl): 0
[22:31:21.242] <TB1> INFO: no data (only TBM hdr): 0
[22:31:21.242] <TB1> INFO: TBM errors: 0
[22:31:21.242] <TB1> INFO: flawed TBM headers: 0
[22:31:21.242] <TB1> INFO: flawed TBM trailers: 0
[22:31:21.242] <TB1> INFO: event ID mismatches: 0
[22:31:21.242] <TB1> INFO: ROC errors: 0
[22:31:21.242] <TB1> INFO: missing ROC header(s): 0
[22:31:21.242] <TB1> INFO: misplaced readback start: 0
[22:31:21.242] <TB1> INFO: Pixel decoding errors: 0
[22:31:21.242] <TB1> INFO: pixel data incomplete: 0
[22:31:21.242] <TB1> INFO: pixel address: 0
[22:31:21.242] <TB1> INFO: pulse height fill bit: 0
[22:31:21.242] <TB1> INFO: buffer corruption: 0
[22:31:21.282] <TB1> INFO: ######################################################################
[22:31:21.282] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[22:31:21.282] <TB1> INFO: ######################################################################
[22:31:21.282] <TB1> INFO: ----------------------------------------------------------------------
[22:31:21.282] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[22:31:21.282] <TB1> INFO: ----------------------------------------------------------------------
[22:31:21.282] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[22:31:21.297] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[22:31:21.297] <TB1> INFO: run 1 of 1
[22:31:21.563] <TB1> INFO: Expecting 36608000 events.
[22:31:45.914] <TB1> INFO: 688800 events read in total (23760ms).
[22:32:09.502] <TB1> INFO: 1364800 events read in total (47348ms).
[22:32:32.960] <TB1> INFO: 2037550 events read in total (70806ms).
[22:32:56.369] <TB1> INFO: 2709500 events read in total (94215ms).
[22:33:19.661] <TB1> INFO: 3381550 events read in total (117507ms).
[22:33:43.274] <TB1> INFO: 4054350 events read in total (141120ms).
[22:34:06.480] <TB1> INFO: 4723100 events read in total (164326ms).
[22:34:29.995] <TB1> INFO: 5393100 events read in total (187841ms).
[22:34:53.277] <TB1> INFO: 6062900 events read in total (211123ms).
[22:35:16.668] <TB1> INFO: 6733200 events read in total (234514ms).
[22:35:39.916] <TB1> INFO: 7404650 events read in total (257762ms).
[22:36:03.408] <TB1> INFO: 8076000 events read in total (281254ms).
[22:36:26.853] <TB1> INFO: 8745450 events read in total (304699ms).
[22:36:50.631] <TB1> INFO: 9414550 events read in total (328477ms).
[22:37:14.359] <TB1> INFO: 10084100 events read in total (352205ms).
[22:37:37.875] <TB1> INFO: 10752450 events read in total (375721ms).
[22:38:01.237] <TB1> INFO: 11420800 events read in total (399084ms).
[22:38:24.781] <TB1> INFO: 12091650 events read in total (422627ms).
[22:38:48.193] <TB1> INFO: 12762350 events read in total (446039ms).
[22:39:11.926] <TB1> INFO: 13431700 events read in total (469772ms).
[22:39:35.403] <TB1> INFO: 14100500 events read in total (493249ms).
[22:39:58.979] <TB1> INFO: 14766650 events read in total (516825ms).
[22:40:22.488] <TB1> INFO: 15434050 events read in total (540334ms).
[22:40:45.845] <TB1> INFO: 16099200 events read in total (563691ms).
[22:41:09.246] <TB1> INFO: 16765250 events read in total (587092ms).
[22:41:32.640] <TB1> INFO: 17430800 events read in total (610486ms).
[22:41:56.191] <TB1> INFO: 18096150 events read in total (634037ms).
[22:42:19.675] <TB1> INFO: 18761050 events read in total (657521ms).
[22:42:43.155] <TB1> INFO: 19426650 events read in total (681001ms).
[22:43:06.480] <TB1> INFO: 20089550 events read in total (704326ms).
[22:43:29.726] <TB1> INFO: 20754900 events read in total (727572ms).
[22:43:53.101] <TB1> INFO: 21418600 events read in total (750947ms).
[22:44:16.657] <TB1> INFO: 22083950 events read in total (774503ms).
[22:44:40.112] <TB1> INFO: 22747600 events read in total (797958ms).
[22:45:03.591] <TB1> INFO: 23412450 events read in total (821437ms).
[22:45:27.082] <TB1> INFO: 24074800 events read in total (844928ms).
[22:45:50.783] <TB1> INFO: 24739850 events read in total (868629ms).
[22:46:14.197] <TB1> INFO: 25403950 events read in total (892043ms).
[22:46:37.529] <TB1> INFO: 26065400 events read in total (915375ms).
[22:47:01.268] <TB1> INFO: 26729200 events read in total (939114ms).
[22:47:24.755] <TB1> INFO: 27391550 events read in total (962601ms).
[22:47:48.149] <TB1> INFO: 28054100 events read in total (985995ms).
[22:48:11.286] <TB1> INFO: 28718050 events read in total (1009132ms).
[22:48:34.430] <TB1> INFO: 29380350 events read in total (1032276ms).
[22:48:57.738] <TB1> INFO: 30042300 events read in total (1055584ms).
[22:49:21.113] <TB1> INFO: 30707200 events read in total (1078959ms).
[22:49:44.625] <TB1> INFO: 31369600 events read in total (1102471ms).
[22:50:08.164] <TB1> INFO: 32032700 events read in total (1126010ms).
[22:50:31.501] <TB1> INFO: 32696000 events read in total (1149347ms).
[22:50:54.915] <TB1> INFO: 33359550 events read in total (1172761ms).
[22:51:18.192] <TB1> INFO: 34025600 events read in total (1196038ms).
[22:51:41.645] <TB1> INFO: 34692050 events read in total (1219491ms).
[22:52:05.310] <TB1> INFO: 35358350 events read in total (1243156ms).
[22:52:29.112] <TB1> INFO: 36026650 events read in total (1266958ms).
[22:52:50.258] <TB1> INFO: 36608000 events read in total (1288104ms).
[22:52:50.337] <TB1> INFO: Test took 1289040ms.
[22:52:50.748] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:52:53.023] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:52:55.362] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:52:57.712] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:52:59.447] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:00.904] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:02.369] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:04.063] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:05.895] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:07.576] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:09.271] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:11.121] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:12.964] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:14.888] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:16.648] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:18.256] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[22:53:19.732] <TB1> INFO: PixTestScurves::scurves() done
[22:53:19.732] <TB1> INFO: Vcal mean: 112.76 123.28 123.07 116.73 123.50 128.19 123.23 122.33 113.76 119.94 122.99 113.02 113.36 114.05 123.22 122.07
[22:53:19.732] <TB1> INFO: Vcal RMS: 4.56 6.50 6.64 5.54 5.90 6.54 6.21 6.23 4.80 7.42 6.45 5.45 5.09 4.80 6.09 5.53
[22:53:19.732] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1318 seconds
[22:53:19.732] <TB1> INFO: Decoding statistics:
[22:53:19.732] <TB1> INFO: General information:
[22:53:19.732] <TB1> INFO: 16bit words read: 0
[22:53:19.732] <TB1> INFO: valid events total: 0
[22:53:19.732] <TB1> INFO: empty events: 0
[22:53:19.732] <TB1> INFO: valid events with pixels: 0
[22:53:19.732] <TB1> INFO: valid pixel hits: 0
[22:53:19.732] <TB1> INFO: Event errors: 0
[22:53:19.732] <TB1> INFO: start marker: 0
[22:53:19.732] <TB1> INFO: stop marker: 0
[22:53:19.732] <TB1> INFO: overflow: 0
[22:53:19.733] <TB1> INFO: invalid 5bit words: 0
[22:53:19.733] <TB1> INFO: invalid XOR eye diagram: 0
[22:53:19.733] <TB1> INFO: frame (failed synchr.): 0
[22:53:19.733] <TB1> INFO: idle data (no TBM trl): 0
[22:53:19.733] <TB1> INFO: no data (only TBM hdr): 0
[22:53:19.733] <TB1> INFO: TBM errors: 0
[22:53:19.733] <TB1> INFO: flawed TBM headers: 0
[22:53:19.733] <TB1> INFO: flawed TBM trailers: 0
[22:53:19.733] <TB1> INFO: event ID mismatches: 0
[22:53:19.733] <TB1> INFO: ROC errors: 0
[22:53:19.733] <TB1> INFO: missing ROC header(s): 0
[22:53:19.733] <TB1> INFO: misplaced readback start: 0
[22:53:19.733] <TB1> INFO: Pixel decoding errors: 0
[22:53:19.733] <TB1> INFO: pixel data incomplete: 0
[22:53:19.733] <TB1> INFO: pixel address: 0
[22:53:19.733] <TB1> INFO: pulse height fill bit: 0
[22:53:19.733] <TB1> INFO: buffer corruption: 0
[22:53:19.815] <TB1> INFO: ######################################################################
[22:53:19.815] <TB1> INFO: PixTestTrim::doTest()
[22:53:19.815] <TB1> INFO: ######################################################################
[22:53:19.817] <TB1> INFO: ----------------------------------------------------------------------
[22:53:19.817] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[22:53:19.817] <TB1> INFO: ----------------------------------------------------------------------
[22:53:19.876] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[22:53:19.876] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[22:53:19.889] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[22:53:19.889] <TB1> INFO: run 1 of 1
[22:53:20.179] <TB1> INFO: Expecting 5025280 events.
[22:53:51.833] <TB1> INFO: 829656 events read in total (31052ms).
[22:54:22.783] <TB1> INFO: 1656808 events read in total (62002ms).
[22:54:54.049] <TB1> INFO: 2481664 events read in total (93268ms).
[22:55:24.781] <TB1> INFO: 3304912 events read in total (124000ms).
[22:55:55.258] <TB1> INFO: 4125808 events read in total (154478ms).
[22:56:25.974] <TB1> INFO: 4946760 events read in total (185193ms).
[22:56:29.277] <TB1> INFO: 5025280 events read in total (188496ms).
[22:56:29.326] <TB1> INFO: Test took 189438ms.
[22:56:46.743] <TB1> INFO: ROC 0 VthrComp = 111
[22:56:46.743] <TB1> INFO: ROC 1 VthrComp = 119
[22:56:46.743] <TB1> INFO: ROC 2 VthrComp = 117
[22:56:46.743] <TB1> INFO: ROC 3 VthrComp = 117
[22:56:46.743] <TB1> INFO: ROC 4 VthrComp = 119
[22:56:46.743] <TB1> INFO: ROC 5 VthrComp = 121
[22:56:46.743] <TB1> INFO: ROC 6 VthrComp = 112
[22:56:46.743] <TB1> INFO: ROC 7 VthrComp = 122
[22:56:46.743] <TB1> INFO: ROC 8 VthrComp = 110
[22:56:46.744] <TB1> INFO: ROC 9 VthrComp = 114
[22:56:46.744] <TB1> INFO: ROC 10 VthrComp = 114
[22:56:46.744] <TB1> INFO: ROC 11 VthrComp = 108
[22:56:46.744] <TB1> INFO: ROC 12 VthrComp = 111
[22:56:46.744] <TB1> INFO: ROC 13 VthrComp = 113
[22:56:46.744] <TB1> INFO: ROC 14 VthrComp = 119
[22:56:46.744] <TB1> INFO: ROC 15 VthrComp = 118
[22:56:46.988] <TB1> INFO: Expecting 41600 events.
[22:56:50.610] <TB1> INFO: 41600 events read in total (3031ms).
[22:56:50.610] <TB1> INFO: Test took 3864ms.
[22:56:50.620] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[22:56:50.620] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[22:56:50.631] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[22:56:50.631] <TB1> INFO: run 1 of 1
[22:56:50.909] <TB1> INFO: Expecting 5025280 events.
[22:57:18.227] <TB1> INFO: 593480 events read in total (26726ms).
[22:57:44.476] <TB1> INFO: 1185552 events read in total (52975ms).
[22:58:10.906] <TB1> INFO: 1777888 events read in total (79405ms).
[22:58:37.159] <TB1> INFO: 2368536 events read in total (105658ms).
[22:59:03.544] <TB1> INFO: 2956968 events read in total (132043ms).
[22:59:30.034] <TB1> INFO: 3544352 events read in total (158533ms).
[22:59:56.321] <TB1> INFO: 4130520 events read in total (184820ms).
[23:00:21.701] <TB1> INFO: 4715832 events read in total (210200ms).
[23:00:35.301] <TB1> INFO: 5025280 events read in total (223800ms).
[23:00:35.383] <TB1> INFO: Test took 224752ms.
[23:00:58.054] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 61.9224 for pixel 5/4 mean/min/max = 48.2057/34.4264/61.9851
[23:00:58.054] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 61.3347 for pixel 17/2 mean/min/max = 46.5782/31.6987/61.4576
[23:00:58.055] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 62.7302 for pixel 22/4 mean/min/max = 47.2827/31.6861/62.8794
[23:00:58.055] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 60.0795 for pixel 7/11 mean/min/max = 46.407/32.589/60.225
[23:00:58.056] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 60.3497 for pixel 22/26 mean/min/max = 45.985/31.5889/60.3811
[23:00:58.056] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 61.9205 for pixel 19/6 mean/min/max = 47.4874/32.7564/62.2184
[23:00:58.057] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 64.0658 for pixel 7/15 mean/min/max = 48.6178/33.1418/64.0938
[23:00:58.058] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 59.872 for pixel 22/1 mean/min/max = 46.4842/33.0911/59.8773
[23:00:58.058] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 61.8326 for pixel 0/0 mean/min/max = 48.5976/35.3348/61.8604
[23:00:58.059] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 63.0667 for pixel 3/2 mean/min/max = 47.2629/31.3528/63.173
[23:00:58.059] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 62.2064 for pixel 31/1 mean/min/max = 47.5787/32.8506/62.3069
[23:00:58.060] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 62.2025 for pixel 17/76 mean/min/max = 48.5053/34.7997/62.2109
[23:00:58.060] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 61.6268 for pixel 49/22 mean/min/max = 48.3822/35.1012/61.6632
[23:00:58.061] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 59.0918 for pixel 47/17 mean/min/max = 46.3246/33.3052/59.3439
[23:00:58.061] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 60.8935 for pixel 7/29 mean/min/max = 46.4248/31.9243/60.9253
[23:00:58.061] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 61.7362 for pixel 0/14 mean/min/max = 46.5408/31.1653/61.9163
[23:00:58.062] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:00:58.151] <TB1> INFO: Expecting 411648 events.
[23:01:07.729] <TB1> INFO: 411648 events read in total (8986ms).
[23:01:07.736] <TB1> INFO: Expecting 411648 events.
[23:01:17.094] <TB1> INFO: 411648 events read in total (8955ms).
[23:01:17.104] <TB1> INFO: Expecting 411648 events.
[23:01:26.548] <TB1> INFO: 411648 events read in total (9041ms).
[23:01:26.562] <TB1> INFO: Expecting 411648 events.
[23:01:36.093] <TB1> INFO: 411648 events read in total (9128ms).
[23:01:36.108] <TB1> INFO: Expecting 411648 events.
[23:01:45.549] <TB1> INFO: 411648 events read in total (9037ms).
[23:01:45.567] <TB1> INFO: Expecting 411648 events.
[23:01:55.064] <TB1> INFO: 411648 events read in total (9094ms).
[23:01:55.085] <TB1> INFO: Expecting 411648 events.
[23:02:04.606] <TB1> INFO: 411648 events read in total (9118ms).
[23:02:04.636] <TB1> INFO: Expecting 411648 events.
[23:02:14.121] <TB1> INFO: 411648 events read in total (9082ms).
[23:02:14.147] <TB1> INFO: Expecting 411648 events.
[23:02:23.643] <TB1> INFO: 411648 events read in total (9093ms).
[23:02:23.674] <TB1> INFO: Expecting 411648 events.
[23:02:33.007] <TB1> INFO: 411648 events read in total (8930ms).
[23:02:33.038] <TB1> INFO: Expecting 411648 events.
[23:02:42.232] <TB1> INFO: 411648 events read in total (8791ms).
[23:02:42.269] <TB1> INFO: Expecting 411648 events.
[23:02:51.704] <TB1> INFO: 411648 events read in total (9032ms).
[23:02:51.741] <TB1> INFO: Expecting 411648 events.
[23:03:00.950] <TB1> INFO: 411648 events read in total (8805ms).
[23:03:00.000] <TB1> INFO: Expecting 411648 events.
[23:03:10.173] <TB1> INFO: 411648 events read in total (8770ms).
[23:03:10.218] <TB1> INFO: Expecting 411648 events.
[23:03:19.581] <TB1> INFO: 411648 events read in total (8960ms).
[23:03:19.626] <TB1> INFO: Expecting 411648 events.
[23:03:28.800] <TB1> INFO: 411648 events read in total (8770ms).
[23:03:28.849] <TB1> INFO: Test took 150787ms.
[23:03:29.584] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[23:03:29.595] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[23:03:29.595] <TB1> INFO: run 1 of 1
[23:03:29.851] <TB1> INFO: Expecting 5025280 events.
[23:03:56.905] <TB1> INFO: 589280 events read in total (26463ms).
[23:04:23.775] <TB1> INFO: 1177696 events read in total (53333ms).
[23:04:50.593] <TB1> INFO: 1766592 events read in total (80151ms).
[23:05:17.098] <TB1> INFO: 2354168 events read in total (106656ms).
[23:05:43.763] <TB1> INFO: 2943168 events read in total (133322ms).
[23:06:10.475] <TB1> INFO: 3533952 events read in total (160033ms).
[23:06:37.160] <TB1> INFO: 4125104 events read in total (186718ms).
[23:07:04.125] <TB1> INFO: 4716048 events read in total (213683ms).
[23:07:18.256] <TB1> INFO: 5025280 events read in total (227814ms).
[23:07:18.425] <TB1> INFO: Test took 228830ms.
[23:07:40.190] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 9.329082 .. 145.244760
[23:07:40.429] <TB1> INFO: Expecting 208000 events.
[23:07:50.327] <TB1> INFO: 208000 events read in total (9306ms).
[23:07:50.327] <TB1> INFO: Test took 10136ms.
[23:07:50.377] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 9 .. 155 (-1/-1) hits flags = 528 (plus default)
[23:07:50.390] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[23:07:50.390] <TB1> INFO: run 1 of 1
[23:07:50.668] <TB1> INFO: Expecting 4892160 events.
[23:08:17.577] <TB1> INFO: 574504 events read in total (26318ms).
[23:08:43.722] <TB1> INFO: 1149096 events read in total (52464ms).
[23:09:09.947] <TB1> INFO: 1722952 events read in total (78688ms).
[23:09:36.208] <TB1> INFO: 2297232 events read in total (104949ms).
[23:10:02.302] <TB1> INFO: 2871784 events read in total (131043ms).
[23:10:28.657] <TB1> INFO: 3445752 events read in total (157398ms).
[23:10:54.586] <TB1> INFO: 4019944 events read in total (183327ms).
[23:11:20.470] <TB1> INFO: 4593776 events read in total (209211ms).
[23:11:34.090] <TB1> INFO: 4892160 events read in total (222831ms).
[23:11:34.178] <TB1> INFO: Test took 223788ms.
[23:11:56.835] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 27.681111 .. 50.210320
[23:11:57.072] <TB1> INFO: Expecting 208000 events.
[23:12:06.956] <TB1> INFO: 208000 events read in total (9293ms).
[23:12:06.957] <TB1> INFO: Test took 10121ms.
[23:12:07.011] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 60 (-1/-1) hits flags = 528 (plus default)
[23:12:07.024] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[23:12:07.024] <TB1> INFO: run 1 of 1
[23:12:07.303] <TB1> INFO: Expecting 1464320 events.
[23:12:35.814] <TB1> INFO: 644088 events read in total (27920ms).
[23:13:03.412] <TB1> INFO: 1287152 events read in total (55518ms).
[23:13:11.494] <TB1> INFO: 1464320 events read in total (63600ms).
[23:13:11.528] <TB1> INFO: Test took 64504ms.
[23:13:25.073] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 26.835139 .. 56.220495
[23:13:25.311] <TB1> INFO: Expecting 208000 events.
[23:13:35.304] <TB1> INFO: 208000 events read in total (9401ms).
[23:13:35.305] <TB1> INFO: Test took 10230ms.
[23:13:35.373] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 66 (-1/-1) hits flags = 528 (plus default)
[23:13:35.386] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[23:13:35.386] <TB1> INFO: run 1 of 1
[23:13:35.664] <TB1> INFO: Expecting 1697280 events.
[23:14:03.298] <TB1> INFO: 631744 events read in total (27042ms).
[23:14:30.374] <TB1> INFO: 1262800 events read in total (54118ms).
[23:14:48.970] <TB1> INFO: 1697280 events read in total (72714ms).
[23:14:49.012] <TB1> INFO: Test took 73626ms.
[23:15:05.331] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 26.247073 .. 59.313533
[23:15:05.568] <TB1> INFO: Expecting 208000 events.
[23:15:15.454] <TB1> INFO: 208000 events read in total (9295ms).
[23:15:15.454] <TB1> INFO: Test took 10122ms.
[23:15:15.524] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 16 .. 69 (-1/-1) hits flags = 528 (plus default)
[23:15:15.538] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[23:15:15.538] <TB1> INFO: run 1 of 1
[23:15:15.847] <TB1> INFO: Expecting 1797120 events.
[23:15:44.152] <TB1> INFO: 624048 events read in total (27714ms).
[23:16:11.199] <TB1> INFO: 1247832 events read in total (54761ms).
[23:16:35.225] <TB1> INFO: 1797120 events read in total (78787ms).
[23:16:35.279] <TB1> INFO: Test took 79742ms.
[23:16:49.284] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[23:16:49.284] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[23:16:49.297] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[23:16:49.298] <TB1> INFO: run 1 of 1
[23:16:49.535] <TB1> INFO: Expecting 1364480 events.
[23:17:19.024] <TB1> INFO: 669336 events read in total (28897ms).
[23:17:48.217] <TB1> INFO: 1338000 events read in total (58090ms).
[23:17:49.757] <TB1> INFO: 1364480 events read in total (59630ms).
[23:17:49.783] <TB1> INFO: Test took 60486ms.
[23:18:04.661] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C0.dat
[23:18:04.661] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C1.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C2.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C3.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C4.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C5.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C6.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C7.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C8.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C9.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C10.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C11.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C12.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C13.dat
[23:18:04.662] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C14.dat
[23:18:04.663] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C15.dat
[23:18:04.663] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C0.dat
[23:18:04.668] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C1.dat
[23:18:04.673] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C2.dat
[23:18:04.678] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C3.dat
[23:18:04.683] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C4.dat
[23:18:04.687] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C5.dat
[23:18:04.692] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C6.dat
[23:18:04.696] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C7.dat
[23:18:04.701] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C8.dat
[23:18:04.706] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C9.dat
[23:18:04.712] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C10.dat
[23:18:04.718] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C11.dat
[23:18:04.725] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C12.dat
[23:18:04.731] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C13.dat
[23:18:04.738] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C14.dat
[23:18:04.745] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//trimParameters35_C15.dat
[23:18:04.751] <TB1> INFO: PixTestTrim::trimTest() done
[23:18:04.751] <TB1> INFO: vtrim: 128 123 130 123 119 134 126 130 110 116 126 125 120 122 145 115
[23:18:04.751] <TB1> INFO: vthrcomp: 111 119 117 117 119 121 112 122 110 114 114 108 111 113 119 118
[23:18:04.751] <TB1> INFO: vcal mean: 35.06 35.03 35.26 35.02 35.01 35.29 35.26 34.97 35.08 35.08 35.15 34.90 35.02 35.05 35.20 34.93
[23:18:04.751] <TB1> INFO: vcal RMS: 1.06 1.14 1.48 1.03 1.09 1.31 1.35 1.01 1.05 1.53 1.19 1.04 1.04 1.10 1.28 1.11
[23:18:04.751] <TB1> INFO: bits mean: 8.89 9.48 9.90 9.22 9.59 9.49 9.12 9.33 8.20 9.44 9.18 8.72 8.85 9.26 9.79 9.04
[23:18:04.751] <TB1> INFO: bits RMS: 2.52 2.77 2.53 2.75 2.78 2.54 2.66 2.66 2.64 2.58 2.68 2.54 2.42 2.67 2.64 2.98
[23:18:04.759] <TB1> INFO: ----------------------------------------------------------------------
[23:18:04.759] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[23:18:04.759] <TB1> INFO: ----------------------------------------------------------------------
[23:18:04.762] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[23:18:04.774] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[23:18:04.774] <TB1> INFO: run 1 of 1
[23:18:05.084] <TB1> INFO: Expecting 4160000 events.
[23:18:38.793] <TB1> INFO: 760865 events read in total (33118ms).
[23:19:11.951] <TB1> INFO: 1516700 events read in total (66276ms).
[23:19:44.415] <TB1> INFO: 2266795 events read in total (98740ms).
[23:20:16.814] <TB1> INFO: 3013940 events read in total (131139ms).
[23:20:49.657] <TB1> INFO: 3760170 events read in total (163982ms).
[23:21:07.259] <TB1> INFO: 4160000 events read in total (181584ms).
[23:21:07.396] <TB1> INFO: Test took 182622ms.
[23:21:31.058] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 201 (-1/-1) hits flags = 528 (plus default)
[23:21:31.070] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[23:21:31.070] <TB1> INFO: run 1 of 1
[23:21:31.307] <TB1> INFO: Expecting 4201600 events.
[23:22:04.370] <TB1> INFO: 733495 events read in total (32471ms).
[23:22:36.630] <TB1> INFO: 1462890 events read in total (64731ms).
[23:23:08.469] <TB1> INFO: 2187530 events read in total (96570ms).
[23:23:40.520] <TB1> INFO: 2909035 events read in total (128621ms).
[23:24:12.420] <TB1> INFO: 3628930 events read in total (160521ms).
[23:24:38.160] <TB1> INFO: 4201600 events read in total (186261ms).
[23:24:38.239] <TB1> INFO: Test took 187169ms.
[23:25:04.360] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 208 (-1/-1) hits flags = 528 (plus default)
[23:25:04.373] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[23:25:04.373] <TB1> INFO: run 1 of 1
[23:25:04.635] <TB1> INFO: Expecting 4347200 events.
[23:25:37.674] <TB1> INFO: 725145 events read in total (32448ms).
[23:26:09.515] <TB1> INFO: 1446015 events read in total (64289ms).
[23:26:41.871] <TB1> INFO: 2163090 events read in total (96645ms).
[23:27:13.602] <TB1> INFO: 2876805 events read in total (128376ms).
[23:27:45.347] <TB1> INFO: 3589530 events read in total (160121ms).
[23:28:17.198] <TB1> INFO: 4304805 events read in total (191972ms).
[23:28:19.400] <TB1> INFO: 4347200 events read in total (194174ms).
[23:28:19.656] <TB1> INFO: Test took 195283ms.
[23:28:44.079] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 213 (-1/-1) hits flags = 528 (plus default)
[23:28:44.090] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[23:28:44.090] <TB1> INFO: run 1 of 1
[23:28:44.328] <TB1> INFO: Expecting 4451200 events.
[23:29:17.037] <TB1> INFO: 719580 events read in total (32118ms).
[23:29:48.775] <TB1> INFO: 1434505 events read in total (63856ms).
[23:30:20.549] <TB1> INFO: 2146745 events read in total (95630ms).
[23:30:52.454] <TB1> INFO: 2855480 events read in total (127535ms).
[23:31:24.291] <TB1> INFO: 3562705 events read in total (159372ms).
[23:31:56.010] <TB1> INFO: 4270590 events read in total (191091ms).
[23:32:04.128] <TB1> INFO: 4451200 events read in total (199209ms).
[23:32:04.236] <TB1> INFO: Test took 200146ms.
[23:32:28.672] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 222 (-1/-1) hits flags = 528 (plus default)
[23:32:28.685] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[23:32:28.685] <TB1> INFO: run 1 of 1
[23:32:28.922] <TB1> INFO: Expecting 4638400 events.
[23:33:01.186] <TB1> INFO: 709855 events read in total (31672ms).
[23:33:32.876] <TB1> INFO: 1415330 events read in total (63362ms).
[23:34:05.030] <TB1> INFO: 2118975 events read in total (95516ms).
[23:34:35.888] <TB1> INFO: 2818455 events read in total (126374ms).
[23:35:07.726] <TB1> INFO: 3516650 events read in total (158212ms).
[23:35:39.375] <TB1> INFO: 4214620 events read in total (189861ms).
[23:35:58.593] <TB1> INFO: 4638400 events read in total (209079ms).
[23:35:58.680] <TB1> INFO: Test took 209995ms.
[23:36:24.749] <TB1> INFO: PixTestTrim::trimBitTest() done
[23:36:24.750] <TB1> INFO: PixTestTrim::doTest() done, duration: 2584 seconds
[23:36:24.750] <TB1> INFO: Decoding statistics:
[23:36:24.750] <TB1> INFO: General information:
[23:36:24.750] <TB1> INFO: 16bit words read: 0
[23:36:24.750] <TB1> INFO: valid events total: 0
[23:36:24.750] <TB1> INFO: empty events: 0
[23:36:24.750] <TB1> INFO: valid events with pixels: 0
[23:36:24.750] <TB1> INFO: valid pixel hits: 0
[23:36:24.750] <TB1> INFO: Event errors: 0
[23:36:24.750] <TB1> INFO: start marker: 0
[23:36:24.750] <TB1> INFO: stop marker: 0
[23:36:24.750] <TB1> INFO: overflow: 0
[23:36:24.750] <TB1> INFO: invalid 5bit words: 0
[23:36:24.750] <TB1> INFO: invalid XOR eye diagram: 0
[23:36:24.750] <TB1> INFO: frame (failed synchr.): 0
[23:36:24.750] <TB1> INFO: idle data (no TBM trl): 0
[23:36:24.750] <TB1> INFO: no data (only TBM hdr): 0
[23:36:24.750] <TB1> INFO: TBM errors: 0
[23:36:24.750] <TB1> INFO: flawed TBM headers: 0
[23:36:24.750] <TB1> INFO: flawed TBM trailers: 0
[23:36:24.750] <TB1> INFO: event ID mismatches: 0
[23:36:24.750] <TB1> INFO: ROC errors: 0
[23:36:24.751] <TB1> INFO: missing ROC header(s): 0
[23:36:24.751] <TB1> INFO: misplaced readback start: 0
[23:36:24.751] <TB1> INFO: Pixel decoding errors: 0
[23:36:24.751] <TB1> INFO: pixel data incomplete: 0
[23:36:24.751] <TB1> INFO: pixel address: 0
[23:36:24.751] <TB1> INFO: pulse height fill bit: 0
[23:36:24.751] <TB1> INFO: buffer corruption: 0
[23:36:25.355] <TB1> INFO: ######################################################################
[23:36:25.355] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[23:36:25.355] <TB1> INFO: ######################################################################
[23:36:25.594] <TB1> INFO: Expecting 41600 events.
[23:36:29.120] <TB1> INFO: 41600 events read in total (2934ms).
[23:36:29.121] <TB1> INFO: Test took 3765ms.
[23:36:29.569] <TB1> INFO: Expecting 41600 events.
[23:36:33.091] <TB1> INFO: 41600 events read in total (2930ms).
[23:36:33.092] <TB1> INFO: Test took 3765ms.
[23:36:33.381] <TB1> INFO: Expecting 41600 events.
[23:36:36.998] <TB1> INFO: 41600 events read in total (3025ms).
[23:36:36.999] <TB1> INFO: Test took 3883ms.
[23:36:37.291] <TB1> INFO: Expecting 41600 events.
[23:36:40.936] <TB1> INFO: 41600 events read in total (3053ms).
[23:36:40.937] <TB1> INFO: Test took 3911ms.
[23:36:41.227] <TB1> INFO: Expecting 41600 events.
[23:36:44.793] <TB1> INFO: 41600 events read in total (2975ms).
[23:36:44.794] <TB1> INFO: Test took 3833ms.
[23:36:45.084] <TB1> INFO: Expecting 41600 events.
[23:36:48.601] <TB1> INFO: 41600 events read in total (2925ms).
[23:36:48.602] <TB1> INFO: Test took 3784ms.
[23:36:48.891] <TB1> INFO: Expecting 41600 events.
[23:36:52.517] <TB1> INFO: 41600 events read in total (3034ms).
[23:36:52.518] <TB1> INFO: Test took 3892ms.
[23:36:52.807] <TB1> INFO: Expecting 41600 events.
[23:36:56.343] <TB1> INFO: 41600 events read in total (2944ms).
[23:36:56.344] <TB1> INFO: Test took 3802ms.
[23:36:56.635] <TB1> INFO: Expecting 41600 events.
[23:37:00.165] <TB1> INFO: 41600 events read in total (2938ms).
[23:37:00.166] <TB1> INFO: Test took 3796ms.
[23:37:00.456] <TB1> INFO: Expecting 41600 events.
[23:37:04.080] <TB1> INFO: 41600 events read in total (3032ms).
[23:37:04.082] <TB1> INFO: Test took 3891ms.
[23:37:04.371] <TB1> INFO: Expecting 41600 events.
[23:37:08.031] <TB1> INFO: 41600 events read in total (3068ms).
[23:37:08.031] <TB1> INFO: Test took 3925ms.
[23:37:08.321] <TB1> INFO: Expecting 41600 events.
[23:37:11.850] <TB1> INFO: 41600 events read in total (2937ms).
[23:37:11.850] <TB1> INFO: Test took 3795ms.
[23:37:12.139] <TB1> INFO: Expecting 41600 events.
[23:37:15.754] <TB1> INFO: 41600 events read in total (3023ms).
[23:37:15.755] <TB1> INFO: Test took 3880ms.
[23:37:16.044] <TB1> INFO: Expecting 41600 events.
[23:37:19.723] <TB1> INFO: 41600 events read in total (3087ms).
[23:37:19.724] <TB1> INFO: Test took 3945ms.
[23:37:20.016] <TB1> INFO: Expecting 41600 events.
[23:37:23.571] <TB1> INFO: 41600 events read in total (2963ms).
[23:37:23.572] <TB1> INFO: Test took 3821ms.
[23:37:23.861] <TB1> INFO: Expecting 41600 events.
[23:37:27.401] <TB1> INFO: 41600 events read in total (2949ms).
[23:37:27.402] <TB1> INFO: Test took 3806ms.
[23:37:27.691] <TB1> INFO: Expecting 41600 events.
[23:37:31.249] <TB1> INFO: 41600 events read in total (2967ms).
[23:37:31.249] <TB1> INFO: Test took 3823ms.
[23:37:31.546] <TB1> INFO: Expecting 41600 events.
[23:37:35.130] <TB1> INFO: 41600 events read in total (2992ms).
[23:37:35.131] <TB1> INFO: Test took 3857ms.
[23:37:35.420] <TB1> INFO: Expecting 41600 events.
[23:37:39.075] <TB1> INFO: 41600 events read in total (3063ms).
[23:37:39.075] <TB1> INFO: Test took 3920ms.
[23:37:39.367] <TB1> INFO: Expecting 41600 events.
[23:37:42.988] <TB1> INFO: 41600 events read in total (3029ms).
[23:37:42.989] <TB1> INFO: Test took 3889ms.
[23:37:43.297] <TB1> INFO: Expecting 41600 events.
[23:37:46.840] <TB1> INFO: 41600 events read in total (2952ms).
[23:37:46.841] <TB1> INFO: Test took 3828ms.
[23:37:47.132] <TB1> INFO: Expecting 41600 events.
[23:37:50.701] <TB1> INFO: 41600 events read in total (2977ms).
[23:37:50.701] <TB1> INFO: Test took 3833ms.
[23:37:50.993] <TB1> INFO: Expecting 41600 events.
[23:37:54.661] <TB1> INFO: 41600 events read in total (3077ms).
[23:37:54.662] <TB1> INFO: Test took 3935ms.
[23:37:54.952] <TB1> INFO: Expecting 41600 events.
[23:37:58.605] <TB1> INFO: 41600 events read in total (3061ms).
[23:37:58.606] <TB1> INFO: Test took 3919ms.
[23:37:58.898] <TB1> INFO: Expecting 41600 events.
[23:38:02.540] <TB1> INFO: 41600 events read in total (3050ms).
[23:38:02.541] <TB1> INFO: Test took 3908ms.
[23:38:02.847] <TB1> INFO: Expecting 41600 events.
[23:38:06.450] <TB1> INFO: 41600 events read in total (3011ms).
[23:38:06.451] <TB1> INFO: Test took 3884ms.
[23:38:06.740] <TB1> INFO: Expecting 41600 events.
[23:38:10.259] <TB1> INFO: 41600 events read in total (2927ms).
[23:38:10.260] <TB1> INFO: Test took 3785ms.
[23:38:10.553] <TB1> INFO: Expecting 41600 events.
[23:38:14.123] <TB1> INFO: 41600 events read in total (2979ms).
[23:38:14.124] <TB1> INFO: Test took 3837ms.
[23:38:14.415] <TB1> INFO: Expecting 41600 events.
[23:38:17.958] <TB1> INFO: 41600 events read in total (2951ms).
[23:38:17.959] <TB1> INFO: Test took 3809ms.
[23:38:18.249] <TB1> INFO: Expecting 2560 events.
[23:38:19.136] <TB1> INFO: 2560 events read in total (295ms).
[23:38:19.136] <TB1> INFO: Test took 1164ms.
[23:38:19.445] <TB1> INFO: Expecting 2560 events.
[23:38:20.337] <TB1> INFO: 2560 events read in total (300ms).
[23:38:20.337] <TB1> INFO: Test took 1201ms.
[23:38:20.645] <TB1> INFO: Expecting 2560 events.
[23:38:21.537] <TB1> INFO: 2560 events read in total (300ms).
[23:38:21.537] <TB1> INFO: Test took 1199ms.
[23:38:21.845] <TB1> INFO: Expecting 2560 events.
[23:38:22.738] <TB1> INFO: 2560 events read in total (301ms).
[23:38:22.738] <TB1> INFO: Test took 1200ms.
[23:38:23.044] <TB1> INFO: Expecting 2560 events.
[23:38:23.925] <TB1> INFO: 2560 events read in total (289ms).
[23:38:23.926] <TB1> INFO: Test took 1187ms.
[23:38:24.232] <TB1> INFO: Expecting 2560 events.
[23:38:25.113] <TB1> INFO: 2560 events read in total (289ms).
[23:38:25.113] <TB1> INFO: Test took 1187ms.
[23:38:25.421] <TB1> INFO: Expecting 2560 events.
[23:38:26.307] <TB1> INFO: 2560 events read in total (294ms).
[23:38:26.307] <TB1> INFO: Test took 1193ms.
[23:38:26.614] <TB1> INFO: Expecting 2560 events.
[23:38:27.497] <TB1> INFO: 2560 events read in total (291ms).
[23:38:27.497] <TB1> INFO: Test took 1190ms.
[23:38:27.805] <TB1> INFO: Expecting 2560 events.
[23:38:28.694] <TB1> INFO: 2560 events read in total (297ms).
[23:38:28.695] <TB1> INFO: Test took 1198ms.
[23:38:28.003] <TB1> INFO: Expecting 2560 events.
[23:38:29.893] <TB1> INFO: 2560 events read in total (298ms).
[23:38:29.893] <TB1> INFO: Test took 1198ms.
[23:38:30.200] <TB1> INFO: Expecting 2560 events.
[23:38:31.084] <TB1> INFO: 2560 events read in total (292ms).
[23:38:31.084] <TB1> INFO: Test took 1191ms.
[23:38:31.391] <TB1> INFO: Expecting 2560 events.
[23:38:32.274] <TB1> INFO: 2560 events read in total (291ms).
[23:38:32.274] <TB1> INFO: Test took 1189ms.
[23:38:32.583] <TB1> INFO: Expecting 2560 events.
[23:38:33.473] <TB1> INFO: 2560 events read in total (299ms).
[23:38:33.474] <TB1> INFO: Test took 1199ms.
[23:38:33.782] <TB1> INFO: Expecting 2560 events.
[23:38:34.671] <TB1> INFO: 2560 events read in total (297ms).
[23:38:34.671] <TB1> INFO: Test took 1197ms.
[23:38:34.979] <TB1> INFO: Expecting 2560 events.
[23:38:35.867] <TB1> INFO: 2560 events read in total (296ms).
[23:38:35.867] <TB1> INFO: Test took 1195ms.
[23:38:36.175] <TB1> INFO: Expecting 2560 events.
[23:38:37.066] <TB1> INFO: 2560 events read in total (299ms).
[23:38:37.066] <TB1> INFO: Test took 1198ms.
[23:38:37.071] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:38:37.375] <TB1> INFO: Expecting 655360 events.
[23:38:52.200] <TB1> INFO: 655360 events read in total (14233ms).
[23:38:52.213] <TB1> INFO: Expecting 655360 events.
[23:39:06.739] <TB1> INFO: 655360 events read in total (14123ms).
[23:39:06.755] <TB1> INFO: Expecting 655360 events.
[23:39:21.336] <TB1> INFO: 655360 events read in total (14178ms).
[23:39:21.357] <TB1> INFO: Expecting 655360 events.
[23:39:35.879] <TB1> INFO: 655360 events read in total (14119ms).
[23:39:35.904] <TB1> INFO: Expecting 655360 events.
[23:39:50.515] <TB1> INFO: 655360 events read in total (14208ms).
[23:39:50.544] <TB1> INFO: Expecting 655360 events.
[23:40:05.067] <TB1> INFO: 655360 events read in total (14120ms).
[23:40:05.114] <TB1> INFO: Expecting 655360 events.
[23:40:19.543] <TB1> INFO: 655360 events read in total (14026ms).
[23:40:19.583] <TB1> INFO: Expecting 655360 events.
[23:40:34.148] <TB1> INFO: 655360 events read in total (14162ms).
[23:40:34.220] <TB1> INFO: Expecting 655360 events.
[23:40:48.756] <TB1> INFO: 655360 events read in total (14132ms).
[23:40:48.820] <TB1> INFO: Expecting 655360 events.
[23:41:03.299] <TB1> INFO: 655360 events read in total (14076ms).
[23:41:03.440] <TB1> INFO: Expecting 655360 events.
[23:41:18.007] <TB1> INFO: 655360 events read in total (14163ms).
[23:41:18.076] <TB1> INFO: Expecting 655360 events.
[23:41:32.852] <TB1> INFO: 655360 events read in total (14372ms).
[23:41:32.943] <TB1> INFO: Expecting 655360 events.
[23:41:47.511] <TB1> INFO: 655360 events read in total (14165ms).
[23:41:47.646] <TB1> INFO: Expecting 655360 events.
[23:42:02.371] <TB1> INFO: 655360 events read in total (14322ms).
[23:42:02.458] <TB1> INFO: Expecting 655360 events.
[23:42:17.127] <TB1> INFO: 655360 events read in total (14266ms).
[23:42:17.221] <TB1> INFO: Expecting 655360 events.
[23:42:31.804] <TB1> INFO: 655360 events read in total (14180ms).
[23:42:31.951] <TB1> INFO: Test took 234880ms.
[23:42:32.068] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:42:32.321] <TB1> INFO: Expecting 655360 events.
[23:42:47.054] <TB1> INFO: 655360 events read in total (14141ms).
[23:42:47.066] <TB1> INFO: Expecting 655360 events.
[23:43:01.512] <TB1> INFO: 655360 events read in total (14043ms).
[23:43:01.529] <TB1> INFO: Expecting 655360 events.
[23:43:16.051] <TB1> INFO: 655360 events read in total (14119ms).
[23:43:16.071] <TB1> INFO: Expecting 655360 events.
[23:43:30.670] <TB1> INFO: 655360 events read in total (14196ms).
[23:43:30.702] <TB1> INFO: Expecting 655360 events.
[23:43:45.215] <TB1> INFO: 655360 events read in total (14110ms).
[23:43:45.244] <TB1> INFO: Expecting 655360 events.
[23:43:59.741] <TB1> INFO: 655360 events read in total (14094ms).
[23:43:59.788] <TB1> INFO: Expecting 655360 events.
[23:44:14.569] <TB1> INFO: 655360 events read in total (14378ms).
[23:44:14.606] <TB1> INFO: Expecting 655360 events.
[23:44:29.349] <TB1> INFO: 655360 events read in total (14340ms).
[23:44:29.423] <TB1> INFO: Expecting 655360 events.
[23:44:43.983] <TB1> INFO: 655360 events read in total (14157ms).
[23:44:44.033] <TB1> INFO: Expecting 655360 events.
[23:44:58.781] <TB1> INFO: 655360 events read in total (14345ms).
[23:44:58.868] <TB1> INFO: Expecting 655360 events.
[23:45:13.808] <TB1> INFO: 655360 events read in total (14536ms).
[23:45:13.944] <TB1> INFO: Expecting 655360 events.
[23:45:28.848] <TB1> INFO: 655360 events read in total (14501ms).
[23:45:29.018] <TB1> INFO: Expecting 655360 events.
[23:45:43.909] <TB1> INFO: 655360 events read in total (14488ms).
[23:45:43.990] <TB1> INFO: Expecting 655360 events.
[23:45:59.087] <TB1> INFO: 655360 events read in total (14694ms).
[23:45:59.170] <TB1> INFO: Expecting 655360 events.
[23:46:13.968] <TB1> INFO: 655360 events read in total (14395ms).
[23:46:14.146] <TB1> INFO: Expecting 655360 events.
[23:46:28.955] <TB1> INFO: 655360 events read in total (14406ms).
[23:46:29.113] <TB1> INFO: Test took 237045ms.
[23:46:29.320] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.325] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.331] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[23:46:29.336] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[23:46:29.342] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.348] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.353] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.359] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.365] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.370] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.376] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[23:46:29.382] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[23:46:29.387] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[23:46:29.393] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[23:46:29.399] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[23:46:29.404] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[23:46:29.410] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[23:46:29.416] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.421] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.427] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.433] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[23:46:29.438] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[23:46:29.444] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[23:46:29.450] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[23:46:29.455] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[23:46:29.461] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[23:46:29.466] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[23:46:29.472] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.477] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.483] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.488] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.494] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[23:46:29.500] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[23:46:29.505] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[23:46:29.511] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[23:46:29.518] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[23:46:29.556] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C0.dat
[23:46:29.557] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C1.dat
[23:46:29.557] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C2.dat
[23:46:29.557] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C3.dat
[23:46:29.557] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C4.dat
[23:46:29.557] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C5.dat
[23:46:29.557] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C6.dat
[23:46:29.558] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C7.dat
[23:46:29.558] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C8.dat
[23:46:29.558] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C9.dat
[23:46:29.558] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C10.dat
[23:46:29.558] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C11.dat
[23:46:29.559] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C12.dat
[23:46:29.559] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C13.dat
[23:46:29.559] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C14.dat
[23:46:29.559] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//dacParameters35_C15.dat
[23:46:29.803] <TB1> INFO: Expecting 41600 events.
[23:46:32.996] <TB1> INFO: 41600 events read in total (2601ms).
[23:46:32.997] <TB1> INFO: Test took 3433ms.
[23:46:33.454] <TB1> INFO: Expecting 41600 events.
[23:46:36.514] <TB1> INFO: 41600 events read in total (2468ms).
[23:46:36.515] <TB1> INFO: Test took 3303ms.
[23:46:36.961] <TB1> INFO: Expecting 41600 events.
[23:46:40.068] <TB1> INFO: 41600 events read in total (2515ms).
[23:46:40.069] <TB1> INFO: Test took 3344ms.
[23:46:40.286] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:40.375] <TB1> INFO: Expecting 2560 events.
[23:46:41.261] <TB1> INFO: 2560 events read in total (295ms).
[23:46:41.261] <TB1> INFO: Test took 975ms.
[23:46:41.264] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:41.570] <TB1> INFO: Expecting 2560 events.
[23:46:42.455] <TB1> INFO: 2560 events read in total (294ms).
[23:46:42.456] <TB1> INFO: Test took 1192ms.
[23:46:42.458] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:42.764] <TB1> INFO: Expecting 2560 events.
[23:46:43.651] <TB1> INFO: 2560 events read in total (295ms).
[23:46:43.651] <TB1> INFO: Test took 1193ms.
[23:46:43.654] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:43.959] <TB1> INFO: Expecting 2560 events.
[23:46:44.844] <TB1> INFO: 2560 events read in total (293ms).
[23:46:44.844] <TB1> INFO: Test took 1190ms.
[23:46:44.847] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:45.153] <TB1> INFO: Expecting 2560 events.
[23:46:46.036] <TB1> INFO: 2560 events read in total (292ms).
[23:46:46.036] <TB1> INFO: Test took 1189ms.
[23:46:46.039] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:46.345] <TB1> INFO: Expecting 2560 events.
[23:46:47.227] <TB1> INFO: 2560 events read in total (291ms).
[23:46:47.228] <TB1> INFO: Test took 1189ms.
[23:46:47.229] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:47.536] <TB1> INFO: Expecting 2560 events.
[23:46:48.420] <TB1> INFO: 2560 events read in total (292ms).
[23:46:48.420] <TB1> INFO: Test took 1191ms.
[23:46:48.424] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:48.729] <TB1> INFO: Expecting 2560 events.
[23:46:49.612] <TB1> INFO: 2560 events read in total (292ms).
[23:46:49.612] <TB1> INFO: Test took 1188ms.
[23:46:49.614] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:49.920] <TB1> INFO: Expecting 2560 events.
[23:46:50.799] <TB1> INFO: 2560 events read in total (287ms).
[23:46:50.800] <TB1> INFO: Test took 1186ms.
[23:46:50.803] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:51.108] <TB1> INFO: Expecting 2560 events.
[23:46:51.990] <TB1> INFO: 2560 events read in total (290ms).
[23:46:51.990] <TB1> INFO: Test took 1188ms.
[23:46:51.992] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:52.298] <TB1> INFO: Expecting 2560 events.
[23:46:53.180] <TB1> INFO: 2560 events read in total (290ms).
[23:46:53.180] <TB1> INFO: Test took 1188ms.
[23:46:53.183] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:53.488] <TB1> INFO: Expecting 2560 events.
[23:46:54.371] <TB1> INFO: 2560 events read in total (291ms).
[23:46:54.371] <TB1> INFO: Test took 1188ms.
[23:46:54.375] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:54.680] <TB1> INFO: Expecting 2560 events.
[23:46:55.563] <TB1> INFO: 2560 events read in total (292ms).
[23:46:55.563] <TB1> INFO: Test took 1188ms.
[23:46:55.568] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:55.871] <TB1> INFO: Expecting 2560 events.
[23:46:56.756] <TB1> INFO: 2560 events read in total (293ms).
[23:46:56.757] <TB1> INFO: Test took 1189ms.
[23:46:56.759] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:57.065] <TB1> INFO: Expecting 2560 events.
[23:46:57.945] <TB1> INFO: 2560 events read in total (289ms).
[23:46:57.945] <TB1> INFO: Test took 1186ms.
[23:46:57.948] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:58.253] <TB1> INFO: Expecting 2560 events.
[23:46:59.134] <TB1> INFO: 2560 events read in total (289ms).
[23:46:59.135] <TB1> INFO: Test took 1187ms.
[23:46:59.139] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:46:59.443] <TB1> INFO: Expecting 2560 events.
[23:47:00.322] <TB1> INFO: 2560 events read in total (288ms).
[23:47:00.323] <TB1> INFO: Test took 1184ms.
[23:47:00.326] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:00.631] <TB1> INFO: Expecting 2560 events.
[23:47:01.513] <TB1> INFO: 2560 events read in total (291ms).
[23:47:01.513] <TB1> INFO: Test took 1187ms.
[23:47:01.517] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:01.821] <TB1> INFO: Expecting 2560 events.
[23:47:02.703] <TB1> INFO: 2560 events read in total (290ms).
[23:47:02.703] <TB1> INFO: Test took 1186ms.
[23:47:02.706] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:03.012] <TB1> INFO: Expecting 2560 events.
[23:47:03.895] <TB1> INFO: 2560 events read in total (292ms).
[23:47:03.895] <TB1> INFO: Test took 1189ms.
[23:47:03.898] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:04.204] <TB1> INFO: Expecting 2560 events.
[23:47:05.087] <TB1> INFO: 2560 events read in total (292ms).
[23:47:05.087] <TB1> INFO: Test took 1189ms.
[23:47:05.090] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:05.395] <TB1> INFO: Expecting 2560 events.
[23:47:06.278] <TB1> INFO: 2560 events read in total (291ms).
[23:47:06.278] <TB1> INFO: Test took 1189ms.
[23:47:06.282] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:06.587] <TB1> INFO: Expecting 2560 events.
[23:47:07.466] <TB1> INFO: 2560 events read in total (288ms).
[23:47:07.467] <TB1> INFO: Test took 1185ms.
[23:47:07.471] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:07.775] <TB1> INFO: Expecting 2560 events.
[23:47:08.656] <TB1> INFO: 2560 events read in total (289ms).
[23:47:08.656] <TB1> INFO: Test took 1185ms.
[23:47:08.660] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:08.965] <TB1> INFO: Expecting 2560 events.
[23:47:09.857] <TB1> INFO: 2560 events read in total (296ms).
[23:47:09.857] <TB1> INFO: Test took 1197ms.
[23:47:09.860] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:10.166] <TB1> INFO: Expecting 2560 events.
[23:47:11.050] <TB1> INFO: 2560 events read in total (293ms).
[23:47:11.050] <TB1> INFO: Test took 1190ms.
[23:47:11.053] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:11.358] <TB1> INFO: Expecting 2560 events.
[23:47:12.243] <TB1> INFO: 2560 events read in total (293ms).
[23:47:12.243] <TB1> INFO: Test took 1190ms.
[23:47:12.246] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:12.551] <TB1> INFO: Expecting 2560 events.
[23:47:13.439] <TB1> INFO: 2560 events read in total (296ms).
[23:47:13.439] <TB1> INFO: Test took 1193ms.
[23:47:13.443] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:13.747] <TB1> INFO: Expecting 2560 events.
[23:47:14.632] <TB1> INFO: 2560 events read in total (293ms).
[23:47:14.632] <TB1> INFO: Test took 1189ms.
[23:47:14.635] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:14.940] <TB1> INFO: Expecting 2560 events.
[23:47:15.825] <TB1> INFO: 2560 events read in total (293ms).
[23:47:15.825] <TB1> INFO: Test took 1190ms.
[23:47:15.828] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:16.134] <TB1> INFO: Expecting 2560 events.
[23:47:17.018] <TB1> INFO: 2560 events read in total (293ms).
[23:47:17.018] <TB1> INFO: Test took 1190ms.
[23:47:17.020] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[23:47:17.326] <TB1> INFO: Expecting 2560 events.
[23:47:18.211] <TB1> INFO: 2560 events read in total (293ms).
[23:47:18.212] <TB1> INFO: Test took 1192ms.
[23:47:18.674] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 653 seconds
[23:47:18.674] <TB1> INFO: PH scale (per ROC): 37 35 48 32 43 36 36 30 40 36 33 34 51 36 38 36
[23:47:18.674] <TB1> INFO: PH offset (per ROC): 110 101 125 85 110 109 97 93 105 104 99 108 123 102 101 91
[23:47:18.683] <TB1> INFO: Decoding statistics:
[23:47:18.683] <TB1> INFO: General information:
[23:47:18.683] <TB1> INFO: 16bit words read: 127894
[23:47:18.683] <TB1> INFO: valid events total: 20480
[23:47:18.683] <TB1> INFO: empty events: 17973
[23:47:18.683] <TB1> INFO: valid events with pixels: 2507
[23:47:18.683] <TB1> INFO: valid pixel hits: 2507
[23:47:18.683] <TB1> INFO: Event errors: 0
[23:47:18.683] <TB1> INFO: start marker: 0
[23:47:18.683] <TB1> INFO: stop marker: 0
[23:47:18.683] <TB1> INFO: overflow: 0
[23:47:18.683] <TB1> INFO: invalid 5bit words: 0
[23:47:18.683] <TB1> INFO: invalid XOR eye diagram: 0
[23:47:18.683] <TB1> INFO: frame (failed synchr.): 0
[23:47:18.683] <TB1> INFO: idle data (no TBM trl): 0
[23:47:18.683] <TB1> INFO: no data (only TBM hdr): 0
[23:47:18.683] <TB1> INFO: TBM errors: 0
[23:47:18.683] <TB1> INFO: flawed TBM headers: 0
[23:47:18.683] <TB1> INFO: flawed TBM trailers: 0
[23:47:18.683] <TB1> INFO: event ID mismatches: 0
[23:47:18.683] <TB1> INFO: ROC errors: 0
[23:47:18.683] <TB1> INFO: missing ROC header(s): 0
[23:47:18.683] <TB1> INFO: misplaced readback start: 0
[23:47:18.683] <TB1> INFO: Pixel decoding errors: 0
[23:47:18.683] <TB1> INFO: pixel data incomplete: 0
[23:47:18.683] <TB1> INFO: pixel address: 0
[23:47:18.683] <TB1> INFO: pulse height fill bit: 0
[23:47:18.683] <TB1> INFO: buffer corruption: 0
[23:47:18.847] <TB1> INFO: ######################################################################
[23:47:18.847] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[23:47:18.847] <TB1> INFO: ######################################################################
[23:47:18.861] <TB1> INFO: scanning low vcal = 10
[23:47:19.097] <TB1> INFO: Expecting 41600 events.
[23:47:22.695] <TB1> INFO: 41600 events read in total (3006ms).
[23:47:22.695] <TB1> INFO: Test took 3833ms.
[23:47:22.697] <TB1> INFO: scanning low vcal = 20
[23:47:22.995] <TB1> INFO: Expecting 41600 events.
[23:47:26.562] <TB1> INFO: 41600 events read in total (2976ms).
[23:47:26.563] <TB1> INFO: Test took 3866ms.
[23:47:26.565] <TB1> INFO: scanning low vcal = 30
[23:47:26.863] <TB1> INFO: Expecting 41600 events.
[23:47:30.549] <TB1> INFO: 41600 events read in total (3095ms).
[23:47:30.550] <TB1> INFO: Test took 3984ms.
[23:47:30.553] <TB1> INFO: scanning low vcal = 40
[23:47:30.868] <TB1> INFO: Expecting 41600 events.
[23:47:34.852] <TB1> INFO: 41600 events read in total (3392ms).
[23:47:34.854] <TB1> INFO: Test took 4301ms.
[23:47:34.858] <TB1> INFO: scanning low vcal = 50
[23:47:35.177] <TB1> INFO: Expecting 41600 events.
[23:47:39.298] <TB1> INFO: 41600 events read in total (3529ms).
[23:47:39.299] <TB1> INFO: Test took 4441ms.
[23:47:39.302] <TB1> INFO: scanning low vcal = 60
[23:47:39.622] <TB1> INFO: Expecting 41600 events.
[23:47:43.595] <TB1> INFO: 41600 events read in total (3381ms).
[23:47:43.596] <TB1> INFO: Test took 4294ms.
[23:47:43.599] <TB1> INFO: scanning low vcal = 70
[23:47:43.917] <TB1> INFO: Expecting 41600 events.
[23:47:47.915] <TB1> INFO: 41600 events read in total (3406ms).
[23:47:47.916] <TB1> INFO: Test took 4317ms.
[23:47:47.919] <TB1> INFO: scanning low vcal = 80
[23:47:48.195] <TB1> INFO: Expecting 41600 events.
[23:47:52.192] <TB1> INFO: 41600 events read in total (3405ms).
[23:47:52.193] <TB1> INFO: Test took 4274ms.
[23:47:52.196] <TB1> INFO: scanning low vcal = 90
[23:47:52.473] <TB1> INFO: Expecting 41600 events.
[23:47:56.469] <TB1> INFO: 41600 events read in total (3404ms).
[23:47:56.470] <TB1> INFO: Test took 4274ms.
[23:47:56.474] <TB1> INFO: scanning low vcal = 100
[23:47:56.792] <TB1> INFO: Expecting 41600 events.
[23:48:00.787] <TB1> INFO: 41600 events read in total (3403ms).
[23:48:00.788] <TB1> INFO: Test took 4313ms.
[23:48:00.791] <TB1> INFO: scanning low vcal = 110
[23:48:01.067] <TB1> INFO: Expecting 41600 events.
[23:48:05.030] <TB1> INFO: 41600 events read in total (3371ms).
[23:48:05.031] <TB1> INFO: Test took 4240ms.
[23:48:05.034] <TB1> INFO: scanning low vcal = 120
[23:48:05.311] <TB1> INFO: Expecting 41600 events.
[23:48:09.272] <TB1> INFO: 41600 events read in total (3369ms).
[23:48:09.273] <TB1> INFO: Test took 4239ms.
[23:48:09.276] <TB1> INFO: scanning low vcal = 130
[23:48:09.553] <TB1> INFO: Expecting 41600 events.
[23:48:13.515] <TB1> INFO: 41600 events read in total (3370ms).
[23:48:13.516] <TB1> INFO: Test took 4240ms.
[23:48:13.519] <TB1> INFO: scanning low vcal = 140
[23:48:13.796] <TB1> INFO: Expecting 41600 events.
[23:48:17.760] <TB1> INFO: 41600 events read in total (3372ms).
[23:48:17.761] <TB1> INFO: Test took 4242ms.
[23:48:17.764] <TB1> INFO: scanning low vcal = 150
[23:48:18.041] <TB1> INFO: Expecting 41600 events.
[23:48:21.003] <TB1> INFO: 41600 events read in total (3370ms).
[23:48:21.004] <TB1> INFO: Test took 4240ms.
[23:48:22.007] <TB1> INFO: scanning low vcal = 160
[23:48:22.284] <TB1> INFO: Expecting 41600 events.
[23:48:26.244] <TB1> INFO: 41600 events read in total (3368ms).
[23:48:26.245] <TB1> INFO: Test took 4238ms.
[23:48:26.248] <TB1> INFO: scanning low vcal = 170
[23:48:26.525] <TB1> INFO: Expecting 41600 events.
[23:48:30.486] <TB1> INFO: 41600 events read in total (3369ms).
[23:48:30.487] <TB1> INFO: Test took 4239ms.
[23:48:30.492] <TB1> INFO: scanning low vcal = 180
[23:48:30.767] <TB1> INFO: Expecting 41600 events.
[23:48:34.737] <TB1> INFO: 41600 events read in total (3378ms).
[23:48:34.737] <TB1> INFO: Test took 4244ms.
[23:48:34.740] <TB1> INFO: scanning low vcal = 190
[23:48:35.017] <TB1> INFO: Expecting 41600 events.
[23:48:38.990] <TB1> INFO: 41600 events read in total (3381ms).
[23:48:38.990] <TB1> INFO: Test took 4249ms.
[23:48:38.993] <TB1> INFO: scanning low vcal = 200
[23:48:39.270] <TB1> INFO: Expecting 41600 events.
[23:48:43.245] <TB1> INFO: 41600 events read in total (3383ms).
[23:48:43.245] <TB1> INFO: Test took 4253ms.
[23:48:43.249] <TB1> INFO: scanning low vcal = 210
[23:48:43.526] <TB1> INFO: Expecting 41600 events.
[23:48:47.488] <TB1> INFO: 41600 events read in total (3370ms).
[23:48:47.489] <TB1> INFO: Test took 4240ms.
[23:48:47.492] <TB1> INFO: scanning low vcal = 220
[23:48:47.769] <TB1> INFO: Expecting 41600 events.
[23:48:51.730] <TB1> INFO: 41600 events read in total (3369ms).
[23:48:51.731] <TB1> INFO: Test took 4239ms.
[23:48:51.734] <TB1> INFO: scanning low vcal = 230
[23:48:52.011] <TB1> INFO: Expecting 41600 events.
[23:48:55.972] <TB1> INFO: 41600 events read in total (3369ms).
[23:48:55.973] <TB1> INFO: Test took 4239ms.
[23:48:55.976] <TB1> INFO: scanning low vcal = 240
[23:48:56.253] <TB1> INFO: Expecting 41600 events.
[23:49:00.214] <TB1> INFO: 41600 events read in total (3369ms).
[23:49:00.215] <TB1> INFO: Test took 4239ms.
[23:49:00.218] <TB1> INFO: scanning low vcal = 250
[23:49:00.495] <TB1> INFO: Expecting 41600 events.
[23:49:04.496] <TB1> INFO: 41600 events read in total (3409ms).
[23:49:04.497] <TB1> INFO: Test took 4279ms.
[23:49:04.501] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[23:49:04.777] <TB1> INFO: Expecting 41600 events.
[23:49:08.757] <TB1> INFO: 41600 events read in total (3388ms).
[23:49:08.758] <TB1> INFO: Test took 4257ms.
[23:49:08.761] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[23:49:09.038] <TB1> INFO: Expecting 41600 events.
[23:49:13.070] <TB1> INFO: 41600 events read in total (3440ms).
[23:49:13.071] <TB1> INFO: Test took 4310ms.
[23:49:13.074] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[23:49:13.351] <TB1> INFO: Expecting 41600 events.
[23:49:17.313] <TB1> INFO: 41600 events read in total (3371ms).
[23:49:17.313] <TB1> INFO: Test took 4239ms.
[23:49:17.317] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[23:49:17.594] <TB1> INFO: Expecting 41600 events.
[23:49:21.560] <TB1> INFO: 41600 events read in total (3374ms).
[23:49:21.561] <TB1> INFO: Test took 4244ms.
[23:49:21.564] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[23:49:21.841] <TB1> INFO: Expecting 41600 events.
[23:49:25.796] <TB1> INFO: 41600 events read in total (3363ms).
[23:49:25.797] <TB1> INFO: Test took 4232ms.
[23:49:26.170] <TB1> INFO: PixTestGainPedestal::measure() done
[23:49:58.440] <TB1> INFO: PixTestGainPedestal::fit() done
[23:49:58.440] <TB1> INFO: non-linearity mean: 0.944 0.940 0.980 1.001 0.950 0.945 0.954 0.915 0.940 0.932 0.949 0.939 0.983 0.955 0.936 1.000
[23:49:58.440] <TB1> INFO: non-linearity RMS: 0.059 0.113 0.004 0.167 0.058 0.051 0.160 0.150 0.073 0.103 0.130 0.160 0.004 0.158 0.086 0.157
[23:49:58.440] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C0.dat
[23:49:58.454] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C1.dat
[23:49:58.467] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C2.dat
[23:49:58.481] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C3.dat
[23:49:58.494] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C4.dat
[23:49:58.508] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C5.dat
[23:49:58.521] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C6.dat
[23:49:58.535] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C7.dat
[23:49:58.548] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C8.dat
[23:49:58.561] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C9.dat
[23:49:58.574] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C10.dat
[23:49:58.587] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C11.dat
[23:49:58.601] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C12.dat
[23:49:58.615] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C13.dat
[23:49:58.628] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C14.dat
[23:49:58.641] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1025_FullQualification_2016-10-19_19h52m_1476899523//003_Fulltest_p17//phCalibrationFitErr35_C15.dat
[23:49:58.654] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 159 seconds
[23:49:58.654] <TB1> INFO: Decoding statistics:
[23:49:58.654] <TB1> INFO: General information:
[23:49:58.654] <TB1> INFO: 16bit words read: 3317812
[23:49:58.654] <TB1> INFO: valid events total: 332800
[23:49:58.654] <TB1> INFO: empty events: 21
[23:49:58.654] <TB1> INFO: valid events with pixels: 332779
[23:49:58.655] <TB1> INFO: valid pixel hits: 660506
[23:49:58.655] <TB1> INFO: Event errors: 0
[23:49:58.655] <TB1> INFO: start marker: 0
[23:49:58.655] <TB1> INFO: stop marker: 0
[23:49:58.655] <TB1> INFO: overflow: 0
[23:49:58.655] <TB1> INFO: invalid 5bit words: 0
[23:49:58.655] <TB1> INFO: invalid XOR eye diagram: 0
[23:49:58.655] <TB1> INFO: frame (failed synchr.): 0
[23:49:58.655] <TB1> INFO: idle data (no TBM trl): 0
[23:49:58.655] <TB1> INFO: no data (only TBM hdr): 0
[23:49:58.655] <TB1> INFO: TBM errors: 0
[23:49:58.655] <TB1> INFO: flawed TBM headers: 0
[23:49:58.655] <TB1> INFO: flawed TBM trailers: 0
[23:49:58.655] <TB1> INFO: event ID mismatches: 0
[23:49:58.655] <TB1> INFO: ROC errors: 0
[23:49:58.655] <TB1> INFO: missing ROC header(s): 0
[23:49:58.655] <TB1> INFO: misplaced readback start: 0
[23:49:58.655] <TB1> INFO: Pixel decoding errors: 0
[23:49:58.655] <TB1> INFO: pixel data incomplete: 0
[23:49:58.655] <TB1> INFO: pixel address: 0
[23:49:58.655] <TB1> INFO: pulse height fill bit: 0
[23:49:58.655] <TB1> INFO: buffer corruption: 0
[23:49:58.671] <TB1> INFO: Decoding statistics:
[23:49:58.671] <TB1> INFO: General information:
[23:49:58.671] <TB1> INFO: 16bit words read: 3447242
[23:49:58.671] <TB1> INFO: valid events total: 353536
[23:49:58.672] <TB1> INFO: empty events: 18250
[23:49:58.672] <TB1> INFO: valid events with pixels: 335286
[23:49:58.672] <TB1> INFO: valid pixel hits: 663013
[23:49:58.672] <TB1> INFO: Event errors: 0
[23:49:58.672] <TB1> INFO: start marker: 0
[23:49:58.672] <TB1> INFO: stop marker: 0
[23:49:58.672] <TB1> INFO: overflow: 0
[23:49:58.672] <TB1> INFO: invalid 5bit words: 0
[23:49:58.672] <TB1> INFO: invalid XOR eye diagram: 0
[23:49:58.672] <TB1> INFO: frame (failed synchr.): 0
[23:49:58.672] <TB1> INFO: idle data (no TBM trl): 0
[23:49:58.672] <TB1> INFO: no data (only TBM hdr): 0
[23:49:58.672] <TB1> INFO: TBM errors: 0
[23:49:58.672] <TB1> INFO: flawed TBM headers: 0
[23:49:58.672] <TB1> INFO: flawed TBM trailers: 0
[23:49:58.672] <TB1> INFO: event ID mismatches: 0
[23:49:58.672] <TB1> INFO: ROC errors: 0
[23:49:58.672] <TB1> INFO: missing ROC header(s): 0
[23:49:58.672] <TB1> INFO: misplaced readback start: 0
[23:49:58.672] <TB1> INFO: Pixel decoding errors: 0
[23:49:58.672] <TB1> INFO: pixel data incomplete: 0
[23:49:58.672] <TB1> INFO: pixel address: 0
[23:49:58.672] <TB1> INFO: pulse height fill bit: 0
[23:49:58.672] <TB1> INFO: buffer corruption: 0
[23:49:58.672] <TB1> INFO: enter test to run
[23:49:58.672] <TB1> INFO: test: exit no parameter change
[23:49:58.792] <TB1> QUIET: Connection to board 154 closed.
[23:49:58.793] <TB1> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud