[12:11:21.255] <TB3> INFO: *** Welcome to pxar ***
[12:11:21.255] <TB3> INFO: *** Today: 2016/10/20
[12:11:21.261] <TB3> INFO: *** Version: c8ba-dirty
[12:11:21.262] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C15.dat
[12:11:21.262] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//tbmParameters_C1b.dat
[12:11:21.262] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//defaultMaskFile.dat
[12:11:21.262] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters_C15.dat
[12:11:21.329] <TB3> INFO: clk: 4
[12:11:21.329] <TB3> INFO: ctr: 4
[12:11:21.329] <TB3> INFO: sda: 19
[12:11:21.329] <TB3> INFO: tin: 9
[12:11:21.329] <TB3> INFO: level: 15
[12:11:21.329] <TB3> INFO: triggerdelay: 0
[12:11:21.329] <TB3> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[12:11:21.329] <TB3> INFO: Log level: INFO
[12:11:21.337] <TB3> INFO: Found DTB DTB_WWVASW
[12:11:21.346] <TB3> QUIET: Connection to board DTB_WWVASW opened.
[12:11:21.348] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 126
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWVASW
MAC address: 40D85511807E
Hostname: pixelDTB126
Comment:
------------------------------------------------------
[12:11:21.350] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[12:11:22.872] <TB3> INFO: DUT info:
[12:11:22.872] <TB3> INFO: The DUT currently contains the following objects:
[12:11:22.872] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[12:11:22.872] <TB3> INFO: TBM Core alpha (0): 7 registers set
[12:11:22.872] <TB3> INFO: TBM Core beta (1): 7 registers set
[12:11:22.872] <TB3> INFO: TBM Core alpha (2): 7 registers set
[12:11:22.872] <TB3> INFO: TBM Core beta (3): 7 registers set
[12:11:22.872] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[12:11:22.872] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.872] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:22.873] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:11:23.273] <TB3> INFO: enter 'restricted' command line mode
[12:11:23.274] <TB3> INFO: enter test to run
[12:11:23.274] <TB3> INFO: test: pretest no parameter change
[12:11:23.274] <TB3> INFO: running: pretest
[12:11:23.280] <TB3> INFO: ######################################################################
[12:11:23.280] <TB3> INFO: PixTestPretest::doTest()
[12:11:23.280] <TB3> INFO: ######################################################################
[12:11:23.282] <TB3> INFO: ----------------------------------------------------------------------
[12:11:23.282] <TB3> INFO: PixTestPretest::programROC()
[12:11:23.282] <TB3> INFO: ----------------------------------------------------------------------
[12:11:41.296] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[12:11:41.296] <TB3> INFO: IA differences per ROC: 19.3 18.5 17.7 19.3 16.9 21.7 20.1 19.3 19.3 20.9 20.9 16.9 21.7 20.1 17.7 20.1
[12:11:41.363] <TB3> INFO: ----------------------------------------------------------------------
[12:11:41.363] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[12:11:41.363] <TB3> INFO: ----------------------------------------------------------------------
[12:12:02.659] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 390.7 mA = 24.4187 mA/ROC
[12:12:02.659] <TB3> INFO: i(loss) [mA/ROC]: 19.3 20.1 20.1 20.1 20.1 20.1 20.1 19.3 19.3 19.3 19.3 18.5 19.3 19.3 19.3 19.3
[12:12:02.693] <TB3> INFO: ----------------------------------------------------------------------
[12:12:02.693] <TB3> INFO: PixTestPretest::findTiming()
[12:12:02.693] <TB3> INFO: ----------------------------------------------------------------------
[12:12:02.693] <TB3> INFO: PixTestCmd::init()
[12:12:03.268] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!
[12:12:34.543] <TB3> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[12:12:34.543] <TB3> INFO: (success/tries = 100/100), width = 3
[12:12:36.040] <TB3> INFO: ----------------------------------------------------------------------
[12:12:36.040] <TB3> INFO: PixTestPretest::findWorkingPixel()
[12:12:36.040] <TB3> INFO: ----------------------------------------------------------------------
[12:12:36.134] <TB3> INFO: Expecting 231680 events.
[12:12:46.198] <TB3> INFO: 231680 events read in total (9473ms).
[12:12:46.206] <TB3> INFO: Test took 10162ms.
[12:12:46.453] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[12:12:46.491] <TB3> INFO: ----------------------------------------------------------------------
[12:12:46.491] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[12:12:46.491] <TB3> INFO: ----------------------------------------------------------------------
[12:12:46.587] <TB3> INFO: Expecting 231680 events.
[12:12:56.730] <TB3> INFO: 231680 events read in total (9552ms).
[12:12:56.739] <TB3> INFO: Test took 10242ms.
[12:12:57.009] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[12:12:57.009] <TB3> INFO: CalDel: 95 101 101 85 89 93 79 86 98 92 108 93 78 95 87 82
[12:12:57.009] <TB3> INFO: VthrComp: 51 54 51 51 54 51 51 52 53 53 51 51 53 51 51 51
[12:12:57.013] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C0.dat
[12:12:57.013] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C1.dat
[12:12:57.013] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C2.dat
[12:12:57.014] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C3.dat
[12:12:57.014] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C4.dat
[12:12:57.014] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C5.dat
[12:12:57.014] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C6.dat
[12:12:57.014] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C7.dat
[12:12:57.014] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C8.dat
[12:12:57.014] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C9.dat
[12:12:57.015] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C10.dat
[12:12:57.015] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C11.dat
[12:12:57.015] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C12.dat
[12:12:57.015] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C13.dat
[12:12:57.015] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C14.dat
[12:12:57.015] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters_C15.dat
[12:12:57.015] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//tbmParameters_C0a.dat
[12:12:57.016] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//tbmParameters_C0b.dat
[12:12:57.016] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//tbmParameters_C1a.dat
[12:12:57.016] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//tbmParameters_C1b.dat
[12:12:57.016] <TB3> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[12:12:57.069] <TB3> INFO: enter test to run
[12:12:57.069] <TB3> INFO: test: FullTest no parameter change
[12:12:57.069] <TB3> INFO: running: fulltest
[12:12:57.069] <TB3> INFO: ######################################################################
[12:12:57.069] <TB3> INFO: PixTestFullTest::doTest()
[12:12:57.069] <TB3> INFO: ######################################################################
[12:12:57.070] <TB3> INFO: ######################################################################
[12:12:57.071] <TB3> INFO: PixTestAlive::doTest()
[12:12:57.071] <TB3> INFO: ######################################################################
[12:12:57.072] <TB3> INFO: ----------------------------------------------------------------------
[12:12:57.072] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:12:57.072] <TB3> INFO: ----------------------------------------------------------------------
[12:12:57.308] <TB3> INFO: Expecting 41600 events.
[12:13:00.954] <TB3> INFO: 41600 events read in total (3054ms).
[12:13:00.955] <TB3> INFO: Test took 3882ms.
[12:13:01.187] <TB3> INFO: PixTestAlive::aliveTest() done
[12:13:01.187] <TB3> INFO: number of dead pixels (per ROC): 0 0 2 0 1 0 3 0 0 0 0 0 0 2 0 0
[12:13:01.189] <TB3> INFO: ----------------------------------------------------------------------
[12:13:01.189] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:13:01.189] <TB3> INFO: ----------------------------------------------------------------------
[12:13:01.436] <TB3> INFO: Expecting 41600 events.
[12:13:04.501] <TB3> INFO: 41600 events read in total (2473ms).
[12:13:04.501] <TB3> INFO: Test took 3310ms.
[12:13:04.501] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[12:13:04.745] <TB3> INFO: PixTestAlive::maskTest() done
[12:13:04.746] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:13:04.747] <TB3> INFO: ----------------------------------------------------------------------
[12:13:04.747] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:13:04.747] <TB3> INFO: ----------------------------------------------------------------------
[12:13:04.992] <TB3> INFO: Expecting 41600 events.
[12:13:08.543] <TB3> INFO: 41600 events read in total (2959ms).
[12:13:08.544] <TB3> INFO: Test took 3795ms.
[12:13:08.781] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[12:13:08.782] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:13:08.782] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[12:13:08.782] <TB3> INFO: Decoding statistics:
[12:13:08.782] <TB3> INFO: General information:
[12:13:08.782] <TB3> INFO: 16bit words read: 0
[12:13:08.782] <TB3> INFO: valid events total: 0
[12:13:08.782] <TB3> INFO: empty events: 0
[12:13:08.782] <TB3> INFO: valid events with pixels: 0
[12:13:08.782] <TB3> INFO: valid pixel hits: 0
[12:13:08.782] <TB3> INFO: Event errors: 0
[12:13:08.782] <TB3> INFO: start marker: 0
[12:13:08.782] <TB3> INFO: stop marker: 0
[12:13:08.782] <TB3> INFO: overflow: 0
[12:13:08.782] <TB3> INFO: invalid 5bit words: 0
[12:13:08.782] <TB3> INFO: invalid XOR eye diagram: 0
[12:13:08.782] <TB3> INFO: frame (failed synchr.): 0
[12:13:08.782] <TB3> INFO: idle data (no TBM trl): 0
[12:13:08.782] <TB3> INFO: no data (only TBM hdr): 0
[12:13:08.782] <TB3> INFO: TBM errors: 0
[12:13:08.782] <TB3> INFO: flawed TBM headers: 0
[12:13:08.782] <TB3> INFO: flawed TBM trailers: 0
[12:13:08.782] <TB3> INFO: event ID mismatches: 0
[12:13:08.782] <TB3> INFO: ROC errors: 0
[12:13:08.782] <TB3> INFO: missing ROC header(s): 0
[12:13:08.782] <TB3> INFO: misplaced readback start: 0
[12:13:08.782] <TB3> INFO: Pixel decoding errors: 0
[12:13:08.782] <TB3> INFO: pixel data incomplete: 0
[12:13:08.782] <TB3> INFO: pixel address: 0
[12:13:08.783] <TB3> INFO: pulse height fill bit: 0
[12:13:08.783] <TB3> INFO: buffer corruption: 0
[12:13:08.792] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C15.dat
[12:13:08.792] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr_C15.dat
[12:13:08.792] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants
[12:13:08.792] <TB3> INFO: ######################################################################
[12:13:08.792] <TB3> INFO: PixTestReadback::doTest()
[12:13:08.792] <TB3> INFO: ######################################################################
[12:13:08.792] <TB3> INFO: ----------------------------------------------------------------------
[12:13:08.792] <TB3> INFO: PixTestReadback::CalibrateVd()
[12:13:08.792] <TB3> INFO: ----------------------------------------------------------------------
[12:13:18.777] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C0.dat
[12:13:18.777] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C1.dat
[12:13:18.777] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C2.dat
[12:13:18.777] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C3.dat
[12:13:18.777] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C4.dat
[12:13:18.777] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C5.dat
[12:13:18.777] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C6.dat
[12:13:18.777] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C7.dat
[12:13:18.777] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C8.dat
[12:13:18.778] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C9.dat
[12:13:18.778] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C10.dat
[12:13:18.778] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C11.dat
[12:13:18.778] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C12.dat
[12:13:18.778] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C13.dat
[12:13:18.778] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C14.dat
[12:13:18.778] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C15.dat
[12:13:18.810] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[12:13:18.810] <TB3> INFO: ----------------------------------------------------------------------
[12:13:18.810] <TB3> INFO: PixTestReadback::CalibrateVa()
[12:13:18.810] <TB3> INFO: ----------------------------------------------------------------------
[12:13:28.751] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C0.dat
[12:13:28.751] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C1.dat
[12:13:28.751] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C2.dat
[12:13:28.751] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C3.dat
[12:13:28.751] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C4.dat
[12:13:28.751] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C5.dat
[12:13:28.751] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C6.dat
[12:13:28.752] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C7.dat
[12:13:28.752] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C8.dat
[12:13:28.752] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C9.dat
[12:13:28.752] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C10.dat
[12:13:28.752] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C11.dat
[12:13:28.752] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C12.dat
[12:13:28.752] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C13.dat
[12:13:28.752] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C14.dat
[12:13:28.752] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C15.dat
[12:13:28.786] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[12:13:28.786] <TB3> INFO: ----------------------------------------------------------------------
[12:13:28.786] <TB3> INFO: PixTestReadback::readbackVbg()
[12:13:28.786] <TB3> INFO: ----------------------------------------------------------------------
[12:13:36.462] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[12:13:36.462] <TB3> INFO: ----------------------------------------------------------------------
[12:13:36.462] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[12:13:36.462] <TB3> INFO: ----------------------------------------------------------------------
[12:13:36.462] <TB3> INFO: Vbg will be calibrated using Vd calibration
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 151calibrated Vbg = 1.20671 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 158calibrated Vbg = 1.20753 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 158.9calibrated Vbg = 1.20343 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 157.7calibrated Vbg = 1.2041 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 161.7calibrated Vbg = 1.20794 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 164.9calibrated Vbg = 1.2132 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 154.5calibrated Vbg = 1.21238 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 161calibrated Vbg = 1.21301 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 158.9calibrated Vbg = 1.20647 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 159calibrated Vbg = 1.20471 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 157calibrated Vbg = 1.20094 :::*/*/*/*/
[12:13:36.462] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 153.8calibrated Vbg = 1.1959 :::*/*/*/*/
[12:13:36.463] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 159.4calibrated Vbg = 1.19993 :::*/*/*/*/
[12:13:36.463] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 158.8calibrated Vbg = 1.20522 :::*/*/*/*/
[12:13:36.463] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 145.9calibrated Vbg = 1.20538 :::*/*/*/*/
[12:13:36.463] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 154.1calibrated Vbg = 1.20348 :::*/*/*/*/
[12:13:36.465] <TB3> INFO: ----------------------------------------------------------------------
[12:13:36.465] <TB3> INFO: PixTestReadback::CalibrateIa()
[12:13:36.466] <TB3> INFO: ----------------------------------------------------------------------
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C0.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C1.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C2.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C3.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C4.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C5.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C6.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C7.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C8.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C9.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C10.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C11.dat
[12:16:17.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C12.dat
[12:16:17.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C13.dat
[12:16:17.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C14.dat
[12:16:17.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//readbackCal_C15.dat
[12:16:17.247] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[12:16:17.250] <TB3> INFO: PixTestReadback::doTest() done
[12:16:17.250] <TB3> INFO: Decoding statistics:
[12:16:17.250] <TB3> INFO: General information:
[12:16:17.250] <TB3> INFO: 16bit words read: 1536
[12:16:17.250] <TB3> INFO: valid events total: 256
[12:16:17.250] <TB3> INFO: empty events: 256
[12:16:17.250] <TB3> INFO: valid events with pixels: 0
[12:16:17.250] <TB3> INFO: valid pixel hits: 0
[12:16:17.250] <TB3> INFO: Event errors: 0
[12:16:17.250] <TB3> INFO: start marker: 0
[12:16:17.250] <TB3> INFO: stop marker: 0
[12:16:17.250] <TB3> INFO: overflow: 0
[12:16:17.250] <TB3> INFO: invalid 5bit words: 0
[12:16:17.250] <TB3> INFO: invalid XOR eye diagram: 0
[12:16:17.250] <TB3> INFO: frame (failed synchr.): 0
[12:16:17.250] <TB3> INFO: idle data (no TBM trl): 0
[12:16:17.250] <TB3> INFO: no data (only TBM hdr): 0
[12:16:17.250] <TB3> INFO: TBM errors: 0
[12:16:17.250] <TB3> INFO: flawed TBM headers: 0
[12:16:17.250] <TB3> INFO: flawed TBM trailers: 0
[12:16:17.250] <TB3> INFO: event ID mismatches: 0
[12:16:17.250] <TB3> INFO: ROC errors: 0
[12:16:17.251] <TB3> INFO: missing ROC header(s): 0
[12:16:17.251] <TB3> INFO: misplaced readback start: 0
[12:16:17.251] <TB3> INFO: Pixel decoding errors: 0
[12:16:17.251] <TB3> INFO: pixel data incomplete: 0
[12:16:17.251] <TB3> INFO: pixel address: 0
[12:16:17.251] <TB3> INFO: pulse height fill bit: 0
[12:16:17.251] <TB3> INFO: buffer corruption: 0
[12:16:17.297] <TB3> INFO: ######################################################################
[12:16:17.297] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[12:16:17.297] <TB3> INFO: ######################################################################
[12:16:17.299] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[12:16:17.313] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[12:16:17.313] <TB3> INFO: run 1 of 1
[12:16:17.550] <TB3> INFO: Expecting 3120000 events.
[12:16:48.321] <TB3> INFO: 676545 events read in total (30179ms).
[12:17:00.779] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (66) != TBM ID (129)
[12:17:00.917] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 66 66 129 66 66 66 66 66
[12:17:00.917] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (67)
[12:17:00.917] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[12:17:00.917] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a046 8000 4c00 4c00 e022 c000
[12:17:00.917] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a040 80b1 4c00 4c00 e022 c000
[12:17:00.917] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a041 80c0 4e01 4c01 e022 c000
[12:17:00.918] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c01 e022 c000
[12:17:00.918] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a043 8040 4c00 4c00 e022 c000
[12:17:00.918] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a044 80b1 4c00 4c00 e022 c000
[12:17:00.918] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a045 80c0 4c00 4c00 e022 c000
[12:17:18.642] <TB3> INFO: 1354895 events read in total (60500ms).
[12:17:31.078] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (16) != TBM ID (129)
[12:17:31.215] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 16 16 129 16 16 16 16 16
[12:17:31.216] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (17)
[12:17:31.216] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[12:17:31.216] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a014 80b1 4c00 4c00 e022 c000
[12:17:31.216] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00e 8000 4c01 4c00 e022 c000
[12:17:31.216] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00f 8040 4c03 4c01 e022 c000
[12:17:31.216] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c01 e022 c000
[12:17:31.216] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a011 80c0 4c01 4c01 e022 c000
[12:17:31.216] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a012 8000 4c00 4c00 e022 c000
[12:17:31.216] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a013 8040 4c00 4c00 e022 c000
[12:17:49.097] <TB3> INFO: 2031985 events read in total (90955ms).
[12:18:01.566] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (242) != TBM ID (129)
[12:18:01.703] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 242 242 129 242 242 242 242 242
[12:18:01.703] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (243)
[12:18:01.703] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[12:18:01.703] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f6 8000 4c00 4c00 e022 c000
[12:18:01.703] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f0 80b1 4c00 4c00 e022 c000
[12:18:01.704] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f1 80c0 4c01 4c01 e022 c000
[12:18:01.704] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c01 e022 c000
[12:18:01.704] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f3 8040 4c00 4c00 e022 c000
[12:18:01.704] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f4 80b1 4c00 4c00 e022 c000
[12:18:01.704] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0f5 80c0 4c00 4c00 e022 c000
[12:18:20.357] <TB3> INFO: 2710010 events read in total (122216ms).
[12:18:27.001] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (123) != TBM ID (129)
[12:18:28.141] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 123 123 129 123 123 123 123 123
[12:18:28.141] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (124)
[12:18:28.141] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:
[12:18:28.141] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07f 8040 4c03 4c01 e022 c000
[12:18:28.141] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a079 80c0 4e00 4e01 e022 c000
[12:18:28.141] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07a 8000 4e01 4c00 e022 c000
[12:18:28.141] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 4c01 4c01 e022 c000
[12:18:28.141] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07c 80b1 4c00 4c00 e022 c000
[12:18:28.141] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07d 80c0 4c00 4c03 e022 c000
[12:18:28.141] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07e 8000 4c00 4c00 e022 c000
[12:18:39.008] <TB3> INFO: 3120000 events read in total (140866ms).
[12:18:39.108] <TB3> INFO: Test took 141796ms.
[12:19:02.361] <TB3> INFO: PixTestBBMap::doTest() done, duration: 165 seconds
[12:19:02.361] <TB3> INFO: number of dead bumps (per ROC): 4 1 0 0 3 0 2 0 0 1 0 0 1 1 0 0
[12:19:02.361] <TB3> INFO: separation cut (per ROC): 125 122 123 115 121 128 123 120 103 106 107 103 110 106 105 107
[12:19:02.361] <TB3> INFO: Decoding statistics:
[12:19:02.361] <TB3> INFO: General information:
[12:19:02.361] <TB3> INFO: 16bit words read: 0
[12:19:02.361] <TB3> INFO: valid events total: 0
[12:19:02.361] <TB3> INFO: empty events: 0
[12:19:02.361] <TB3> INFO: valid events with pixels: 0
[12:19:02.361] <TB3> INFO: valid pixel hits: 0
[12:19:02.361] <TB3> INFO: Event errors: 0
[12:19:02.361] <TB3> INFO: start marker: 0
[12:19:02.361] <TB3> INFO: stop marker: 0
[12:19:02.361] <TB3> INFO: overflow: 0
[12:19:02.361] <TB3> INFO: invalid 5bit words: 0
[12:19:02.361] <TB3> INFO: invalid XOR eye diagram: 0
[12:19:02.361] <TB3> INFO: frame (failed synchr.): 0
[12:19:02.361] <TB3> INFO: idle data (no TBM trl): 0
[12:19:02.361] <TB3> INFO: no data (only TBM hdr): 0
[12:19:02.361] <TB3> INFO: TBM errors: 0
[12:19:02.361] <TB3> INFO: flawed TBM headers: 0
[12:19:02.361] <TB3> INFO: flawed TBM trailers: 0
[12:19:02.361] <TB3> INFO: event ID mismatches: 0
[12:19:02.361] <TB3> INFO: ROC errors: 0
[12:19:02.361] <TB3> INFO: missing ROC header(s): 0
[12:19:02.361] <TB3> INFO: misplaced readback start: 0
[12:19:02.361] <TB3> INFO: Pixel decoding errors: 0
[12:19:02.361] <TB3> INFO: pixel data incomplete: 0
[12:19:02.361] <TB3> INFO: pixel address: 0
[12:19:02.361] <TB3> INFO: pulse height fill bit: 0
[12:19:02.361] <TB3> INFO: buffer corruption: 0
[12:19:02.399] <TB3> INFO: ######################################################################
[12:19:02.399] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[12:19:02.399] <TB3> INFO: ######################################################################
[12:19:02.399] <TB3> INFO: ----------------------------------------------------------------------
[12:19:02.399] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[12:19:02.399] <TB3> INFO: ----------------------------------------------------------------------
[12:19:02.399] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[12:19:02.414] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[12:19:02.414] <TB3> INFO: run 1 of 1
[12:19:02.655] <TB3> INFO: Expecting 36608000 events.
[12:19:26.751] <TB3> INFO: 705200 events read in total (23504ms).
[12:19:49.966] <TB3> INFO: 1395250 events read in total (46719ms).
[12:20:13.010] <TB3> INFO: 2085250 events read in total (69763ms).
[12:20:36.190] <TB3> INFO: 2775000 events read in total (92943ms).
[12:20:59.288] <TB3> INFO: 3461450 events read in total (116041ms).
[12:21:22.419] <TB3> INFO: 4150150 events read in total (139172ms).
[12:21:45.306] <TB3> INFO: 4835000 events read in total (162059ms).
[12:22:08.175] <TB3> INFO: 5518250 events read in total (184928ms).
[12:22:31.246] <TB3> INFO: 6207000 events read in total (207999ms).
[12:22:54.173] <TB3> INFO: 6892950 events read in total (230926ms).
[12:23:17.416] <TB3> INFO: 7576850 events read in total (254169ms).
[12:23:40.348] <TB3> INFO: 8261950 events read in total (277101ms).
[12:24:03.379] <TB3> INFO: 8946050 events read in total (300132ms).
[12:24:26.262] <TB3> INFO: 9629900 events read in total (323015ms).
[12:24:49.391] <TB3> INFO: 10313200 events read in total (346144ms).
[12:25:12.094] <TB3> INFO: 10997400 events read in total (368848ms).
[12:25:34.941] <TB3> INFO: 11678700 events read in total (391694ms).
[12:25:57.979] <TB3> INFO: 12361450 events read in total (414732ms).
[12:26:21.103] <TB3> INFO: 13043400 events read in total (437856ms).
[12:26:44.040] <TB3> INFO: 13727150 events read in total (460793ms).
[12:27:07.080] <TB3> INFO: 14410400 events read in total (483833ms).
[12:27:29.972] <TB3> INFO: 15091700 events read in total (506725ms).
[12:27:53.060] <TB3> INFO: 15774850 events read in total (529813ms).
[12:28:16.080] <TB3> INFO: 16456200 events read in total (552833ms).
[12:28:38.933] <TB3> INFO: 17139300 events read in total (575686ms).
[12:29:01.773] <TB3> INFO: 17818000 events read in total (598526ms).
[12:29:24.914] <TB3> INFO: 18497050 events read in total (621667ms).
[12:29:47.919] <TB3> INFO: 19173000 events read in total (644672ms).
[12:30:10.747] <TB3> INFO: 19848650 events read in total (667500ms).
[12:30:33.694] <TB3> INFO: 20525000 events read in total (690447ms).
[12:30:56.677] <TB3> INFO: 21199200 events read in total (713430ms).
[12:31:19.396] <TB3> INFO: 21875600 events read in total (736149ms).
[12:31:42.309] <TB3> INFO: 22551700 events read in total (759063ms).
[12:32:05.163] <TB3> INFO: 23225950 events read in total (781916ms).
[12:32:27.962] <TB3> INFO: 23899900 events read in total (804715ms).
[12:32:51.166] <TB3> INFO: 24575850 events read in total (827919ms).
[12:33:14.294] <TB3> INFO: 25252200 events read in total (851047ms).
[12:33:37.188] <TB3> INFO: 25925800 events read in total (873941ms).
[12:33:59.991] <TB3> INFO: 26601400 events read in total (896744ms).
[12:34:22.598] <TB3> INFO: 27275850 events read in total (919351ms).
[12:34:45.315] <TB3> INFO: 27948850 events read in total (942068ms).
[12:35:07.989] <TB3> INFO: 28622500 events read in total (964742ms).
[12:35:31.108] <TB3> INFO: 29295550 events read in total (987861ms).
[12:35:53.791] <TB3> INFO: 29968750 events read in total (1010544ms).
[12:36:16.281] <TB3> INFO: 30639750 events read in total (1033034ms).
[12:36:39.031] <TB3> INFO: 31311900 events read in total (1055784ms).
[12:37:01.641] <TB3> INFO: 31983450 events read in total (1078394ms).
[12:37:24.526] <TB3> INFO: 32656400 events read in total (1101279ms).
[12:37:47.517] <TB3> INFO: 33330550 events read in total (1124270ms).
[12:38:10.469] <TB3> INFO: 34004100 events read in total (1147222ms).
[12:38:33.391] <TB3> INFO: 34678200 events read in total (1170144ms).
[12:38:56.146] <TB3> INFO: 35354150 events read in total (1192899ms).
[12:39:19.320] <TB3> INFO: 36031750 events read in total (1216073ms).
[12:39:39.892] <TB3> INFO: 36608000 events read in total (1236645ms).
[12:39:39.952] <TB3> INFO: Test took 1237538ms.
[12:39:40.329] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:41.872] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:43.299] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:44.709] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:46.121] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:47.522] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:48.916] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:50.376] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:51.794] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:53.246] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:54.951] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:56.923] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:39:58.467] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:40:00.482] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:40:02.185] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:40:03.968] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[12:40:05.897] <TB3> INFO: PixTestScurves::scurves() done
[12:40:05.897] <TB3> INFO: Vcal mean: 124.84 128.75 131.38 125.37 127.88 132.05 130.49 132.46 130.17 132.76 127.98 112.55 127.01 119.01 127.03 123.49
[12:40:05.897] <TB3> INFO: Vcal RMS: 6.89 6.40 7.54 5.68 6.39 5.68 7.26 5.71 7.10 6.23 6.61 4.87 6.28 5.88 6.45 6.18
[12:40:05.897] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1263 seconds
[12:40:05.897] <TB3> INFO: Decoding statistics:
[12:40:05.897] <TB3> INFO: General information:
[12:40:05.897] <TB3> INFO: 16bit words read: 0
[12:40:05.897] <TB3> INFO: valid events total: 0
[12:40:05.897] <TB3> INFO: empty events: 0
[12:40:05.898] <TB3> INFO: valid events with pixels: 0
[12:40:05.898] <TB3> INFO: valid pixel hits: 0
[12:40:05.898] <TB3> INFO: Event errors: 0
[12:40:05.898] <TB3> INFO: start marker: 0
[12:40:05.898] <TB3> INFO: stop marker: 0
[12:40:05.898] <TB3> INFO: overflow: 0
[12:40:05.898] <TB3> INFO: invalid 5bit words: 0
[12:40:05.898] <TB3> INFO: invalid XOR eye diagram: 0
[12:40:05.898] <TB3> INFO: frame (failed synchr.): 0
[12:40:05.898] <TB3> INFO: idle data (no TBM trl): 0
[12:40:05.898] <TB3> INFO: no data (only TBM hdr): 0
[12:40:05.898] <TB3> INFO: TBM errors: 0
[12:40:05.898] <TB3> INFO: flawed TBM headers: 0
[12:40:05.898] <TB3> INFO: flawed TBM trailers: 0
[12:40:05.898] <TB3> INFO: event ID mismatches: 0
[12:40:05.898] <TB3> INFO: ROC errors: 0
[12:40:05.898] <TB3> INFO: missing ROC header(s): 0
[12:40:05.898] <TB3> INFO: misplaced readback start: 0
[12:40:05.898] <TB3> INFO: Pixel decoding errors: 0
[12:40:05.898] <TB3> INFO: pixel data incomplete: 0
[12:40:05.898] <TB3> INFO: pixel address: 0
[12:40:05.898] <TB3> INFO: pulse height fill bit: 0
[12:40:05.898] <TB3> INFO: buffer corruption: 0
[12:40:05.965] <TB3> INFO: ######################################################################
[12:40:05.966] <TB3> INFO: PixTestTrim::doTest()
[12:40:05.966] <TB3> INFO: ######################################################################
[12:40:05.967] <TB3> INFO: ----------------------------------------------------------------------
[12:40:05.967] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[12:40:05.967] <TB3> INFO: ----------------------------------------------------------------------
[12:40:06.015] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:40:06.015] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:40:06.028] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:40:06.028] <TB3> INFO: run 1 of 1
[12:40:06.293] <TB3> INFO: Expecting 5025280 events.
[12:40:37.490] <TB3> INFO: 833048 events read in total (30600ms).
[12:41:07.794] <TB3> INFO: 1665696 events read in total (60904ms).
[12:41:38.406] <TB3> INFO: 2495976 events read in total (91516ms).
[12:42:09.105] <TB3> INFO: 3322760 events read in total (122215ms).
[12:42:39.618] <TB3> INFO: 4145760 events read in total (152728ms).
[12:43:11.435] <TB3> INFO: 4967008 events read in total (184545ms).
[12:43:13.971] <TB3> INFO: 5025280 events read in total (187081ms).
[12:43:14.017] <TB3> INFO: Test took 187989ms.
[12:43:31.810] <TB3> INFO: ROC 0 VthrComp = 126
[12:43:31.810] <TB3> INFO: ROC 1 VthrComp = 124
[12:43:31.810] <TB3> INFO: ROC 2 VthrComp = 128
[12:43:31.810] <TB3> INFO: ROC 3 VthrComp = 125
[12:43:31.810] <TB3> INFO: ROC 4 VthrComp = 124
[12:43:31.810] <TB3> INFO: ROC 5 VthrComp = 131
[12:43:31.811] <TB3> INFO: ROC 6 VthrComp = 132
[12:43:31.811] <TB3> INFO: ROC 7 VthrComp = 133
[12:43:31.811] <TB3> INFO: ROC 8 VthrComp = 128
[12:43:31.811] <TB3> INFO: ROC 9 VthrComp = 128
[12:43:31.812] <TB3> INFO: ROC 10 VthrComp = 125
[12:43:31.812] <TB3> INFO: ROC 11 VthrComp = 108
[12:43:31.812] <TB3> INFO: ROC 12 VthrComp = 129
[12:43:31.812] <TB3> INFO: ROC 13 VthrComp = 121
[12:43:31.812] <TB3> INFO: ROC 14 VthrComp = 127
[12:43:31.812] <TB3> INFO: ROC 15 VthrComp = 125
[12:43:32.057] <TB3> INFO: Expecting 41600 events.
[12:43:35.619] <TB3> INFO: 41600 events read in total (2971ms).
[12:43:35.620] <TB3> INFO: Test took 3807ms.
[12:43:35.629] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:43:35.629] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:43:35.641] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:43:35.641] <TB3> INFO: run 1 of 1
[12:43:35.919] <TB3> INFO: Expecting 5025280 events.
[12:44:02.649] <TB3> INFO: 591584 events read in total (26139ms).
[12:44:28.812] <TB3> INFO: 1182680 events read in total (52302ms).
[12:44:54.535] <TB3> INFO: 1774016 events read in total (78025ms).
[12:45:20.292] <TB3> INFO: 2364616 events read in total (103782ms).
[12:45:46.431] <TB3> INFO: 2952248 events read in total (129921ms).
[12:46:12.506] <TB3> INFO: 3539144 events read in total (155996ms).
[12:46:38.789] <TB3> INFO: 4124904 events read in total (182279ms).
[12:47:05.035] <TB3> INFO: 4710840 events read in total (208525ms).
[12:47:19.921] <TB3> INFO: 5025280 events read in total (223411ms).
[12:47:20.006] <TB3> INFO: Test took 224366ms.
[12:47:44.512] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 60.4327 for pixel 1/9 mean/min/max = 45.887/31.3188/60.4551
[12:47:44.512] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 64.208 for pixel 4/13 mean/min/max = 48.9373/33.484/64.3906
[12:47:44.512] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 62.3454 for pixel 2/25 mean/min/max = 46.8664/31.3409/62.3919
[12:47:44.513] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 59.1497 for pixel 17/2 mean/min/max = 45.4737/31.7832/59.1642
[12:47:44.513] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 63.1694 for pixel 7/4 mean/min/max = 48.2303/32.6334/63.8273
[12:47:44.514] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 60.2211 for pixel 24/16 mean/min/max = 46.6255/32.9883/60.2628
[12:47:44.514] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 60.9142 for pixel 18/6 mean/min/max = 46.5288/32.1039/60.9538
[12:47:44.514] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 60.8917 for pixel 51/18 mean/min/max = 46.2453/31.4195/61.071
[12:47:44.515] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 64.9734 for pixel 0/57 mean/min/max = 48.0645/30.7698/65.3592
[12:47:44.515] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 65.3963 for pixel 0/3 mean/min/max = 48.7114/31.9344/65.4883
[12:47:44.516] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 63.9611 for pixel 12/6 mean/min/max = 47.8064/31.1213/64.4915
[12:47:44.516] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 62.5698 for pixel 2/70 mean/min/max = 49.1154/35.2957/62.9352
[12:47:44.516] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 61.221 for pixel 5/20 mean/min/max = 46.333/31.4341/61.2319
[12:47:44.516] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 63.1808 for pixel 13/11 mean/min/max = 46.484/29.3491/63.619
[12:47:44.517] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 60.8032 for pixel 0/49 mean/min/max = 46.3601/31.9115/60.8087
[12:47:44.517] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 59.823 for pixel 11/1 mean/min/max = 46.1757/32.525/59.8264
[12:47:44.517] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:47:44.606] <TB3> INFO: Expecting 411648 events.
[12:47:54.215] <TB3> INFO: 411648 events read in total (9017ms).
[12:47:54.222] <TB3> INFO: Expecting 411648 events.
[12:48:03.524] <TB3> INFO: 411648 events read in total (8899ms).
[12:48:03.534] <TB3> INFO: Expecting 411648 events.
[12:48:12.887] <TB3> INFO: 411648 events read in total (8950ms).
[12:48:12.900] <TB3> INFO: Expecting 411648 events.
[12:48:22.255] <TB3> INFO: 411648 events read in total (8952ms).
[12:48:22.270] <TB3> INFO: Expecting 411648 events.
[12:48:31.601] <TB3> INFO: 411648 events read in total (8928ms).
[12:48:31.619] <TB3> INFO: Expecting 411648 events.
[12:48:40.976] <TB3> INFO: 411648 events read in total (8954ms).
[12:48:40.997] <TB3> INFO: Expecting 411648 events.
[12:48:50.423] <TB3> INFO: 411648 events read in total (9023ms).
[12:48:50.446] <TB3> INFO: Expecting 411648 events.
[12:48:59.801] <TB3> INFO: 411648 events read in total (8952ms).
[12:48:59.828] <TB3> INFO: Expecting 411648 events.
[12:49:09.225] <TB3> INFO: 411648 events read in total (8994ms).
[12:49:09.263] <TB3> INFO: Expecting 411648 events.
[12:49:18.595] <TB3> INFO: 411648 events read in total (8930ms).
[12:49:18.627] <TB3> INFO: Expecting 411648 events.
[12:49:27.995] <TB3> INFO: 411648 events read in total (8965ms).
[12:49:28.030] <TB3> INFO: Expecting 411648 events.
[12:49:37.335] <TB3> INFO: 411648 events read in total (8902ms).
[12:49:37.372] <TB3> INFO: Expecting 411648 events.
[12:49:46.703] <TB3> INFO: 411648 events read in total (8928ms).
[12:49:46.742] <TB3> INFO: Expecting 411648 events.
[12:49:56.472] <TB3> INFO: 411648 events read in total (9327ms).
[12:49:56.514] <TB3> INFO: Expecting 411648 events.
[12:50:05.802] <TB3> INFO: 411648 events read in total (8885ms).
[12:50:05.848] <TB3> INFO: Expecting 411648 events.
[12:50:15.091] <TB3> INFO: 411648 events read in total (8840ms).
[12:50:15.138] <TB3> INFO: Test took 150621ms.
[12:50:15.799] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[12:50:15.813] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:50:15.813] <TB3> INFO: run 1 of 1
[12:50:16.051] <TB3> INFO: Expecting 5025280 events.
[12:50:42.814] <TB3> INFO: 591840 events read in total (26172ms).
[12:51:08.874] <TB3> INFO: 1183384 events read in total (52232ms).
[12:51:34.970] <TB3> INFO: 1772168 events read in total (78328ms).
[12:52:01.373] <TB3> INFO: 2361232 events read in total (104731ms).
[12:52:28.145] <TB3> INFO: 2953864 events read in total (131503ms).
[12:52:54.544] <TB3> INFO: 3545560 events read in total (157902ms).
[12:53:20.883] <TB3> INFO: 4138032 events read in total (184241ms).
[12:53:47.620] <TB3> INFO: 4729296 events read in total (210978ms).
[12:54:01.271] <TB3> INFO: 5025280 events read in total (224629ms).
[12:54:01.399] <TB3> INFO: Test took 225587ms.
[12:54:24.572] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 6.567893 .. 144.739686
[12:54:24.815] <TB3> INFO: Expecting 208000 events.
[12:54:34.399] <TB3> INFO: 208000 events read in total (8992ms).
[12:54:34.400] <TB3> INFO: Test took 9826ms.
[12:54:34.449] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 6 .. 154 (-1/-1) hits flags = 528 (plus default)
[12:54:34.462] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:54:34.462] <TB3> INFO: run 1 of 1
[12:54:34.740] <TB3> INFO: Expecting 4958720 events.
[12:55:01.076] <TB3> INFO: 578928 events read in total (25744ms).
[12:55:26.537] <TB3> INFO: 1157408 events read in total (51206ms).
[12:55:52.164] <TB3> INFO: 1735936 events read in total (76833ms).
[12:56:17.939] <TB3> INFO: 2314208 events read in total (102607ms).
[12:56:44.158] <TB3> INFO: 2892432 events read in total (128826ms).
[12:57:09.765] <TB3> INFO: 3470256 events read in total (154433ms).
[12:57:35.912] <TB3> INFO: 4047992 events read in total (180580ms).
[12:58:01.986] <TB3> INFO: 4625576 events read in total (206654ms).
[12:58:18.136] <TB3> INFO: 4958720 events read in total (222804ms).
[12:58:18.333] <TB3> INFO: Test took 223872ms.
[12:58:50.216] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 28.083382 .. 50.901132
[12:58:50.459] <TB3> INFO: Expecting 208000 events.
[12:59:00.128] <TB3> INFO: 208000 events read in total (9078ms).
[12:59:00.131] <TB3> INFO: Test took 9912ms.
[12:59:00.179] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 18 .. 60 (-1/-1) hits flags = 528 (plus default)
[12:59:00.190] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[12:59:00.190] <TB3> INFO: run 1 of 1
[12:59:00.469] <TB3> INFO: Expecting 1431040 events.
[12:59:28.639] <TB3> INFO: 640656 events read in total (27579ms).
[12:59:55.000] <TB3> INFO: 1278864 events read in total (54940ms).
[13:00:03.057] <TB3> INFO: 1431040 events read in total (61997ms).
[13:00:03.099] <TB3> INFO: Test took 62909ms.
[13:00:17.815] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 28.346391 .. 49.087798
[13:00:18.054] <TB3> INFO: Expecting 208000 events.
[13:00:27.909] <TB3> INFO: 208000 events read in total (9263ms).
[13:00:27.910] <TB3> INFO: Test took 10093ms.
[13:00:27.959] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 18 .. 59 (-1/-1) hits flags = 528 (plus default)
[13:00:27.972] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[13:00:27.972] <TB3> INFO: run 1 of 1
[13:00:28.250] <TB3> INFO: Expecting 1397760 events.
[13:00:56.572] <TB3> INFO: 642848 events read in total (27730ms).
[13:01:23.968] <TB3> INFO: 1284072 events read in total (55126ms).
[13:01:29.405] <TB3> INFO: 1397760 events read in total (60563ms).
[13:01:29.440] <TB3> INFO: Test took 61468ms.
[13:01:43.570] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 26.217528 .. 47.563528
[13:01:43.828] <TB3> INFO: Expecting 208000 events.
[13:01:53.749] <TB3> INFO: 208000 events read in total (9329ms).
[13:01:53.750] <TB3> INFO: Test took 10178ms.
[13:01:53.799] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 16 .. 57 (-1/-1) hits flags = 528 (plus default)
[13:01:53.811] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[13:01:53.812] <TB3> INFO: run 1 of 1
[13:01:54.090] <TB3> INFO: Expecting 1397760 events.
[13:02:22.826] <TB3> INFO: 657112 events read in total (28144ms).
[13:02:50.343] <TB3> INFO: 1313440 events read in total (55661ms).
[13:02:54.369] <TB3> INFO: 1397760 events read in total (59687ms).
[13:02:54.407] <TB3> INFO: Test took 60595ms.
[13:03:09.063] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[13:03:09.064] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[13:03:09.076] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[13:03:09.076] <TB3> INFO: run 1 of 1
[13:03:09.313] <TB3> INFO: Expecting 1364480 events.
[13:03:37.905] <TB3> INFO: 668728 events read in total (28001ms).
[13:04:06.352] <TB3> INFO: 1336928 events read in total (56448ms).
[13:04:07.983] <TB3> INFO: 1364480 events read in total (58080ms).
[13:04:08.012] <TB3> INFO: Test took 58935ms.
[13:04:22.170] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C0.dat
[13:04:22.170] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C1.dat
[13:04:22.170] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C2.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C3.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C4.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C5.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C6.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C7.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C8.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C9.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C10.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C11.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C12.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C13.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C14.dat
[13:04:22.171] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C15.dat
[13:04:22.172] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C0.dat
[13:04:22.178] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C1.dat
[13:04:22.182] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C2.dat
[13:04:22.187] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C3.dat
[13:04:22.192] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C4.dat
[13:04:22.196] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C5.dat
[13:04:22.201] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C6.dat
[13:04:22.206] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C7.dat
[13:04:22.211] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C8.dat
[13:04:22.215] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C9.dat
[13:04:22.220] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C10.dat
[13:04:22.224] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C11.dat
[13:04:22.229] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C12.dat
[13:04:22.234] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C13.dat
[13:04:22.238] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C14.dat
[13:04:22.243] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//trimParameters35_C15.dat
[13:04:22.248] <TB3> INFO: PixTestTrim::trimTest() done
[13:04:22.248] <TB3> INFO: vtrim: 107 141 125 132 113 128 141 120 135 140 140 117 120 146 130 120
[13:04:22.248] <TB3> INFO: vthrcomp: 126 124 128 125 124 131 132 133 128 128 125 108 129 121 127 125
[13:04:22.248] <TB3> INFO: vcal mean: 34.95 35.20 35.07 34.92 35.28 35.03 35.08 35.08 35.27 35.46 35.26 35.09 35.00 34.97 35.05 34.97
[13:04:22.248] <TB3> INFO: vcal RMS: 1.03 1.26 1.47 1.08 1.36 1.01 1.23 1.17 1.53 1.68 1.52 1.21 1.02 1.23 1.24 1.03
[13:04:22.248] <TB3> INFO: bits mean: 9.20 9.16 9.59 9.64 8.71 9.45 9.53 9.62 9.49 8.99 9.77 8.32 9.20 10.12 9.12 9.38
[13:04:22.248] <TB3> INFO: bits RMS: 2.96 2.53 2.74 2.70 2.87 2.55 2.64 2.73 2.81 2.92 2.66 2.66 2.88 2.38 2.91 2.73
[13:04:22.255] <TB3> INFO: ----------------------------------------------------------------------
[13:04:22.255] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[13:04:22.255] <TB3> INFO: ----------------------------------------------------------------------
[13:04:22.259] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[13:04:22.270] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:04:22.270] <TB3> INFO: run 1 of 1
[13:04:22.506] <TB3> INFO: Expecting 4160000 events.
[13:04:55.538] <TB3> INFO: 781995 events read in total (32440ms).
[13:05:28.243] <TB3> INFO: 1555055 events read in total (65145ms).
[13:06:00.384] <TB3> INFO: 2322695 events read in total (97286ms).
[13:06:32.627] <TB3> INFO: 3083860 events read in total (129529ms).
[13:07:05.559] <TB3> INFO: 3842330 events read in total (162461ms).
[13:07:19.270] <TB3> INFO: 4160000 events read in total (176172ms).
[13:07:19.336] <TB3> INFO: Test took 177066ms.
[13:07:45.526] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 206 (-1/-1) hits flags = 528 (plus default)
[13:07:45.538] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:07:45.538] <TB3> INFO: run 1 of 1
[13:07:45.774] <TB3> INFO: Expecting 4305600 events.
[13:08:17.952] <TB3> INFO: 743105 events read in total (31587ms).
[13:08:49.386] <TB3> INFO: 1478490 events read in total (63021ms).
[13:09:20.961] <TB3> INFO: 2211425 events read in total (94597ms).
[13:09:52.328] <TB3> INFO: 2937470 events read in total (125963ms).
[13:10:23.664] <TB3> INFO: 3661645 events read in total (157299ms).
[13:10:51.986] <TB3> INFO: 4305600 events read in total (185621ms).
[13:10:52.113] <TB3> INFO: Test took 186574ms.
[13:11:22.479] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[13:11:22.492] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:11:22.492] <TB3> INFO: run 1 of 1
[13:11:22.771] <TB3> INFO: Expecting 4160000 events.
[13:11:55.673] <TB3> INFO: 753520 events read in total (32311ms).
[13:12:28.254] <TB3> INFO: 1499220 events read in total (64892ms).
[13:13:00.390] <TB3> INFO: 2241255 events read in total (97028ms).
[13:13:32.702] <TB3> INFO: 2976890 events read in total (129340ms).
[13:14:04.489] <TB3> INFO: 3710130 events read in total (161127ms).
[13:14:24.188] <TB3> INFO: 4160000 events read in total (180826ms).
[13:14:24.258] <TB3> INFO: Test took 181767ms.
[13:14:51.084] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[13:14:51.097] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:14:51.097] <TB3> INFO: run 1 of 1
[13:14:51.344] <TB3> INFO: Expecting 4139200 events.
[13:15:23.883] <TB3> INFO: 755585 events read in total (31948ms).
[13:15:55.962] <TB3> INFO: 1503115 events read in total (64027ms).
[13:16:27.717] <TB3> INFO: 2246535 events read in total (95783ms).
[13:16:59.440] <TB3> INFO: 2984095 events read in total (127505ms).
[13:17:31.064] <TB3> INFO: 3718905 events read in total (159129ms).
[13:17:49.473] <TB3> INFO: 4139200 events read in total (177538ms).
[13:17:49.624] <TB3> INFO: Test took 178527ms.
[13:18:16.616] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[13:18:16.629] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[13:18:16.629] <TB3> INFO: run 1 of 1
[13:18:16.865] <TB3> INFO: Expecting 4139200 events.
[13:18:49.543] <TB3> INFO: 756000 events read in total (32086ms).
[13:19:21.743] <TB3> INFO: 1503840 events read in total (64286ms).
[13:19:53.782] <TB3> INFO: 2247585 events read in total (96325ms).
[13:20:25.491] <TB3> INFO: 2985290 events read in total (128034ms).
[13:20:57.155] <TB3> INFO: 3720175 events read in total (159698ms).
[13:21:16.041] <TB3> INFO: 4139200 events read in total (178584ms).
[13:21:16.284] <TB3> INFO: Test took 179654ms.
[13:21:42.516] <TB3> INFO: PixTestTrim::trimBitTest() done
[13:21:42.518] <TB3> INFO: PixTestTrim::doTest() done, duration: 2496 seconds
[13:21:42.518] <TB3> INFO: Decoding statistics:
[13:21:42.518] <TB3> INFO: General information:
[13:21:42.518] <TB3> INFO: 16bit words read: 0
[13:21:42.518] <TB3> INFO: valid events total: 0
[13:21:42.518] <TB3> INFO: empty events: 0
[13:21:42.518] <TB3> INFO: valid events with pixels: 0
[13:21:42.518] <TB3> INFO: valid pixel hits: 0
[13:21:42.518] <TB3> INFO: Event errors: 0
[13:21:42.518] <TB3> INFO: start marker: 0
[13:21:42.518] <TB3> INFO: stop marker: 0
[13:21:42.518] <TB3> INFO: overflow: 0
[13:21:42.518] <TB3> INFO: invalid 5bit words: 0
[13:21:42.518] <TB3> INFO: invalid XOR eye diagram: 0
[13:21:42.518] <TB3> INFO: frame (failed synchr.): 0
[13:21:42.518] <TB3> INFO: idle data (no TBM trl): 0
[13:21:42.518] <TB3> INFO: no data (only TBM hdr): 0
[13:21:42.518] <TB3> INFO: TBM errors: 0
[13:21:42.518] <TB3> INFO: flawed TBM headers: 0
[13:21:42.518] <TB3> INFO: flawed TBM trailers: 0
[13:21:42.518] <TB3> INFO: event ID mismatches: 0
[13:21:42.518] <TB3> INFO: ROC errors: 0
[13:21:42.518] <TB3> INFO: missing ROC header(s): 0
[13:21:42.518] <TB3> INFO: misplaced readback start: 0
[13:21:42.518] <TB3> INFO: Pixel decoding errors: 0
[13:21:42.518] <TB3> INFO: pixel data incomplete: 0
[13:21:42.518] <TB3> INFO: pixel address: 0
[13:21:42.518] <TB3> INFO: pulse height fill bit: 0
[13:21:42.518] <TB3> INFO: buffer corruption: 0
[13:21:43.332] <TB3> INFO: ######################################################################
[13:21:43.332] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[13:21:43.332] <TB3> INFO: ######################################################################
[13:21:43.659] <TB3> INFO: Expecting 41600 events.
[13:21:47.218] <TB3> INFO: 41600 events read in total (2967ms).
[13:21:47.219] <TB3> INFO: Test took 3885ms.
[13:21:47.701] <TB3> INFO: Expecting 41600 events.
[13:21:51.213] <TB3> INFO: 41600 events read in total (2920ms).
[13:21:51.214] <TB3> INFO: Test took 3792ms.
[13:21:51.505] <TB3> INFO: Expecting 41600 events.
[13:21:55.115] <TB3> INFO: 41600 events read in total (3018ms).
[13:21:55.116] <TB3> INFO: Test took 3876ms.
[13:21:55.437] <TB3> INFO: Expecting 41600 events.
[13:21:58.921] <TB3> INFO: 41600 events read in total (2892ms).
[13:21:58.922] <TB3> INFO: Test took 3778ms.
[13:21:59.213] <TB3> INFO: Expecting 41600 events.
[13:22:02.692] <TB3> INFO: 41600 events read in total (2887ms).
[13:22:02.693] <TB3> INFO: Test took 3745ms.
[13:22:02.982] <TB3> INFO: Expecting 41600 events.
[13:22:06.509] <TB3> INFO: 41600 events read in total (2936ms).
[13:22:06.510] <TB3> INFO: Test took 3793ms.
[13:22:06.799] <TB3> INFO: Expecting 41600 events.
[13:22:10.357] <TB3> INFO: 41600 events read in total (2966ms).
[13:22:10.358] <TB3> INFO: Test took 3823ms.
[13:22:10.647] <TB3> INFO: Expecting 41600 events.
[13:22:14.141] <TB3> INFO: 41600 events read in total (2902ms).
[13:22:14.142] <TB3> INFO: Test took 3760ms.
[13:22:14.431] <TB3> INFO: Expecting 41600 events.
[13:22:17.971] <TB3> INFO: 41600 events read in total (2948ms).
[13:22:17.971] <TB3> INFO: Test took 3806ms.
[13:22:18.261] <TB3> INFO: Expecting 41600 events.
[13:22:21.855] <TB3> INFO: 41600 events read in total (3002ms).
[13:22:21.856] <TB3> INFO: Test took 3860ms.
[13:22:22.146] <TB3> INFO: Expecting 41600 events.
[13:22:25.658] <TB3> INFO: 41600 events read in total (2920ms).
[13:22:25.659] <TB3> INFO: Test took 3778ms.
[13:22:25.986] <TB3> INFO: Expecting 41600 events.
[13:22:29.552] <TB3> INFO: 41600 events read in total (2974ms).
[13:22:29.553] <TB3> INFO: Test took 3870ms.
[13:22:29.844] <TB3> INFO: Expecting 41600 events.
[13:22:33.329] <TB3> INFO: 41600 events read in total (2893ms).
[13:22:33.330] <TB3> INFO: Test took 3751ms.
[13:22:33.684] <TB3> INFO: Expecting 41600 events.
[13:22:37.195] <TB3> INFO: 41600 events read in total (2919ms).
[13:22:37.196] <TB3> INFO: Test took 3842ms.
[13:22:37.485] <TB3> INFO: Expecting 41600 events.
[13:22:41.012] <TB3> INFO: 41600 events read in total (2935ms).
[13:22:41.012] <TB3> INFO: Test took 3792ms.
[13:22:41.302] <TB3> INFO: Expecting 41600 events.
[13:22:44.810] <TB3> INFO: 41600 events read in total (2917ms).
[13:22:44.811] <TB3> INFO: Test took 3774ms.
[13:22:45.101] <TB3> INFO: Expecting 41600 events.
[13:22:48.607] <TB3> INFO: 41600 events read in total (2915ms).
[13:22:48.608] <TB3> INFO: Test took 3772ms.
[13:22:48.897] <TB3> INFO: Expecting 41600 events.
[13:22:52.399] <TB3> INFO: 41600 events read in total (2910ms).
[13:22:52.400] <TB3> INFO: Test took 3768ms.
[13:22:52.689] <TB3> INFO: Expecting 41600 events.
[13:22:56.386] <TB3> INFO: 41600 events read in total (3105ms).
[13:22:56.387] <TB3> INFO: Test took 3963ms.
[13:22:56.678] <TB3> INFO: Expecting 41600 events.
[13:23:00.228] <TB3> INFO: 41600 events read in total (2958ms).
[13:23:00.229] <TB3> INFO: Test took 3816ms.
[13:23:00.534] <TB3> INFO: Expecting 41600 events.
[13:23:04.045] <TB3> INFO: 41600 events read in total (2919ms).
[13:23:04.046] <TB3> INFO: Test took 3793ms.
[13:23:04.338] <TB3> INFO: Expecting 41600 events.
[13:23:07.831] <TB3> INFO: 41600 events read in total (2902ms).
[13:23:07.832] <TB3> INFO: Test took 3760ms.
[13:23:08.121] <TB3> INFO: Expecting 41600 events.
[13:23:11.628] <TB3> INFO: 41600 events read in total (2915ms).
[13:23:11.629] <TB3> INFO: Test took 3773ms.
[13:23:11.918] <TB3> INFO: Expecting 41600 events.
[13:23:15.513] <TB3> INFO: 41600 events read in total (3003ms).
[13:23:15.514] <TB3> INFO: Test took 3860ms.
[13:23:15.805] <TB3> INFO: Expecting 41600 events.
[13:23:19.359] <TB3> INFO: 41600 events read in total (2962ms).
[13:23:19.360] <TB3> INFO: Test took 3820ms.
[13:23:19.669] <TB3> INFO: Expecting 41600 events.
[13:23:23.185] <TB3> INFO: 41600 events read in total (2924ms).
[13:23:23.186] <TB3> INFO: Test took 3802ms.
[13:23:23.477] <TB3> INFO: Expecting 41600 events.
[13:23:26.996] <TB3> INFO: 41600 events read in total (2927ms).
[13:23:26.996] <TB3> INFO: Test took 3784ms.
[13:23:27.289] <TB3> INFO: Expecting 2560 events.
[13:23:28.182] <TB3> INFO: 2560 events read in total (302ms).
[13:23:28.182] <TB3> INFO: Test took 1170ms.
[13:23:28.490] <TB3> INFO: Expecting 2560 events.
[13:23:29.385] <TB3> INFO: 2560 events read in total (303ms).
[13:23:29.385] <TB3> INFO: Test took 1202ms.
[13:23:29.692] <TB3> INFO: Expecting 2560 events.
[13:23:30.575] <TB3> INFO: 2560 events read in total (292ms).
[13:23:30.576] <TB3> INFO: Test took 1189ms.
[13:23:30.884] <TB3> INFO: Expecting 2560 events.
[13:23:31.773] <TB3> INFO: 2560 events read in total (298ms).
[13:23:31.773] <TB3> INFO: Test took 1197ms.
[13:23:32.081] <TB3> INFO: Expecting 2560 events.
[13:23:32.971] <TB3> INFO: 2560 events read in total (298ms).
[13:23:32.972] <TB3> INFO: Test took 1198ms.
[13:23:33.280] <TB3> INFO: Expecting 2560 events.
[13:23:34.160] <TB3> INFO: 2560 events read in total (289ms).
[13:23:34.160] <TB3> INFO: Test took 1188ms.
[13:23:34.468] <TB3> INFO: Expecting 2560 events.
[13:23:35.349] <TB3> INFO: 2560 events read in total (289ms).
[13:23:35.349] <TB3> INFO: Test took 1189ms.
[13:23:35.658] <TB3> INFO: Expecting 2560 events.
[13:23:36.547] <TB3> INFO: 2560 events read in total (297ms).
[13:23:36.547] <TB3> INFO: Test took 1197ms.
[13:23:36.855] <TB3> INFO: Expecting 2560 events.
[13:23:37.743] <TB3> INFO: 2560 events read in total (296ms).
[13:23:37.743] <TB3> INFO: Test took 1195ms.
[13:23:38.052] <TB3> INFO: Expecting 2560 events.
[13:23:38.936] <TB3> INFO: 2560 events read in total (293ms).
[13:23:38.936] <TB3> INFO: Test took 1193ms.
[13:23:39.243] <TB3> INFO: Expecting 2560 events.
[13:23:40.133] <TB3> INFO: 2560 events read in total (298ms).
[13:23:40.133] <TB3> INFO: Test took 1197ms.
[13:23:40.441] <TB3> INFO: Expecting 2560 events.
[13:23:41.329] <TB3> INFO: 2560 events read in total (297ms).
[13:23:41.329] <TB3> INFO: Test took 1195ms.
[13:23:41.637] <TB3> INFO: Expecting 2560 events.
[13:23:42.532] <TB3> INFO: 2560 events read in total (303ms).
[13:23:42.532] <TB3> INFO: Test took 1202ms.
[13:23:42.840] <TB3> INFO: Expecting 2560 events.
[13:23:43.730] <TB3> INFO: 2560 events read in total (299ms).
[13:23:43.731] <TB3> INFO: Test took 1199ms.
[13:23:44.039] <TB3> INFO: Expecting 2560 events.
[13:23:44.931] <TB3> INFO: 2560 events read in total (300ms).
[13:23:44.932] <TB3> INFO: Test took 1201ms.
[13:23:45.238] <TB3> INFO: Expecting 2560 events.
[13:23:46.126] <TB3> INFO: 2560 events read in total (297ms).
[13:23:46.127] <TB3> INFO: Test took 1195ms.
[13:23:46.129] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:23:46.436] <TB3> INFO: Expecting 655360 events.
[13:24:01.470] <TB3> INFO: 655360 events read in total (14443ms).
[13:24:01.482] <TB3> INFO: Expecting 655360 events.
[13:24:16.293] <TB3> INFO: 655360 events read in total (14408ms).
[13:24:16.309] <TB3> INFO: Expecting 655360 events.
[13:24:31.119] <TB3> INFO: 655360 events read in total (14407ms).
[13:24:31.145] <TB3> INFO: Expecting 655360 events.
[13:24:45.776] <TB3> INFO: 655360 events read in total (14228ms).
[13:24:45.809] <TB3> INFO: Expecting 655360 events.
[13:25:00.488] <TB3> INFO: 655360 events read in total (14276ms).
[13:25:00.518] <TB3> INFO: Expecting 655360 events.
[13:25:15.289] <TB3> INFO: 655360 events read in total (14368ms).
[13:25:15.322] <TB3> INFO: Expecting 655360 events.
[13:25:29.953] <TB3> INFO: 655360 events read in total (14228ms).
[13:25:29.002] <TB3> INFO: Expecting 655360 events.
[13:25:44.810] <TB3> INFO: 655360 events read in total (14405ms).
[13:25:44.852] <TB3> INFO: Expecting 655360 events.
[13:25:59.635] <TB3> INFO: 655360 events read in total (14380ms).
[13:25:59.687] <TB3> INFO: Expecting 655360 events.
[13:26:14.432] <TB3> INFO: 655360 events read in total (14342ms).
[13:26:14.486] <TB3> INFO: Expecting 655360 events.
[13:26:29.248] <TB3> INFO: 655360 events read in total (14359ms).
[13:26:29.451] <TB3> INFO: Expecting 655360 events.
[13:26:44.142] <TB3> INFO: 655360 events read in total (14288ms).
[13:26:44.217] <TB3> INFO: Expecting 655360 events.
[13:26:58.948] <TB3> INFO: 655360 events read in total (14328ms).
[13:26:59.028] <TB3> INFO: Expecting 655360 events.
[13:27:13.755] <TB3> INFO: 655360 events read in total (14324ms).
[13:27:13.871] <TB3> INFO: Expecting 655360 events.
[13:27:28.552] <TB3> INFO: 655360 events read in total (14278ms).
[13:27:28.689] <TB3> INFO: Expecting 655360 events.
[13:27:43.478] <TB3> INFO: 655360 events read in total (14386ms).
[13:27:43.611] <TB3> INFO: Test took 237482ms.
[13:27:43.981] <TB3> INFO: Expecting 655360 events.
[13:28:04.760] <TB3> INFO: 549970 events read in total (20187ms).
[13:28:09.011] <TB3> INFO: 655360 events read in total (24438ms).
[13:28:09.035] <TB3> INFO: Test took 25311ms.
[13:28:09.151] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.156] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:28:09.162] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[13:28:09.168] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.174] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.179] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:28:09.185] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[13:28:09.190] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[13:28:09.196] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.202] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.207] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:28:09.213] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[13:28:09.219] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[13:28:09.225] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[13:28:09.230] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.236] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.242] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.247] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:28:09.253] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.259] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:28:09.264] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[13:28:09.270] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[13:28:09.276] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[13:28:09.281] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[13:28:09.287] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[13:28:09.292] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[13:28:09.298] <TB3> INFO: safety margin for low PH: adding 8, margin is now 28
[13:28:09.304] <TB3> INFO: safety margin for low PH: adding 9, margin is now 29
[13:28:09.309] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.315] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:28:09.321] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[13:28:09.327] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[13:28:09.333] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[13:28:09.338] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[13:28:09.344] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[13:28:09.349] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[13:28:09.355] <TB3> INFO: safety margin for low PH: adding 8, margin is now 28
[13:28:09.361] <TB3> INFO: safety margin for low PH: adding 9, margin is now 29
[13:28:09.366] <TB3> INFO: safety margin for low PH: adding 10, margin is now 30
[13:28:09.372] <TB3> INFO: safety margin for low PH: adding 11, margin is now 31
[13:28:09.377] <TB3> INFO: safety margin for low PH: adding 12, margin is now 32
[13:28:09.383] <TB3> INFO: safety margin for low PH: adding 13, margin is now 33
[13:28:09.389] <TB3> INFO: safety margin for low PH: adding 14, margin is now 34
[13:28:09.395] <TB3> INFO: safety margin for low PH: adding 15, margin is now 35
[13:28:09.400] <TB3> INFO: safety margin for low PH: adding 16, margin is now 36
[13:28:09.406] <TB3> INFO: safety margin for low PH: adding 17, margin is now 37
[13:28:09.412] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.418] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:28:09.423] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.429] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.435] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.441] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:28:09.446] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[13:28:09.452] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[13:28:09.458] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[13:28:09.463] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[13:28:09.470] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[13:28:09.476] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[13:28:09.481] <TB3> INFO: safety margin for low PH: adding 8, margin is now 28
[13:28:09.487] <TB3> INFO: safety margin for low PH: adding 9, margin is now 29
[13:28:09.492] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.498] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[13:28:09.504] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[13:28:09.540] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C0.dat
[13:28:09.540] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C1.dat
[13:28:09.540] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C2.dat
[13:28:09.541] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C3.dat
[13:28:09.541] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C4.dat
[13:28:09.541] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C5.dat
[13:28:09.541] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C6.dat
[13:28:09.542] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C7.dat
[13:28:09.542] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C8.dat
[13:28:09.542] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C9.dat
[13:28:09.542] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C10.dat
[13:28:09.542] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C11.dat
[13:28:09.543] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C12.dat
[13:28:09.543] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C13.dat
[13:28:09.543] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C14.dat
[13:28:09.543] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//dacParameters35_C15.dat
[13:28:09.788] <TB3> INFO: Expecting 41600 events.
[13:28:12.907] <TB3> INFO: 41600 events read in total (2527ms).
[13:28:12.908] <TB3> INFO: Test took 3360ms.
[13:28:13.355] <TB3> INFO: Expecting 41600 events.
[13:28:16.406] <TB3> INFO: 41600 events read in total (2459ms).
[13:28:16.408] <TB3> INFO: Test took 3289ms.
[13:28:16.861] <TB3> INFO: Expecting 41600 events.
[13:28:20.004] <TB3> INFO: 41600 events read in total (2551ms).
[13:28:20.005] <TB3> INFO: Test took 3383ms.
[13:28:20.221] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:20.310] <TB3> INFO: Expecting 2560 events.
[13:28:21.207] <TB3> INFO: 2560 events read in total (305ms).
[13:28:21.208] <TB3> INFO: Test took 987ms.
[13:28:21.212] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:21.514] <TB3> INFO: Expecting 2560 events.
[13:28:22.404] <TB3> INFO: 2560 events read in total (298ms).
[13:28:22.404] <TB3> INFO: Test took 1193ms.
[13:28:22.408] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:22.712] <TB3> INFO: Expecting 2560 events.
[13:28:23.608] <TB3> INFO: 2560 events read in total (305ms).
[13:28:23.608] <TB3> INFO: Test took 1200ms.
[13:28:23.611] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:23.916] <TB3> INFO: Expecting 2560 events.
[13:28:24.811] <TB3> INFO: 2560 events read in total (303ms).
[13:28:24.811] <TB3> INFO: Test took 1200ms.
[13:28:24.814] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:25.118] <TB3> INFO: Expecting 2560 events.
[13:28:25.002] <TB3> INFO: 2560 events read in total (292ms).
[13:28:25.002] <TB3> INFO: Test took 1188ms.
[13:28:26.004] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:26.310] <TB3> INFO: Expecting 2560 events.
[13:28:27.203] <TB3> INFO: 2560 events read in total (302ms).
[13:28:27.204] <TB3> INFO: Test took 1200ms.
[13:28:27.206] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:27.510] <TB3> INFO: Expecting 2560 events.
[13:28:28.398] <TB3> INFO: 2560 events read in total (296ms).
[13:28:28.399] <TB3> INFO: Test took 1193ms.
[13:28:28.401] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:28.706] <TB3> INFO: Expecting 2560 events.
[13:28:29.596] <TB3> INFO: 2560 events read in total (299ms).
[13:28:29.596] <TB3> INFO: Test took 1195ms.
[13:28:29.599] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:29.905] <TB3> INFO: Expecting 2560 events.
[13:28:30.796] <TB3> INFO: 2560 events read in total (300ms).
[13:28:30.796] <TB3> INFO: Test took 1197ms.
[13:28:30.799] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:31.101] <TB3> INFO: Expecting 2560 events.
[13:28:31.990] <TB3> INFO: 2560 events read in total (297ms).
[13:28:31.990] <TB3> INFO: Test took 1191ms.
[13:28:31.994] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:32.296] <TB3> INFO: Expecting 2560 events.
[13:28:33.184] <TB3> INFO: 2560 events read in total (296ms).
[13:28:33.185] <TB3> INFO: Test took 1191ms.
[13:28:33.188] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:33.491] <TB3> INFO: Expecting 2560 events.
[13:28:34.376] <TB3> INFO: 2560 events read in total (293ms).
[13:28:34.377] <TB3> INFO: Test took 1189ms.
[13:28:34.379] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:34.683] <TB3> INFO: Expecting 2560 events.
[13:28:35.574] <TB3> INFO: 2560 events read in total (299ms).
[13:28:35.575] <TB3> INFO: Test took 1196ms.
[13:28:35.578] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:35.882] <TB3> INFO: Expecting 2560 events.
[13:28:36.768] <TB3> INFO: 2560 events read in total (295ms).
[13:28:36.769] <TB3> INFO: Test took 1192ms.
[13:28:36.772] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:37.077] <TB3> INFO: Expecting 2560 events.
[13:28:37.966] <TB3> INFO: 2560 events read in total (298ms).
[13:28:37.967] <TB3> INFO: Test took 1195ms.
[13:28:37.971] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:38.274] <TB3> INFO: Expecting 2560 events.
[13:28:39.163] <TB3> INFO: 2560 events read in total (298ms).
[13:28:39.164] <TB3> INFO: Test took 1193ms.
[13:28:39.166] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:39.470] <TB3> INFO: Expecting 2560 events.
[13:28:40.359] <TB3> INFO: 2560 events read in total (297ms).
[13:28:40.360] <TB3> INFO: Test took 1194ms.
[13:28:40.363] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:40.667] <TB3> INFO: Expecting 2560 events.
[13:28:41.555] <TB3> INFO: 2560 events read in total (297ms).
[13:28:41.556] <TB3> INFO: Test took 1193ms.
[13:28:41.560] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:41.863] <TB3> INFO: Expecting 2560 events.
[13:28:42.744] <TB3> INFO: 2560 events read in total (289ms).
[13:28:42.744] <TB3> INFO: Test took 1185ms.
[13:28:42.749] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:43.051] <TB3> INFO: Expecting 2560 events.
[13:28:43.936] <TB3> INFO: 2560 events read in total (293ms).
[13:28:43.936] <TB3> INFO: Test took 1188ms.
[13:28:43.939] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:44.244] <TB3> INFO: Expecting 2560 events.
[13:28:45.126] <TB3> INFO: 2560 events read in total (290ms).
[13:28:45.127] <TB3> INFO: Test took 1188ms.
[13:28:45.129] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:45.434] <TB3> INFO: Expecting 2560 events.
[13:28:46.318] <TB3> INFO: 2560 events read in total (292ms).
[13:28:46.318] <TB3> INFO: Test took 1190ms.
[13:28:46.320] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:46.626] <TB3> INFO: Expecting 2560 events.
[13:28:47.512] <TB3> INFO: 2560 events read in total (295ms).
[13:28:47.512] <TB3> INFO: Test took 1192ms.
[13:28:47.514] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:47.819] <TB3> INFO: Expecting 2560 events.
[13:28:48.705] <TB3> INFO: 2560 events read in total (294ms).
[13:28:48.706] <TB3> INFO: Test took 1192ms.
[13:28:48.709] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:49.014] <TB3> INFO: Expecting 2560 events.
[13:28:49.912] <TB3> INFO: 2560 events read in total (306ms).
[13:28:49.912] <TB3> INFO: Test took 1204ms.
[13:28:49.915] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:50.219] <TB3> INFO: Expecting 2560 events.
[13:28:51.115] <TB3> INFO: 2560 events read in total (304ms).
[13:28:51.116] <TB3> INFO: Test took 1201ms.
[13:28:51.119] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:51.422] <TB3> INFO: Expecting 2560 events.
[13:28:52.313] <TB3> INFO: 2560 events read in total (299ms).
[13:28:52.313] <TB3> INFO: Test took 1194ms.
[13:28:52.315] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:52.621] <TB3> INFO: Expecting 2560 events.
[13:28:53.514] <TB3> INFO: 2560 events read in total (301ms).
[13:28:53.515] <TB3> INFO: Test took 1200ms.
[13:28:53.517] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:53.822] <TB3> INFO: Expecting 2560 events.
[13:28:54.716] <TB3> INFO: 2560 events read in total (302ms).
[13:28:54.716] <TB3> INFO: Test took 1199ms.
[13:28:54.718] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:55.023] <TB3> INFO: Expecting 2560 events.
[13:28:55.912] <TB3> INFO: 2560 events read in total (296ms).
[13:28:55.912] <TB3> INFO: Test took 1194ms.
[13:28:55.914] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:56.220] <TB3> INFO: Expecting 2560 events.
[13:28:57.110] <TB3> INFO: 2560 events read in total (299ms).
[13:28:57.110] <TB3> INFO: Test took 1196ms.
[13:28:57.112] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:28:57.419] <TB3> INFO: Expecting 2560 events.
[13:28:58.307] <TB3> INFO: 2560 events read in total (297ms).
[13:28:58.308] <TB3> INFO: Test took 1196ms.
[13:28:58.779] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 435 seconds
[13:28:58.779] <TB3> INFO: PH scale (per ROC): 30 49 31 37 33 35 38 43 39 48 35 35 33 35 47 35
[13:28:58.779] <TB3> INFO: PH offset (per ROC): 106 110 101 83 93 100 109 85 95 113 93 110 100 102 103 102
[13:28:58.787] <TB3> INFO: Decoding statistics:
[13:28:58.787] <TB3> INFO: General information:
[13:28:58.787] <TB3> INFO: 16bit words read: 127894
[13:28:58.787] <TB3> INFO: valid events total: 20480
[13:28:58.787] <TB3> INFO: empty events: 17973
[13:28:58.787] <TB3> INFO: valid events with pixels: 2507
[13:28:58.787] <TB3> INFO: valid pixel hits: 2507
[13:28:58.787] <TB3> INFO: Event errors: 0
[13:28:58.787] <TB3> INFO: start marker: 0
[13:28:58.787] <TB3> INFO: stop marker: 0
[13:28:58.787] <TB3> INFO: overflow: 0
[13:28:58.787] <TB3> INFO: invalid 5bit words: 0
[13:28:58.787] <TB3> INFO: invalid XOR eye diagram: 0
[13:28:58.787] <TB3> INFO: frame (failed synchr.): 0
[13:28:58.787] <TB3> INFO: idle data (no TBM trl): 0
[13:28:58.787] <TB3> INFO: no data (only TBM hdr): 0
[13:28:58.787] <TB3> INFO: TBM errors: 0
[13:28:58.787] <TB3> INFO: flawed TBM headers: 0
[13:28:58.787] <TB3> INFO: flawed TBM trailers: 0
[13:28:58.787] <TB3> INFO: event ID mismatches: 0
[13:28:58.787] <TB3> INFO: ROC errors: 0
[13:28:58.787] <TB3> INFO: missing ROC header(s): 0
[13:28:58.787] <TB3> INFO: misplaced readback start: 0
[13:28:58.787] <TB3> INFO: Pixel decoding errors: 0
[13:28:58.787] <TB3> INFO: pixel data incomplete: 0
[13:28:58.787] <TB3> INFO: pixel address: 0
[13:28:58.787] <TB3> INFO: pulse height fill bit: 0
[13:28:58.787] <TB3> INFO: buffer corruption: 0
[13:28:58.950] <TB3> INFO: ######################################################################
[13:28:58.950] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[13:28:58.950] <TB3> INFO: ######################################################################
[13:28:58.964] <TB3> INFO: scanning low vcal = 10
[13:28:59.208] <TB3> INFO: Expecting 41600 events.
[13:29:02.792] <TB3> INFO: 41600 events read in total (2992ms).
[13:29:02.792] <TB3> INFO: Test took 3828ms.
[13:29:02.794] <TB3> INFO: scanning low vcal = 20
[13:29:03.090] <TB3> INFO: Expecting 41600 events.
[13:29:06.672] <TB3> INFO: 41600 events read in total (2991ms).
[13:29:06.672] <TB3> INFO: Test took 3878ms.
[13:29:06.674] <TB3> INFO: scanning low vcal = 30
[13:29:06.969] <TB3> INFO: Expecting 41600 events.
[13:29:10.639] <TB3> INFO: 41600 events read in total (3078ms).
[13:29:10.640] <TB3> INFO: Test took 3966ms.
[13:29:10.642] <TB3> INFO: scanning low vcal = 40
[13:29:10.923] <TB3> INFO: Expecting 41600 events.
[13:29:14.837] <TB3> INFO: 41600 events read in total (3322ms).
[13:29:14.838] <TB3> INFO: Test took 4195ms.
[13:29:14.841] <TB3> INFO: scanning low vcal = 50
[13:29:15.119] <TB3> INFO: Expecting 41600 events.
[13:29:19.193] <TB3> INFO: 41600 events read in total (3482ms).
[13:29:19.194] <TB3> INFO: Test took 4353ms.
[13:29:19.196] <TB3> INFO: scanning low vcal = 60
[13:29:19.481] <TB3> INFO: Expecting 41600 events.
[13:29:23.482] <TB3> INFO: 41600 events read in total (3409ms).
[13:29:23.483] <TB3> INFO: Test took 4286ms.
[13:29:23.486] <TB3> INFO: scanning low vcal = 70
[13:29:23.762] <TB3> INFO: Expecting 41600 events.
[13:29:27.768] <TB3> INFO: 41600 events read in total (3414ms).
[13:29:27.769] <TB3> INFO: Test took 4283ms.
[13:29:27.772] <TB3> INFO: scanning low vcal = 80
[13:29:28.049] <TB3> INFO: Expecting 41600 events.
[13:29:32.036] <TB3> INFO: 41600 events read in total (3395ms).
[13:29:32.037] <TB3> INFO: Test took 4265ms.
[13:29:32.041] <TB3> INFO: scanning low vcal = 90
[13:29:32.318] <TB3> INFO: Expecting 41600 events.
[13:29:36.317] <TB3> INFO: 41600 events read in total (3407ms).
[13:29:36.318] <TB3> INFO: Test took 4277ms.
[13:29:36.322] <TB3> INFO: scanning low vcal = 100
[13:29:36.598] <TB3> INFO: Expecting 41600 events.
[13:29:40.572] <TB3> INFO: 41600 events read in total (3382ms).
[13:29:40.573] <TB3> INFO: Test took 4251ms.
[13:29:40.576] <TB3> INFO: scanning low vcal = 110
[13:29:40.852] <TB3> INFO: Expecting 41600 events.
[13:29:44.801] <TB3> INFO: 41600 events read in total (3357ms).
[13:29:44.802] <TB3> INFO: Test took 4226ms.
[13:29:44.805] <TB3> INFO: scanning low vcal = 120
[13:29:45.082] <TB3> INFO: Expecting 41600 events.
[13:29:49.118] <TB3> INFO: 41600 events read in total (3445ms).
[13:29:49.119] <TB3> INFO: Test took 4314ms.
[13:29:49.122] <TB3> INFO: scanning low vcal = 130
[13:29:49.399] <TB3> INFO: Expecting 41600 events.
[13:29:53.354] <TB3> INFO: 41600 events read in total (3363ms).
[13:29:53.355] <TB3> INFO: Test took 4233ms.
[13:29:53.358] <TB3> INFO: scanning low vcal = 140
[13:29:53.635] <TB3> INFO: Expecting 41600 events.
[13:29:57.590] <TB3> INFO: 41600 events read in total (3363ms).
[13:29:57.591] <TB3> INFO: Test took 4232ms.
[13:29:57.594] <TB3> INFO: scanning low vcal = 150
[13:29:57.870] <TB3> INFO: Expecting 41600 events.
[13:30:01.879] <TB3> INFO: 41600 events read in total (3417ms).
[13:30:01.880] <TB3> INFO: Test took 4286ms.
[13:30:01.883] <TB3> INFO: scanning low vcal = 160
[13:30:02.160] <TB3> INFO: Expecting 41600 events.
[13:30:06.189] <TB3> INFO: 41600 events read in total (3437ms).
[13:30:06.190] <TB3> INFO: Test took 4307ms.
[13:30:06.193] <TB3> INFO: scanning low vcal = 170
[13:30:06.470] <TB3> INFO: Expecting 41600 events.
[13:30:10.454] <TB3> INFO: 41600 events read in total (3393ms).
[13:30:10.455] <TB3> INFO: Test took 4262ms.
[13:30:10.460] <TB3> INFO: scanning low vcal = 180
[13:30:10.734] <TB3> INFO: Expecting 41600 events.
[13:30:14.774] <TB3> INFO: 41600 events read in total (3448ms).
[13:30:14.774] <TB3> INFO: Test took 4314ms.
[13:30:14.777] <TB3> INFO: scanning low vcal = 190
[13:30:15.054] <TB3> INFO: Expecting 41600 events.
[13:30:19.109] <TB3> INFO: 41600 events read in total (3463ms).
[13:30:19.110] <TB3> INFO: Test took 4333ms.
[13:30:19.113] <TB3> INFO: scanning low vcal = 200
[13:30:19.391] <TB3> INFO: Expecting 41600 events.
[13:30:23.375] <TB3> INFO: 41600 events read in total (3392ms).
[13:30:23.376] <TB3> INFO: Test took 4264ms.
[13:30:23.380] <TB3> INFO: scanning low vcal = 210
[13:30:23.657] <TB3> INFO: Expecting 41600 events.
[13:30:27.642] <TB3> INFO: 41600 events read in total (3393ms).
[13:30:27.643] <TB3> INFO: Test took 4263ms.
[13:30:27.646] <TB3> INFO: scanning low vcal = 220
[13:30:27.923] <TB3> INFO: Expecting 41600 events.
[13:30:31.991] <TB3> INFO: 41600 events read in total (3476ms).
[13:30:31.992] <TB3> INFO: Test took 4346ms.
[13:30:31.994] <TB3> INFO: scanning low vcal = 230
[13:30:32.272] <TB3> INFO: Expecting 41600 events.
[13:30:36.256] <TB3> INFO: 41600 events read in total (3392ms).
[13:30:36.257] <TB3> INFO: Test took 4262ms.
[13:30:36.260] <TB3> INFO: scanning low vcal = 240
[13:30:36.536] <TB3> INFO: Expecting 41600 events.
[13:30:40.508] <TB3> INFO: 41600 events read in total (3381ms).
[13:30:40.509] <TB3> INFO: Test took 4249ms.
[13:30:40.512] <TB3> INFO: scanning low vcal = 250
[13:30:40.789] <TB3> INFO: Expecting 41600 events.
[13:30:44.766] <TB3> INFO: 41600 events read in total (3385ms).
[13:30:44.767] <TB3> INFO: Test took 4255ms.
[13:30:44.772] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[13:30:45.047] <TB3> INFO: Expecting 41600 events.
[13:30:49.128] <TB3> INFO: 41600 events read in total (3489ms).
[13:30:49.129] <TB3> INFO: Test took 4357ms.
[13:30:49.132] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[13:30:49.409] <TB3> INFO: Expecting 41600 events.
[13:30:53.402] <TB3> INFO: 41600 events read in total (3401ms).
[13:30:53.403] <TB3> INFO: Test took 4271ms.
[13:30:53.406] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[13:30:53.683] <TB3> INFO: Expecting 41600 events.
[13:30:57.704] <TB3> INFO: 41600 events read in total (3429ms).
[13:30:57.705] <TB3> INFO: Test took 4298ms.
[13:30:57.709] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[13:30:57.986] <TB3> INFO: Expecting 41600 events.
[13:31:02.029] <TB3> INFO: 41600 events read in total (3451ms).
[13:31:02.030] <TB3> INFO: Test took 4320ms.
[13:31:02.033] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[13:31:02.310] <TB3> INFO: Expecting 41600 events.
[13:31:06.266] <TB3> INFO: 41600 events read in total (3364ms).
[13:31:06.267] <TB3> INFO: Test took 4234ms.
[13:31:06.686] <TB3> INFO: PixTestGainPedestal::measure() done
[13:31:41.990] <TB3> INFO: PixTestGainPedestal::fit() done
[13:31:41.990] <TB3> INFO: non-linearity mean: 0.922 0.968 0.967 0.944 0.935 0.969 0.916 0.941 0.951 0.983 0.931 0.931 0.954 0.979 0.956 0.914
[13:31:41.990] <TB3> INFO: non-linearity RMS: 0.197 0.021 0.166 0.154 0.148 0.168 0.100 0.107 0.050 0.004 0.147 0.105 0.157 0.168 0.040 0.104
[13:31:41.990] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C0.dat
[13:31:42.004] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C1.dat
[13:31:42.016] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C2.dat
[13:31:42.029] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C3.dat
[13:31:42.042] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C4.dat
[13:31:42.055] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C5.dat
[13:31:42.068] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C6.dat
[13:31:42.081] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C7.dat
[13:31:42.095] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C8.dat
[13:31:42.107] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C9.dat
[13:31:42.120] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C10.dat
[13:31:42.133] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C11.dat
[13:31:42.146] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C12.dat
[13:31:42.159] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C13.dat
[13:31:42.172] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C14.dat
[13:31:42.184] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1031_FullQualification_2016-10-20_09h44m_1476949484//003_Fulltest_p17//phCalibrationFitErr35_C15.dat
[13:31:42.198] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 163 seconds
[13:31:42.198] <TB3> INFO: Decoding statistics:
[13:31:42.198] <TB3> INFO: General information:
[13:31:42.198] <TB3> INFO: 16bit words read: 3287828
[13:31:42.198] <TB3> INFO: valid events total: 332800
[13:31:42.198] <TB3> INFO: empty events: 3301
[13:31:42.198] <TB3> INFO: valid events with pixels: 329499
[13:31:42.198] <TB3> INFO: valid pixel hits: 645514
[13:31:42.198] <TB3> INFO: Event errors: 0
[13:31:42.198] <TB3> INFO: start marker: 0
[13:31:42.198] <TB3> INFO: stop marker: 0
[13:31:42.198] <TB3> INFO: overflow: 0
[13:31:42.198] <TB3> INFO: invalid 5bit words: 0
[13:31:42.198] <TB3> INFO: invalid XOR eye diagram: 0
[13:31:42.198] <TB3> INFO: frame (failed synchr.): 0
[13:31:42.198] <TB3> INFO: idle data (no TBM trl): 0
[13:31:42.198] <TB3> INFO: no data (only TBM hdr): 0
[13:31:42.198] <TB3> INFO: TBM errors: 0
[13:31:42.198] <TB3> INFO: flawed TBM headers: 0
[13:31:42.198] <TB3> INFO: flawed TBM trailers: 0
[13:31:42.198] <TB3> INFO: event ID mismatches: 0
[13:31:42.198] <TB3> INFO: ROC errors: 0
[13:31:42.198] <TB3> INFO: missing ROC header(s): 0
[13:31:42.198] <TB3> INFO: misplaced readback start: 0
[13:31:42.198] <TB3> INFO: Pixel decoding errors: 0
[13:31:42.198] <TB3> INFO: pixel data incomplete: 0
[13:31:42.198] <TB3> INFO: pixel address: 0
[13:31:42.198] <TB3> INFO: pulse height fill bit: 0
[13:31:42.198] <TB3> INFO: buffer corruption: 0
[13:31:42.216] <TB3> INFO: Decoding statistics:
[13:31:42.216] <TB3> INFO: General information:
[13:31:42.216] <TB3> INFO: 16bit words read: 3417258
[13:31:42.216] <TB3> INFO: valid events total: 353536
[13:31:42.216] <TB3> INFO: empty events: 21530
[13:31:42.216] <TB3> INFO: valid events with pixels: 332006
[13:31:42.216] <TB3> INFO: valid pixel hits: 648021
[13:31:42.216] <TB3> INFO: Event errors: 0
[13:31:42.216] <TB3> INFO: start marker: 0
[13:31:42.216] <TB3> INFO: stop marker: 0
[13:31:42.216] <TB3> INFO: overflow: 0
[13:31:42.216] <TB3> INFO: invalid 5bit words: 0
[13:31:42.216] <TB3> INFO: invalid XOR eye diagram: 0
[13:31:42.216] <TB3> INFO: frame (failed synchr.): 0
[13:31:42.216] <TB3> INFO: idle data (no TBM trl): 0
[13:31:42.216] <TB3> INFO: no data (only TBM hdr): 0
[13:31:42.216] <TB3> INFO: TBM errors: 0
[13:31:42.216] <TB3> INFO: flawed TBM headers: 0
[13:31:42.216] <TB3> INFO: flawed TBM trailers: 0
[13:31:42.216] <TB3> INFO: event ID mismatches: 0
[13:31:42.216] <TB3> INFO: ROC errors: 0
[13:31:42.216] <TB3> INFO: missing ROC header(s): 0
[13:31:42.216] <TB3> INFO: misplaced readback start: 0
[13:31:42.216] <TB3> INFO: Pixel decoding errors: 0
[13:31:42.216] <TB3> INFO: pixel data incomplete: 0
[13:31:42.216] <TB3> INFO: pixel address: 0
[13:31:42.216] <TB3> INFO: pulse height fill bit: 0
[13:31:42.216] <TB3> INFO: buffer corruption: 0
[13:31:42.216] <TB3> INFO: enter test to run
[13:31:42.216] <TB3> INFO: test: exit no parameter change
[13:31:42.351] <TB3> QUIET: Connection to board 126 closed.
[13:31:42.352] <TB3> INFO: pXar: this is the end, my friend