[17:34:22.949] <TB1> INFO: *** Welcome to pxar ***
[17:34:22.949] <TB1> INFO: *** Today: 2016/10/25
[17:34:22.956] <TB1> INFO: *** Version: c8ba-dirty
[17:34:22.956] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C15.dat
[17:34:22.956] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//tbmParameters_C1b.dat
[17:34:22.957] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//defaultMaskFile.dat
[17:34:22.957] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters_C15.dat
[17:34:23.024] <TB1> INFO: clk: 4
[17:34:23.024] <TB1> INFO: ctr: 4
[17:34:23.024] <TB1> INFO: sda: 19
[17:34:23.024] <TB1> INFO: tin: 9
[17:34:23.024] <TB1> INFO: level: 15
[17:34:23.024] <TB1> INFO: triggerdelay: 0
[17:34:23.024] <TB1> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[17:34:23.024] <TB1> INFO: Log level: INFO
[17:34:23.034] <TB1> INFO: Found DTB DTB_WXC03A
[17:34:23.045] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[17:34:23.047] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 154
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXC03A
MAC address: 40D85511809A
Hostname: pixelDTB154
Comment:
------------------------------------------------------
[17:34:23.049] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[17:34:24.577] <TB1> INFO: DUT info:
[17:34:24.577] <TB1> INFO: The DUT currently contains the following objects:
[17:34:24.577] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[17:34:24.577] <TB1> INFO: TBM Core alpha (0): 7 registers set
[17:34:24.577] <TB1> INFO: TBM Core beta (1): 7 registers set
[17:34:24.577] <TB1> INFO: TBM Core alpha (2): 7 registers set
[17:34:24.577] <TB1> INFO: TBM Core beta (3): 7 registers set
[17:34:24.577] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[17:34:24.577] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.577] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.578] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:34:24.978] <TB1> INFO: enter 'restricted' command line mode
[17:34:24.978] <TB1> INFO: enter test to run
[17:34:24.978] <TB1> INFO: test: pretest no parameter change
[17:34:24.978] <TB1> INFO: running: pretest
[17:34:24.985] <TB1> INFO: ######################################################################
[17:34:24.985] <TB1> INFO: PixTestPretest::doTest()
[17:34:24.985] <TB1> INFO: ######################################################################
[17:34:24.986] <TB1> INFO: ----------------------------------------------------------------------
[17:34:24.986] <TB1> INFO: PixTestPretest::programROC()
[17:34:24.986] <TB1> INFO: ----------------------------------------------------------------------
[17:34:42.000] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[17:34:42.000] <TB1> INFO: IA differences per ROC: 18.5 18.5 19.3 17.7 17.7 19.3 17.7 20.1 18.5 20.1 20.9 18.5 19.3 20.1 20.9 20.1
[17:34:43.070] <TB1> INFO: ----------------------------------------------------------------------
[17:34:43.070] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[17:34:43.070] <TB1> INFO: ----------------------------------------------------------------------
[17:35:04.369] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 382.7 mA = 23.9187 mA/ROC
[17:35:04.370] <TB1> INFO: i(loss) [mA/ROC]: 19.3 19.3 19.3 19.3 18.5 19.3 19.3 19.3 19.3 19.3 19.3 19.3 19.3 19.3 19.3 19.3
[17:35:04.407] <TB1> INFO: ----------------------------------------------------------------------
[17:35:04.407] <TB1> INFO: PixTestPretest::findTiming()
[17:35:04.407] <TB1> INFO: ----------------------------------------------------------------------
[17:35:04.407] <TB1> INFO: PixTestCmd::init()

[17:35:36.599] <TB1> INFO: TBM phases: 160MHz: 7, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[17:35:36.599] <TB1> INFO: (success/tries = 100/100), width = 3
[17:35:38.094] <TB1> INFO: ----------------------------------------------------------------------
[17:35:38.094] <TB1> INFO: PixTestPretest::findWorkingPixel()
[17:35:38.094] <TB1> INFO: ----------------------------------------------------------------------
[17:35:38.190] <TB1> INFO: Expecting 231680 events.
[17:35:48.056] <TB1> INFO: 231680 events read in total (9274ms).
[17:35:48.063] <TB1> INFO: Test took 9964ms.
[17:35:48.312] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[17:35:48.346] <TB1> INFO: ----------------------------------------------------------------------
[17:35:48.346] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[17:35:48.346] <TB1> INFO: ----------------------------------------------------------------------
[17:35:48.442] <TB1> INFO: Expecting 231680 events.
[17:35:58.290] <TB1> INFO: 231680 events read in total (9257ms).
[17:35:58.299] <TB1> INFO: Test took 9947ms.
[17:35:58.564] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[17:35:58.564] <TB1> INFO: CalDel: 95 92 97 94 85 84 93 101 100 91 111 90 110 97 83 114
[17:35:58.564] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 52 51 51 51 51
[17:35:58.568] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C0.dat
[17:35:58.568] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C1.dat
[17:35:58.568] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C2.dat
[17:35:58.568] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C3.dat
[17:35:58.568] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C4.dat
[17:35:58.568] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C5.dat
[17:35:58.568] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C6.dat
[17:35:58.569] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C7.dat
[17:35:58.569] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C8.dat
[17:35:58.569] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C9.dat
[17:35:58.569] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C10.dat
[17:35:58.569] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C11.dat
[17:35:58.569] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C12.dat
[17:35:58.569] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C13.dat
[17:35:58.569] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C14.dat
[17:35:58.570] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters_C15.dat
[17:35:58.570] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//tbmParameters_C0a.dat
[17:35:58.570] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//tbmParameters_C0b.dat
[17:35:58.570] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//tbmParameters_C1a.dat
[17:35:58.570] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//tbmParameters_C1b.dat
[17:35:58.570] <TB1> INFO: PixTestPretest::doTest() done, duration: 93 seconds
[17:35:58.624] <TB1> INFO: enter test to run
[17:35:58.624] <TB1> INFO: test: FullTest no parameter change
[17:35:58.624] <TB1> INFO: running: fulltest
[17:35:58.624] <TB1> INFO: ######################################################################
[17:35:58.624] <TB1> INFO: PixTestFullTest::doTest()
[17:35:58.624] <TB1> INFO: ######################################################################
[17:35:58.625] <TB1> INFO: ######################################################################
[17:35:58.625] <TB1> INFO: PixTestAlive::doTest()
[17:35:58.625] <TB1> INFO: ######################################################################
[17:35:58.626] <TB1> INFO: ----------------------------------------------------------------------
[17:35:58.626] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:35:58.626] <TB1> INFO: ----------------------------------------------------------------------
[17:35:58.866] <TB1> INFO: Expecting 41600 events.
[17:36:02.494] <TB1> INFO: 41600 events read in total (3037ms).
[17:36:02.495] <TB1> INFO: Test took 3867ms.
[17:36:02.723] <TB1> INFO: PixTestAlive::aliveTest() done
[17:36:02.723] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:36:02.724] <TB1> INFO: ----------------------------------------------------------------------
[17:36:02.724] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:36:02.725] <TB1> INFO: ----------------------------------------------------------------------
[17:36:02.964] <TB1> INFO: Expecting 41600 events.
[17:36:06.045] <TB1> INFO: 41600 events read in total (2490ms).
[17:36:06.046] <TB1> INFO: Test took 3320ms.
[17:36:06.046] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[17:36:06.277] <TB1> INFO: PixTestAlive::maskTest() done
[17:36:06.277] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:36:06.279] <TB1> INFO: ----------------------------------------------------------------------
[17:36:06.279] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:36:06.279] <TB1> INFO: ----------------------------------------------------------------------
[17:36:06.518] <TB1> INFO: Expecting 41600 events.
[17:36:10.077] <TB1> INFO: 41600 events read in total (2967ms).
[17:36:10.078] <TB1> INFO: Test took 3798ms.
[17:36:10.317] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[17:36:10.317] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:36:10.318] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[17:36:10.318] <TB1> INFO: Decoding statistics:
[17:36:10.318] <TB1> INFO: General information:
[17:36:10.318] <TB1> INFO: 16bit words read: 0
[17:36:10.318] <TB1> INFO: valid events total: 0
[17:36:10.318] <TB1> INFO: empty events: 0
[17:36:10.318] <TB1> INFO: valid events with pixels: 0
[17:36:10.318] <TB1> INFO: valid pixel hits: 0
[17:36:10.318] <TB1> INFO: Event errors: 0
[17:36:10.318] <TB1> INFO: start marker: 0
[17:36:10.318] <TB1> INFO: stop marker: 0
[17:36:10.318] <TB1> INFO: overflow: 0
[17:36:10.318] <TB1> INFO: invalid 5bit words: 0
[17:36:10.318] <TB1> INFO: invalid XOR eye diagram: 0
[17:36:10.318] <TB1> INFO: frame (failed synchr.): 0
[17:36:10.318] <TB1> INFO: idle data (no TBM trl): 0
[17:36:10.318] <TB1> INFO: no data (only TBM hdr): 0
[17:36:10.318] <TB1> INFO: TBM errors: 0
[17:36:10.318] <TB1> INFO: flawed TBM headers: 0
[17:36:10.318] <TB1> INFO: flawed TBM trailers: 0
[17:36:10.318] <TB1> INFO: event ID mismatches: 0
[17:36:10.318] <TB1> INFO: ROC errors: 0
[17:36:10.318] <TB1> INFO: missing ROC header(s): 0
[17:36:10.318] <TB1> INFO: misplaced readback start: 0
[17:36:10.318] <TB1> INFO: Pixel decoding errors: 0
[17:36:10.318] <TB1> INFO: pixel data incomplete: 0
[17:36:10.318] <TB1> INFO: pixel address: 0
[17:36:10.318] <TB1> INFO: pulse height fill bit: 0
[17:36:10.318] <TB1> INFO: buffer corruption: 0
[17:36:10.325] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C15.dat
[17:36:10.326] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr_C15.dat

[17:36:10.326] <TB1> INFO: ######################################################################
[17:36:10.326] <TB1> INFO: PixTestReadback::doTest()
[17:36:10.326] <TB1> INFO: ######################################################################
[17:36:10.326] <TB1> INFO: ----------------------------------------------------------------------
[17:36:10.326] <TB1> INFO: PixTestReadback::CalibrateVd()
[17:36:10.326] <TB1> INFO: ----------------------------------------------------------------------
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C0.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C1.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C2.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C3.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C4.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C5.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C6.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C7.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C8.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C9.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C10.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C11.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C12.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C13.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C14.dat
[17:36:20.300] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C15.dat
[17:36:20.328] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[17:36:20.328] <TB1> INFO: ----------------------------------------------------------------------
[17:36:20.328] <TB1> INFO: PixTestReadback::CalibrateVa()
[17:36:20.328] <TB1> INFO: ----------------------------------------------------------------------
[17:36:30.255] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C0.dat
[17:36:30.255] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C1.dat
[17:36:30.255] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C2.dat
[17:36:30.255] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C3.dat
[17:36:30.255] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C4.dat
[17:36:30.255] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C5.dat
[17:36:30.255] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C6.dat
[17:36:30.255] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C7.dat
[17:36:30.255] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C8.dat
[17:36:30.256] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C9.dat
[17:36:30.256] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C10.dat
[17:36:30.256] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C11.dat
[17:36:30.256] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C12.dat
[17:36:30.256] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C13.dat
[17:36:30.256] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C14.dat
[17:36:30.256] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C15.dat
[17:36:30.285] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[17:36:30.285] <TB1> INFO: ----------------------------------------------------------------------
[17:36:30.285] <TB1> INFO: PixTestReadback::readbackVbg()
[17:36:30.285] <TB1> INFO: ----------------------------------------------------------------------
[17:36:37.956] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[17:36:37.956] <TB1> INFO: ----------------------------------------------------------------------
[17:36:37.956] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[17:36:37.956] <TB1> INFO: ----------------------------------------------------------------------
[17:36:37.957] <TB1> INFO: Vbg will be calibrated using Vd calibration
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 151.2calibrated Vbg = 1.19257 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 161.4calibrated Vbg = 1.20044 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 164.6calibrated Vbg = 1.18898 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 161.9calibrated Vbg = 1.1894 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 164.5calibrated Vbg = 1.19011 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 154.9calibrated Vbg = 1.19668 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 152.3calibrated Vbg = 1.20299 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 154.3calibrated Vbg = 1.19975 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 156calibrated Vbg = 1.19196 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 154.1calibrated Vbg = 1.19011 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 144.8calibrated Vbg = 1.18819 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 152.5calibrated Vbg = 1.17704 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 155.8calibrated Vbg = 1.19579 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 156.6calibrated Vbg = 1.19747 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 157.2calibrated Vbg = 1.19516 :::*/*/*/*/
[17:36:37.957] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 157calibrated Vbg = 1.19807 :::*/*/*/*/
[17:36:37.960] <TB1> INFO: ----------------------------------------------------------------------
[17:36:37.960] <TB1> INFO: PixTestReadback::CalibrateIa()
[17:36:37.960] <TB1> INFO: ----------------------------------------------------------------------
[17:39:18.791] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C0.dat
[17:39:18.791] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C1.dat
[17:39:18.791] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C2.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C3.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C4.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C5.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C6.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C7.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C8.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C9.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C10.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C11.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C12.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C13.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C14.dat
[17:39:18.792] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//readbackCal_C15.dat
[17:39:18.822] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[17:39:18.825] <TB1> INFO: PixTestReadback::doTest() done
[17:39:18.825] <TB1> INFO: Decoding statistics:
[17:39:18.825] <TB1> INFO: General information:
[17:39:18.825] <TB1> INFO: 16bit words read: 1536
[17:39:18.825] <TB1> INFO: valid events total: 256
[17:39:18.825] <TB1> INFO: empty events: 256
[17:39:18.825] <TB1> INFO: valid events with pixels: 0
[17:39:18.825] <TB1> INFO: valid pixel hits: 0
[17:39:18.825] <TB1> INFO: Event errors: 0
[17:39:18.825] <TB1> INFO: start marker: 0
[17:39:18.825] <TB1> INFO: stop marker: 0
[17:39:18.825] <TB1> INFO: overflow: 0
[17:39:18.825] <TB1> INFO: invalid 5bit words: 0
[17:39:18.825] <TB1> INFO: invalid XOR eye diagram: 0
[17:39:18.825] <TB1> INFO: frame (failed synchr.): 0
[17:39:18.825] <TB1> INFO: idle data (no TBM trl): 0
[17:39:18.825] <TB1> INFO: no data (only TBM hdr): 0
[17:39:18.825] <TB1> INFO: TBM errors: 0
[17:39:18.825] <TB1> INFO: flawed TBM headers: 0
[17:39:18.825] <TB1> INFO: flawed TBM trailers: 0
[17:39:18.825] <TB1> INFO: event ID mismatches: 0
[17:39:18.825] <TB1> INFO: ROC errors: 0
[17:39:18.825] <TB1> INFO: missing ROC header(s): 0
[17:39:18.825] <TB1> INFO: misplaced readback start: 0
[17:39:18.825] <TB1> INFO: Pixel decoding errors: 0
[17:39:18.825] <TB1> INFO: pixel data incomplete: 0
[17:39:18.825] <TB1> INFO: pixel address: 0
[17:39:18.825] <TB1> INFO: pulse height fill bit: 0
[17:39:18.825] <TB1> INFO: buffer corruption: 0
[17:39:18.875] <TB1> INFO: ######################################################################
[17:39:18.875] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[17:39:18.875] <TB1> INFO: ######################################################################
[17:39:18.878] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[17:39:18.891] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[17:39:18.891] <TB1> INFO: run 1 of 1
[17:39:19.129] <TB1> INFO: Expecting 3120000 events.
[17:39:50.507] <TB1> INFO: 680725 events read in total (30786ms).











[17:40:21.631] <TB1> INFO: 1360050 events read in total (61910ms).











[17:40:52.606] <TB1> INFO: 2036745 events read in total (92885ms).











[17:41:23.609] <TB1> INFO: 2713065 events read in total (123888ms).











[17:41:42.155] <TB1> INFO: 3120000 events read in total (142434ms).
[17:41:42.216] <TB1> INFO: Test took 143326ms.
[17:42:06.974] <TB1> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 168 seconds
[17:42:06.974] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 1 0 1 1 1 0 0 0 0 0 0 0 0
[17:42:06.974] <TB1> INFO: separation cut (per ROC): 100 104 103 104 100 126 104 111 107 107 108 110 105 111 109 120
[17:42:06.974] <TB1> INFO: Decoding statistics:
[17:42:06.974] <TB1> INFO: General information:
[17:42:06.974] <TB1> INFO: 16bit words read: 0
[17:42:06.974] <TB1> INFO: valid events total: 0
[17:42:06.974] <TB1> INFO: empty events: 0
[17:42:06.974] <TB1> INFO: valid events with pixels: 0
[17:42:06.974] <TB1> INFO: valid pixel hits: 0
[17:42:06.974] <TB1> INFO: Event errors: 0
[17:42:06.974] <TB1> INFO: start marker: 0
[17:42:06.974] <TB1> INFO: stop marker: 0
[17:42:06.974] <TB1> INFO: overflow: 0
[17:42:06.974] <TB1> INFO: invalid 5bit words: 0
[17:42:06.974] <TB1> INFO: invalid XOR eye diagram: 0
[17:42:06.974] <TB1> INFO: frame (failed synchr.): 0
[17:42:06.974] <TB1> INFO: idle data (no TBM trl): 0
[17:42:06.974] <TB1> INFO: no data (only TBM hdr): 0
[17:42:06.974] <TB1> INFO: TBM errors: 0
[17:42:06.974] <TB1> INFO: flawed TBM headers: 0
[17:42:06.974] <TB1> INFO: flawed TBM trailers: 0
[17:42:06.974] <TB1> INFO: event ID mismatches: 0
[17:42:06.974] <TB1> INFO: ROC errors: 0
[17:42:06.974] <TB1> INFO: missing ROC header(s): 0
[17:42:06.974] <TB1> INFO: misplaced readback start: 0
[17:42:06.974] <TB1> INFO: Pixel decoding errors: 0
[17:42:06.974] <TB1> INFO: pixel data incomplete: 0
[17:42:06.975] <TB1> INFO: pixel address: 0
[17:42:06.975] <TB1> INFO: pulse height fill bit: 0
[17:42:06.975] <TB1> INFO: buffer corruption: 0
[17:42:07.016] <TB1> INFO: ######################################################################
[17:42:07.016] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[17:42:07.016] <TB1> INFO: ######################################################################
[17:42:07.016] <TB1> INFO: ----------------------------------------------------------------------
[17:42:07.016] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[17:42:07.016] <TB1> INFO: ----------------------------------------------------------------------
[17:42:07.016] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[17:42:07.031] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[17:42:07.031] <TB1> INFO: run 1 of 1
[17:42:07.309] <TB1> INFO: Expecting 36608000 events.
[17:42:31.173] <TB1> INFO: 702300 events read in total (23273ms).
[17:42:54.480] <TB1> INFO: 1388700 events read in total (46580ms).
[17:43:18.020] <TB1> INFO: 2075950 events read in total (70120ms).
[17:43:41.177] <TB1> INFO: 2762550 events read in total (93277ms).
[17:44:04.673] <TB1> INFO: 3446200 events read in total (116773ms).
[17:44:27.896] <TB1> INFO: 4127550 events read in total (139996ms).
[17:44:51.202] <TB1> INFO: 4811700 events read in total (163302ms).
[17:45:14.741] <TB1> INFO: 5497500 events read in total (186841ms).
[17:45:38.093] <TB1> INFO: 6181100 events read in total (210193ms).
[17:46:01.379] <TB1> INFO: 6863500 events read in total (233479ms).
[17:46:24.992] <TB1> INFO: 7544850 events read in total (257092ms).
[17:46:48.725] <TB1> INFO: 8225450 events read in total (280825ms).
[17:47:12.318] <TB1> INFO: 8906850 events read in total (304418ms).
[17:47:35.765] <TB1> INFO: 9589500 events read in total (327865ms).
[17:47:59.063] <TB1> INFO: 10272350 events read in total (351163ms).
[17:48:22.591] <TB1> INFO: 10954500 events read in total (374691ms).
[17:48:46.085] <TB1> INFO: 11636550 events read in total (398185ms).
[17:49:09.438] <TB1> INFO: 12317800 events read in total (421538ms).
[17:49:32.693] <TB1> INFO: 12999000 events read in total (444793ms).
[17:49:56.027] <TB1> INFO: 13680650 events read in total (468127ms).
[17:50:19.281] <TB1> INFO: 14359800 events read in total (491381ms).
[17:50:42.745] <TB1> INFO: 15039900 events read in total (514845ms).
[17:51:06.232] <TB1> INFO: 15716300 events read in total (538332ms).
[17:51:29.653] <TB1> INFO: 16393200 events read in total (561753ms).
[17:51:52.809] <TB1> INFO: 17070450 events read in total (584909ms).
[17:52:16.320] <TB1> INFO: 17747600 events read in total (608420ms).
[17:52:39.785] <TB1> INFO: 18424200 events read in total (631885ms).
[17:53:02.993] <TB1> INFO: 19100600 events read in total (655093ms).
[17:53:26.402] <TB1> INFO: 19775650 events read in total (678502ms).
[17:53:49.901] <TB1> INFO: 20449850 events read in total (702001ms).
[17:54:13.137] <TB1> INFO: 21125000 events read in total (725237ms).
[17:54:36.514] <TB1> INFO: 21797500 events read in total (748614ms).
[17:54:59.747] <TB1> INFO: 22469700 events read in total (771847ms).
[17:55:23.094] <TB1> INFO: 23141700 events read in total (795194ms).
[17:55:46.523] <TB1> INFO: 23815750 events read in total (818623ms).
[17:56:09.717] <TB1> INFO: 24487600 events read in total (841818ms).
[17:56:32.989] <TB1> INFO: 25158950 events read in total (865089ms).
[17:56:55.732] <TB1> INFO: 25831350 events read in total (887832ms).
[17:57:18.642] <TB1> INFO: 26502800 events read in total (910742ms).
[17:57:41.599] <TB1> INFO: 27175150 events read in total (933699ms).
[17:58:04.730] <TB1> INFO: 27847800 events read in total (956830ms).
[17:58:27.815] <TB1> INFO: 28518300 events read in total (979915ms).
[17:58:50.917] <TB1> INFO: 29188100 events read in total (1003017ms).
[17:59:13.672] <TB1> INFO: 29857700 events read in total (1025772ms).
[17:59:36.518] <TB1> INFO: 30526650 events read in total (1048618ms).
[17:59:59.581] <TB1> INFO: 31197850 events read in total (1071681ms).
[18:00:22.856] <TB1> INFO: 31869900 events read in total (1094956ms).
[18:00:45.672] <TB1> INFO: 32541450 events read in total (1117772ms).
[18:01:09.092] <TB1> INFO: 33213550 events read in total (1141192ms).
[18:01:31.973] <TB1> INFO: 33886850 events read in total (1164073ms).
[18:01:55.270] <TB1> INFO: 34562900 events read in total (1187370ms).
[18:02:18.251] <TB1> INFO: 35234700 events read in total (1210351ms).
[18:02:41.810] <TB1> INFO: 35905800 events read in total (1233910ms).
[18:03:05.881] <TB1> INFO: 36592200 events read in total (1257981ms).
[18:03:06.780] <TB1> INFO: 36608000 events read in total (1258880ms).
[18:03:06.862] <TB1> INFO: Test took 1259831ms.
[18:03:07.344] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:09.219] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:11.112] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:13.125] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:15.126] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:17.003] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:18.553] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:19.969] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:21.393] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:23.129] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:24.872] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:26.661] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:28.645] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:30.640] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:32.476] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:34.299] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[18:03:35.746] <TB1> INFO: PixTestScurves::scurves() done
[18:03:35.746] <TB1> INFO: Vcal mean: 119.25 122.61 116.00 123.66 112.07 130.78 120.69 122.38 121.46 133.57 123.39 132.97 123.59 114.72 122.66 128.85
[18:03:35.746] <TB1> INFO: Vcal RMS: 5.43 6.32 5.50 6.32 4.69 5.28 5.70 6.00 5.95 6.19 6.12 6.26 6.43 4.96 5.94 6.21
[18:03:35.746] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1288 seconds
[18:03:35.746] <TB1> INFO: Decoding statistics:
[18:03:35.746] <TB1> INFO: General information:
[18:03:35.746] <TB1> INFO: 16bit words read: 0
[18:03:35.746] <TB1> INFO: valid events total: 0
[18:03:35.746] <TB1> INFO: empty events: 0
[18:03:35.746] <TB1> INFO: valid events with pixels: 0
[18:03:35.746] <TB1> INFO: valid pixel hits: 0
[18:03:35.746] <TB1> INFO: Event errors: 0
[18:03:35.746] <TB1> INFO: start marker: 0
[18:03:35.746] <TB1> INFO: stop marker: 0
[18:03:35.746] <TB1> INFO: overflow: 0
[18:03:35.746] <TB1> INFO: invalid 5bit words: 0
[18:03:35.746] <TB1> INFO: invalid XOR eye diagram: 0
[18:03:35.746] <TB1> INFO: frame (failed synchr.): 0
[18:03:35.746] <TB1> INFO: idle data (no TBM trl): 0
[18:03:35.746] <TB1> INFO: no data (only TBM hdr): 0
[18:03:35.746] <TB1> INFO: TBM errors: 0
[18:03:35.747] <TB1> INFO: flawed TBM headers: 0
[18:03:35.747] <TB1> INFO: flawed TBM trailers: 0
[18:03:35.747] <TB1> INFO: event ID mismatches: 0
[18:03:35.747] <TB1> INFO: ROC errors: 0
[18:03:35.747] <TB1> INFO: missing ROC header(s): 0
[18:03:35.747] <TB1> INFO: misplaced readback start: 0
[18:03:35.747] <TB1> INFO: Pixel decoding errors: 0
[18:03:35.747] <TB1> INFO: pixel data incomplete: 0
[18:03:35.747] <TB1> INFO: pixel address: 0
[18:03:35.747] <TB1> INFO: pulse height fill bit: 0
[18:03:35.747] <TB1> INFO: buffer corruption: 0
[18:03:35.812] <TB1> INFO: ######################################################################
[18:03:35.812] <TB1> INFO: PixTestTrim::doTest()
[18:03:35.812] <TB1> INFO: ######################################################################
[18:03:35.813] <TB1> INFO: ----------------------------------------------------------------------
[18:03:35.813] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[18:03:35.813] <TB1> INFO: ----------------------------------------------------------------------
[18:03:35.854] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[18:03:35.854] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[18:03:35.867] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:03:35.867] <TB1> INFO: run 1 of 1
[18:03:36.105] <TB1> INFO: Expecting 5025280 events.
[18:04:06.777] <TB1> INFO: 831832 events read in total (30076ms).
[18:04:37.145] <TB1> INFO: 1660352 events read in total (60445ms).
[18:05:07.374] <TB1> INFO: 2486752 events read in total (90674ms).
[18:05:37.243] <TB1> INFO: 3308528 events read in total (120542ms).
[18:06:06.999] <TB1> INFO: 4125504 events read in total (150299ms).
[18:06:37.158] <TB1> INFO: 4942312 events read in total (180457ms).
[18:06:40.615] <TB1> INFO: 5025280 events read in total (183914ms).
[18:06:40.665] <TB1> INFO: Test took 184797ms.
[18:06:58.458] <TB1> INFO: ROC 0 VthrComp = 116
[18:06:58.459] <TB1> INFO: ROC 1 VthrComp = 122
[18:06:58.459] <TB1> INFO: ROC 2 VthrComp = 115
[18:06:58.459] <TB1> INFO: ROC 3 VthrComp = 116
[18:06:58.459] <TB1> INFO: ROC 4 VthrComp = 109
[18:06:58.459] <TB1> INFO: ROC 5 VthrComp = 131
[18:06:58.459] <TB1> INFO: ROC 6 VthrComp = 114
[18:06:58.459] <TB1> INFO: ROC 7 VthrComp = 121
[18:06:58.459] <TB1> INFO: ROC 8 VthrComp = 114
[18:06:58.460] <TB1> INFO: ROC 9 VthrComp = 123
[18:06:58.461] <TB1> INFO: ROC 10 VthrComp = 119
[18:06:58.461] <TB1> INFO: ROC 11 VthrComp = 129
[18:06:58.461] <TB1> INFO: ROC 12 VthrComp = 124
[18:06:58.461] <TB1> INFO: ROC 13 VthrComp = 124
[18:06:58.461] <TB1> INFO: ROC 14 VthrComp = 125
[18:06:58.461] <TB1> INFO: ROC 15 VthrComp = 123
[18:06:58.723] <TB1> INFO: Expecting 41600 events.
[18:07:02.225] <TB1> INFO: 41600 events read in total (2910ms).
[18:07:02.226] <TB1> INFO: Test took 3763ms.
[18:07:02.235] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[18:07:02.235] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[18:07:02.247] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:07:02.247] <TB1> INFO: run 1 of 1
[18:07:02.525] <TB1> INFO: Expecting 5025280 events.
[18:07:29.144] <TB1> INFO: 591896 events read in total (26027ms).
[18:07:54.978] <TB1> INFO: 1182152 events read in total (51861ms).
[18:08:21.228] <TB1> INFO: 1772696 events read in total (78111ms).
[18:08:47.128] <TB1> INFO: 2361968 events read in total (104011ms).
[18:09:12.002] <TB1> INFO: 2949320 events read in total (129885ms).
[18:09:38.737] <TB1> INFO: 3534944 events read in total (155621ms).
[18:10:04.492] <TB1> INFO: 4119360 events read in total (181375ms).
[18:10:30.316] <TB1> INFO: 4704360 events read in total (207199ms).
[18:10:44.721] <TB1> INFO: 5025280 events read in total (221604ms).
[18:10:44.800] <TB1> INFO: Test took 222552ms.
[18:11:10.357] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 59.7367 for pixel 0/1 mean/min/max = 46.3779/32.9715/59.7843
[18:11:10.357] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 61.0528 for pixel 6/60 mean/min/max = 46.7213/32.385/61.0576
[18:11:10.357] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 59.7746 for pixel 15/3 mean/min/max = 46.1084/32.3822/59.8346
[18:11:10.358] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 62.2835 for pixel 3/8 mean/min/max = 47.6738/33.0023/62.3452
[18:11:10.358] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 61.1352 for pixel 21/6 mean/min/max = 48.0375/34.893/61.182
[18:11:10.359] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 60.3829 for pixel 1/6 mean/min/max = 46.4814/32.563/60.3997
[18:11:10.359] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 61.7087 for pixel 23/3 mean/min/max = 47.5106/33.2649/61.7563
[18:11:10.360] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 60.943 for pixel 5/6 mean/min/max = 46.9394/32.6721/61.2068
[18:11:10.360] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 63.0987 for pixel 1/19 mean/min/max = 47.9556/32.6203/63.291
[18:11:10.360] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 64.6976 for pixel 20/0 mean/min/max = 48.5614/31.9891/65.1337
[18:11:10.361] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 60.2163 for pixel 0/1 mean/min/max = 45.8971/31.4455/60.3488
[18:11:10.361] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 62.32 for pixel 2/1 mean/min/max = 47.9135/33.4439/62.3831
[18:11:10.362] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 59.3918 for pixel 3/76 mean/min/max = 45.7152/31.8715/59.5589
[18:11:10.362] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 57.8254 for pixel 6/78 mean/min/max = 45.2908/32.6197/57.962
[18:11:10.363] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 59.8125 for pixel 6/5 mean/min/max = 46.2104/32.455/59.9659
[18:11:10.363] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 62.8035 for pixel 20/1 mean/min/max = 47.0375/31.205/62.87
[18:11:10.364] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:11:10.453] <TB1> INFO: Expecting 411648 events.
[18:11:19.922] <TB1> INFO: 411648 events read in total (8877ms).
[18:11:19.931] <TB1> INFO: Expecting 411648 events.
[18:11:29.175] <TB1> INFO: 411648 events read in total (8840ms).
[18:11:29.185] <TB1> INFO: Expecting 411648 events.
[18:11:38.524] <TB1> INFO: 411648 events read in total (8936ms).
[18:11:38.541] <TB1> INFO: Expecting 411648 events.
[18:11:47.754] <TB1> INFO: 411648 events read in total (8810ms).
[18:11:47.769] <TB1> INFO: Expecting 411648 events.
[18:11:57.128] <TB1> INFO: 411648 events read in total (8956ms).
[18:11:57.147] <TB1> INFO: Expecting 411648 events.
[18:12:06.449] <TB1> INFO: 411648 events read in total (8899ms).
[18:12:06.470] <TB1> INFO: Expecting 411648 events.
[18:12:15.775] <TB1> INFO: 411648 events read in total (8902ms).
[18:12:15.799] <TB1> INFO: Expecting 411648 events.
[18:12:25.109] <TB1> INFO: 411648 events read in total (8907ms).
[18:12:25.142] <TB1> INFO: Expecting 411648 events.
[18:12:34.365] <TB1> INFO: 411648 events read in total (8820ms).
[18:12:34.394] <TB1> INFO: Expecting 411648 events.
[18:12:43.723] <TB1> INFO: 411648 events read in total (8926ms).
[18:12:43.755] <TB1> INFO: Expecting 411648 events.
[18:12:53.066] <TB1> INFO: 411648 events read in total (8908ms).
[18:12:53.100] <TB1> INFO: Expecting 411648 events.
[18:13:02.478] <TB1> INFO: 411648 events read in total (8975ms).
[18:13:02.526] <TB1> INFO: Expecting 411648 events.
[18:13:11.726] <TB1> INFO: 411648 events read in total (8797ms).
[18:13:11.765] <TB1> INFO: Expecting 411648 events.
[18:13:20.976] <TB1> INFO: 411648 events read in total (8808ms).
[18:13:21.031] <TB1> INFO: Expecting 411648 events.
[18:13:30.545] <TB1> INFO: 411648 events read in total (9111ms).
[18:13:30.595] <TB1> INFO: Expecting 411648 events.
[18:13:39.840] <TB1> INFO: 411648 events read in total (8842ms).
[18:13:39.902] <TB1> INFO: Test took 149538ms.
[18:13:40.588] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[18:13:40.602] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:13:40.603] <TB1> INFO: run 1 of 1
[18:13:40.878] <TB1> INFO: Expecting 5025280 events.
[18:14:07.347] <TB1> INFO: 588568 events read in total (25878ms).
[18:14:33.369] <TB1> INFO: 1174464 events read in total (51900ms).
[18:14:59.339] <TB1> INFO: 1761864 events read in total (77871ms).
[18:15:25.633] <TB1> INFO: 2348488 events read in total (104164ms).
[18:15:51.860] <TB1> INFO: 2936504 events read in total (130391ms).
[18:16:18.128] <TB1> INFO: 3524992 events read in total (156659ms).
[18:16:44.491] <TB1> INFO: 4114920 events read in total (183022ms).
[18:17:10.783] <TB1> INFO: 4703576 events read in total (209314ms).
[18:17:25.232] <TB1> INFO: 5025280 events read in total (223763ms).
[18:17:25.402] <TB1> INFO: Test took 224801ms.
[18:17:47.664] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 9.545395 .. 144.685423
[18:17:47.902] <TB1> INFO: Expecting 208000 events.
[18:17:57.504] <TB1> INFO: 208000 events read in total (9011ms).
[18:17:57.505] <TB1> INFO: Test took 9839ms.
[18:17:57.558] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 9 .. 154 (-1/-1) hits flags = 528 (plus default)
[18:17:57.571] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:17:57.571] <TB1> INFO: run 1 of 1
[18:17:57.849] <TB1> INFO: Expecting 4858880 events.
[18:18:24.097] <TB1> INFO: 574576 events read in total (25656ms).
[18:18:49.544] <TB1> INFO: 1149008 events read in total (51105ms).
[18:19:15.252] <TB1> INFO: 1723368 events read in total (76812ms).
[18:19:41.065] <TB1> INFO: 2297944 events read in total (102624ms).
[18:20:06.691] <TB1> INFO: 2871944 events read in total (128250ms).
[18:20:32.365] <TB1> INFO: 3445688 events read in total (153924ms).
[18:20:58.238] <TB1> INFO: 4018944 events read in total (179797ms).
[18:21:23.775] <TB1> INFO: 4592352 events read in total (205334ms).
[18:21:36.096] <TB1> INFO: 4858880 events read in total (217656ms).
[18:21:36.223] <TB1> INFO: Test took 218653ms.
[18:22:00.727] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 27.870228 .. 46.909445
[18:22:00.965] <TB1> INFO: Expecting 208000 events.
[18:22:10.583] <TB1> INFO: 208000 events read in total (9026ms).
[18:22:10.584] <TB1> INFO: Test took 9855ms.
[18:22:10.632] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 56 (-1/-1) hits flags = 528 (plus default)
[18:22:10.645] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:22:10.645] <TB1> INFO: run 1 of 1
[18:22:10.923] <TB1> INFO: Expecting 1331200 events.
[18:22:39.121] <TB1> INFO: 656248 events read in total (27606ms).
[18:23:06.813] <TB1> INFO: 1311240 events read in total (55299ms).
[18:23:08.110] <TB1> INFO: 1331200 events read in total (56596ms).
[18:23:08.156] <TB1> INFO: Test took 57512ms.
[18:23:23.300] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 26.372871 .. 49.811829
[18:23:23.574] <TB1> INFO: Expecting 208000 events.
[18:23:33.541] <TB1> INFO: 208000 events read in total (9375ms).
[18:23:33.542] <TB1> INFO: Test took 10240ms.
[18:23:33.599] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 59 (-1/-1) hits flags = 528 (plus default)
[18:23:33.613] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:23:33.613] <TB1> INFO: run 1 of 1
[18:23:33.891] <TB1> INFO: Expecting 1464320 events.
[18:24:02.042] <TB1> INFO: 650312 events read in total (27560ms).
[18:24:29.885] <TB1> INFO: 1298720 events read in total (55404ms).
[18:24:37.120] <TB1> INFO: 1464320 events read in total (62638ms).
[18:24:37.162] <TB1> INFO: Test took 63550ms.
[18:24:51.695] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 23.609190 .. 49.301352
[18:24:51.932] <TB1> INFO: Expecting 208000 events.
[18:25:01.728] <TB1> INFO: 208000 events read in total (9204ms).
[18:25:01.729] <TB1> INFO: Test took 10033ms.
[18:25:01.777] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 13 .. 59 (-1/-1) hits flags = 528 (plus default)
[18:25:01.790] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:25:01.790] <TB1> INFO: run 1 of 1
[18:25:02.068] <TB1> INFO: Expecting 1564160 events.
[18:25:30.251] <TB1> INFO: 661200 events read in total (27591ms).
[18:25:57.808] <TB1> INFO: 1321544 events read in total (55148ms).
[18:26:08.063] <TB1> INFO: 1564160 events read in total (65403ms).
[18:26:08.106] <TB1> INFO: Test took 66317ms.
[18:26:21.958] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[18:26:21.958] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[18:26:21.972] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[18:26:21.972] <TB1> INFO: run 1 of 1
[18:26:22.209] <TB1> INFO: Expecting 1364480 events.
[18:26:50.751] <TB1> INFO: 669448 events read in total (27950ms).
[18:27:19.067] <TB1> INFO: 1337320 events read in total (56266ms).
[18:27:20.610] <TB1> INFO: 1364480 events read in total (57809ms).
[18:27:20.644] <TB1> INFO: Test took 58673ms.
[18:27:35.813] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C0.dat
[18:27:35.813] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C1.dat
[18:27:35.813] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C2.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C3.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C4.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C5.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C6.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C7.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C8.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C9.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C10.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C11.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C12.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C13.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C14.dat
[18:27:35.814] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C15.dat
[18:27:35.815] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C0.dat
[18:27:35.820] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C1.dat
[18:27:35.825] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C2.dat
[18:27:35.832] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C3.dat
[18:27:35.838] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C4.dat
[18:27:35.845] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C5.dat
[18:27:35.852] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C6.dat
[18:27:35.857] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C7.dat
[18:27:35.863] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C8.dat
[18:27:35.870] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C9.dat
[18:27:35.876] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C10.dat
[18:27:35.883] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C11.dat
[18:27:35.889] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C12.dat
[18:27:35.895] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C13.dat
[18:27:35.902] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C14.dat
[18:27:35.908] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//trimParameters35_C15.dat
[18:27:35.914] <TB1> INFO: PixTestTrim::trimTest() done
[18:27:35.914] <TB1> INFO: vtrim: 130 120 125 115 118 133 123 121 143 148 111 125 114 118 123 129
[18:27:35.914] <TB1> INFO: vthrcomp: 116 122 115 116 109 131 114 121 114 123 119 129 124 124 125 123
[18:27:35.914] <TB1> INFO: vcal mean: 35.02 35.16 35.06 35.35 35.15 35.06 35.24 35.21 35.45 35.92 34.99 35.38 35.04 35.03 35.05 35.09
[18:27:35.914] <TB1> INFO: vcal RMS: 1.05 1.16 0.99 1.39 1.03 1.02 1.25 1.20 1.51 2.08 1.15 1.48 1.10 0.96 1.10 1.25
[18:27:35.914] <TB1> INFO: bits mean: 9.08 9.21 9.53 9.15 8.86 9.13 9.09 9.05 9.46 9.74 9.53 9.22 9.57 9.50 9.24 9.81
[18:27:35.914] <TB1> INFO: bits RMS: 2.78 2.83 2.65 2.71 2.49 2.80 2.73 2.82 2.64 2.71 2.75 2.66 2.75 2.69 2.82 2.67
[18:27:35.922] <TB1> INFO: ----------------------------------------------------------------------
[18:27:35.922] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[18:27:35.922] <TB1> INFO: ----------------------------------------------------------------------
[18:27:35.925] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[18:27:35.940] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:27:35.940] <TB1> INFO: run 1 of 1
[18:27:36.187] <TB1> INFO: Expecting 4160000 events.
[18:28:09.257] <TB1> INFO: 774255 events read in total (32479ms).
[18:28:41.536] <TB1> INFO: 1541010 events read in total (64758ms).
[18:29:13.707] <TB1> INFO: 2301490 events read in total (96929ms).
[18:29:45.637] <TB1> INFO: 3057470 events read in total (128859ms).
[18:30:17.918] <TB1> INFO: 3809945 events read in total (161140ms).
[18:30:32.799] <TB1> INFO: 4160000 events read in total (176021ms).
[18:30:32.870] <TB1> INFO: Test took 176930ms.
[18:31:02.720] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 209 (-1/-1) hits flags = 528 (plus default)
[18:31:02.734] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:31:02.734] <TB1> INFO: run 1 of 1
[18:31:02.985] <TB1> INFO: Expecting 4368000 events.
[18:31:35.335] <TB1> INFO: 733015 events read in total (31759ms).
[18:32:07.081] <TB1> INFO: 1460415 events read in total (63505ms).
[18:32:38.639] <TB1> INFO: 2184365 events read in total (95063ms).
[18:33:10.287] <TB1> INFO: 2904195 events read in total (126711ms).
[18:33:42.020] <TB1> INFO: 3620885 events read in total (158444ms).
[18:34:13.852] <TB1> INFO: 4339580 events read in total (190276ms).
[18:34:15.447] <TB1> INFO: 4368000 events read in total (191871ms).
[18:34:15.523] <TB1> INFO: Test took 192789ms.
[18:34:42.481] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[18:34:42.493] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:34:42.493] <TB1> INFO: run 1 of 1
[18:34:42.733] <TB1> INFO: Expecting 4139200 events.
[18:35:15.688] <TB1> INFO: 748350 events read in total (32363ms).
[18:35:47.560] <TB1> INFO: 1491170 events read in total (64235ms).
[18:36:19.372] <TB1> INFO: 2229580 events read in total (96047ms).
[18:36:51.132] <TB1> INFO: 2962435 events read in total (127807ms).
[18:37:22.297] <TB1> INFO: 3692395 events read in total (158972ms).
[18:37:41.707] <TB1> INFO: 4139200 events read in total (178382ms).
[18:37:41.776] <TB1> INFO: Test took 179282ms.
[18:38:06.794] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 197 (-1/-1) hits flags = 528 (plus default)
[18:38:06.810] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:38:06.811] <TB1> INFO: run 1 of 1
[18:38:07.046] <TB1> INFO: Expecting 4118400 events.
[18:38:39.918] <TB1> INFO: 750380 events read in total (32280ms).
[18:39:11.978] <TB1> INFO: 1494465 events read in total (64340ms).
[18:39:43.385] <TB1> INFO: 2233500 events read in total (95747ms).
[18:40:14.758] <TB1> INFO: 2968130 events read in total (127120ms).
[18:40:46.085] <TB1> INFO: 3699980 events read in total (158447ms).
[18:41:04.264] <TB1> INFO: 4118400 events read in total (176626ms).
[18:41:04.338] <TB1> INFO: Test took 177527ms.
[18:41:27.585] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 196 (-1/-1) hits flags = 528 (plus default)
[18:41:27.599] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[18:41:27.599] <TB1> INFO: run 1 of 1
[18:41:27.850] <TB1> INFO: Expecting 4097600 events.
[18:42:00.431] <TB1> INFO: 752435 events read in total (31989ms).
[18:42:33.610] <TB1> INFO: 1498640 events read in total (65168ms).
[18:43:05.773] <TB1> INFO: 2240130 events read in total (97331ms).
[18:43:37.393] <TB1> INFO: 2976390 events read in total (128951ms).
[18:44:08.835] <TB1> INFO: 3710160 events read in total (160393ms).
[18:44:25.540] <TB1> INFO: 4097600 events read in total (177098ms).
[18:44:25.610] <TB1> INFO: Test took 178011ms.
[18:44:51.621] <TB1> INFO: PixTestTrim::trimBitTest() done
[18:44:51.622] <TB1> INFO: PixTestTrim::doTest() done, duration: 2475 seconds
[18:44:51.622] <TB1> INFO: Decoding statistics:
[18:44:51.622] <TB1> INFO: General information:
[18:44:51.622] <TB1> INFO: 16bit words read: 0
[18:44:51.622] <TB1> INFO: valid events total: 0
[18:44:51.622] <TB1> INFO: empty events: 0
[18:44:51.622] <TB1> INFO: valid events with pixels: 0
[18:44:51.622] <TB1> INFO: valid pixel hits: 0
[18:44:51.622] <TB1> INFO: Event errors: 0
[18:44:51.622] <TB1> INFO: start marker: 0
[18:44:51.622] <TB1> INFO: stop marker: 0
[18:44:51.622] <TB1> INFO: overflow: 0
[18:44:51.622] <TB1> INFO: invalid 5bit words: 0
[18:44:51.622] <TB1> INFO: invalid XOR eye diagram: 0
[18:44:51.622] <TB1> INFO: frame (failed synchr.): 0
[18:44:51.622] <TB1> INFO: idle data (no TBM trl): 0
[18:44:51.622] <TB1> INFO: no data (only TBM hdr): 0
[18:44:51.622] <TB1> INFO: TBM errors: 0
[18:44:51.622] <TB1> INFO: flawed TBM headers: 0
[18:44:51.622] <TB1> INFO: flawed TBM trailers: 0
[18:44:51.622] <TB1> INFO: event ID mismatches: 0
[18:44:51.622] <TB1> INFO: ROC errors: 0
[18:44:51.622] <TB1> INFO: missing ROC header(s): 0
[18:44:51.622] <TB1> INFO: misplaced readback start: 0
[18:44:51.622] <TB1> INFO: Pixel decoding errors: 0
[18:44:51.622] <TB1> INFO: pixel data incomplete: 0
[18:44:51.622] <TB1> INFO: pixel address: 0
[18:44:51.622] <TB1> INFO: pulse height fill bit: 0
[18:44:51.622] <TB1> INFO: buffer corruption: 0
[18:44:52.230] <TB1> INFO: ######################################################################
[18:44:52.230] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[18:44:52.230] <TB1> INFO: ######################################################################
[18:44:52.468] <TB1> INFO: Expecting 41600 events.
[18:44:55.999] <TB1> INFO: 41600 events read in total (2940ms).
[18:44:55.000] <TB1> INFO: Test took 3769ms.
[18:44:56.446] <TB1> INFO: Expecting 41600 events.
[18:44:59.983] <TB1> INFO: 41600 events read in total (2945ms).
[18:44:59.984] <TB1> INFO: Test took 3780ms.
[18:45:00.273] <TB1> INFO: Expecting 41600 events.
[18:45:03.785] <TB1> INFO: 41600 events read in total (2921ms).
[18:45:03.786] <TB1> INFO: Test took 3778ms.
[18:45:04.076] <TB1> INFO: Expecting 41600 events.
[18:45:07.555] <TB1> INFO: 41600 events read in total (2887ms).
[18:45:07.555] <TB1> INFO: Test took 3744ms.
[18:45:07.848] <TB1> INFO: Expecting 41600 events.
[18:45:11.416] <TB1> INFO: 41600 events read in total (2976ms).
[18:45:11.417] <TB1> INFO: Test took 3837ms.
[18:45:11.706] <TB1> INFO: Expecting 41600 events.
[18:45:15.192] <TB1> INFO: 41600 events read in total (2894ms).
[18:45:15.193] <TB1> INFO: Test took 3751ms.
[18:45:15.483] <TB1> INFO: Expecting 41600 events.
[18:45:19.003] <TB1> INFO: 41600 events read in total (2928ms).
[18:45:19.004] <TB1> INFO: Test took 3786ms.
[18:45:19.294] <TB1> INFO: Expecting 41600 events.
[18:45:22.843] <TB1> INFO: 41600 events read in total (2957ms).
[18:45:22.844] <TB1> INFO: Test took 3815ms.
[18:45:23.133] <TB1> INFO: Expecting 41600 events.
[18:45:26.720] <TB1> INFO: 41600 events read in total (2995ms).
[18:45:26.721] <TB1> INFO: Test took 3854ms.
[18:45:27.011] <TB1> INFO: Expecting 41600 events.
[18:45:30.590] <TB1> INFO: 41600 events read in total (2988ms).
[18:45:30.591] <TB1> INFO: Test took 3845ms.
[18:45:30.914] <TB1> INFO: Expecting 41600 events.
[18:45:34.417] <TB1> INFO: 41600 events read in total (2912ms).
[18:45:34.418] <TB1> INFO: Test took 3799ms.
[18:45:34.709] <TB1> INFO: Expecting 41600 events.
[18:45:38.298] <TB1> INFO: 41600 events read in total (2998ms).
[18:45:38.299] <TB1> INFO: Test took 3856ms.
[18:45:38.589] <TB1> INFO: Expecting 41600 events.
[18:45:42.185] <TB1> INFO: 41600 events read in total (3005ms).
[18:45:42.186] <TB1> INFO: Test took 3862ms.
[18:45:42.476] <TB1> INFO: Expecting 41600 events.
[18:45:46.080] <TB1> INFO: 41600 events read in total (3013ms).
[18:45:46.081] <TB1> INFO: Test took 3871ms.
[18:45:46.370] <TB1> INFO: Expecting 41600 events.
[18:45:50.005] <TB1> INFO: 41600 events read in total (3043ms).
[18:45:50.006] <TB1> INFO: Test took 3901ms.
[18:45:50.296] <TB1> INFO: Expecting 41600 events.
[18:45:53.945] <TB1> INFO: 41600 events read in total (3057ms).
[18:45:53.946] <TB1> INFO: Test took 3915ms.
[18:45:54.275] <TB1> INFO: Expecting 41600 events.
[18:45:57.882] <TB1> INFO: 41600 events read in total (3016ms).
[18:45:57.883] <TB1> INFO: Test took 3908ms.
[18:45:58.174] <TB1> INFO: Expecting 41600 events.
[18:46:01.784] <TB1> INFO: 41600 events read in total (3018ms).
[18:46:01.785] <TB1> INFO: Test took 3875ms.
[18:46:02.094] <TB1> INFO: Expecting 41600 events.
[18:46:05.892] <TB1> INFO: 41600 events read in total (3206ms).
[18:46:05.892] <TB1> INFO: Test took 4079ms.
[18:46:06.202] <TB1> INFO: Expecting 41600 events.
[18:46:09.800] <TB1> INFO: 41600 events read in total (3007ms).
[18:46:09.801] <TB1> INFO: Test took 3882ms.
[18:46:10.091] <TB1> INFO: Expecting 41600 events.
[18:46:13.659] <TB1> INFO: 41600 events read in total (2976ms).
[18:46:13.660] <TB1> INFO: Test took 3834ms.
[18:46:13.951] <TB1> INFO: Expecting 41600 events.
[18:46:17.436] <TB1> INFO: 41600 events read in total (2893ms).
[18:46:17.437] <TB1> INFO: Test took 3750ms.
[18:46:17.726] <TB1> INFO: Expecting 41600 events.
[18:46:21.207] <TB1> INFO: 41600 events read in total (2888ms).
[18:46:21.207] <TB1> INFO: Test took 3746ms.
[18:46:21.499] <TB1> INFO: Expecting 41600 events.
[18:46:25.087] <TB1> INFO: 41600 events read in total (2997ms).
[18:46:25.088] <TB1> INFO: Test took 3854ms.
[18:46:25.378] <TB1> INFO: Expecting 41600 events.
[18:46:28.980] <TB1> INFO: 41600 events read in total (3011ms).
[18:46:28.981] <TB1> INFO: Test took 3868ms.
[18:46:29.271] <TB1> INFO: Expecting 41600 events.
[18:46:32.794] <TB1> INFO: 41600 events read in total (2931ms).
[18:46:32.794] <TB1> INFO: Test took 3788ms.
[18:46:33.086] <TB1> INFO: Expecting 41600 events.
[18:46:36.576] <TB1> INFO: 41600 events read in total (2898ms).
[18:46:36.577] <TB1> INFO: Test took 3755ms.
[18:46:36.872] <TB1> INFO: Expecting 41600 events.
[18:46:40.344] <TB1> INFO: 41600 events read in total (2880ms).
[18:46:40.345] <TB1> INFO: Test took 3737ms.
[18:46:40.638] <TB1> INFO: Expecting 2560 events.
[18:46:41.524] <TB1> INFO: 2560 events read in total (295ms).
[18:46:41.525] <TB1> INFO: Test took 1164ms.
[18:46:41.832] <TB1> INFO: Expecting 2560 events.
[18:46:42.716] <TB1> INFO: 2560 events read in total (293ms).
[18:46:42.716] <TB1> INFO: Test took 1191ms.
[18:46:43.024] <TB1> INFO: Expecting 2560 events.
[18:46:43.907] <TB1> INFO: 2560 events read in total (292ms).
[18:46:43.907] <TB1> INFO: Test took 1191ms.
[18:46:44.214] <TB1> INFO: Expecting 2560 events.
[18:46:45.104] <TB1> INFO: 2560 events read in total (298ms).
[18:46:45.105] <TB1> INFO: Test took 1198ms.
[18:46:45.413] <TB1> INFO: Expecting 2560 events.
[18:46:46.295] <TB1> INFO: 2560 events read in total (291ms).
[18:46:46.295] <TB1> INFO: Test took 1189ms.
[18:46:46.603] <TB1> INFO: Expecting 2560 events.
[18:46:47.482] <TB1> INFO: 2560 events read in total (288ms).
[18:46:47.482] <TB1> INFO: Test took 1186ms.
[18:46:47.790] <TB1> INFO: Expecting 2560 events.
[18:46:48.671] <TB1> INFO: 2560 events read in total (290ms).
[18:46:48.672] <TB1> INFO: Test took 1190ms.
[18:46:48.979] <TB1> INFO: Expecting 2560 events.
[18:46:49.858] <TB1> INFO: 2560 events read in total (288ms).
[18:46:49.859] <TB1> INFO: Test took 1186ms.
[18:46:50.167] <TB1> INFO: Expecting 2560 events.
[18:46:51.046] <TB1> INFO: 2560 events read in total (288ms).
[18:46:51.046] <TB1> INFO: Test took 1187ms.
[18:46:51.354] <TB1> INFO: Expecting 2560 events.
[18:46:52.232] <TB1> INFO: 2560 events read in total (287ms).
[18:46:52.232] <TB1> INFO: Test took 1185ms.
[18:46:52.540] <TB1> INFO: Expecting 2560 events.
[18:46:53.419] <TB1> INFO: 2560 events read in total (287ms).
[18:46:53.420] <TB1> INFO: Test took 1187ms.
[18:46:53.728] <TB1> INFO: Expecting 2560 events.
[18:46:54.612] <TB1> INFO: 2560 events read in total (292ms).
[18:46:54.612] <TB1> INFO: Test took 1191ms.
[18:46:54.920] <TB1> INFO: Expecting 2560 events.
[18:46:55.814] <TB1> INFO: 2560 events read in total (302ms).
[18:46:55.814] <TB1> INFO: Test took 1201ms.
[18:46:56.121] <TB1> INFO: Expecting 2560 events.
[18:46:57.004] <TB1> INFO: 2560 events read in total (291ms).
[18:46:57.005] <TB1> INFO: Test took 1190ms.
[18:46:57.313] <TB1> INFO: Expecting 2560 events.
[18:46:58.206] <TB1> INFO: 2560 events read in total (302ms).
[18:46:58.207] <TB1> INFO: Test took 1202ms.
[18:46:58.515] <TB1> INFO: Expecting 2560 events.
[18:46:59.400] <TB1> INFO: 2560 events read in total (293ms).
[18:46:59.400] <TB1> INFO: Test took 1192ms.
[18:46:59.404] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:46:59.709] <TB1> INFO: Expecting 655360 events.
[18:47:14.619] <TB1> INFO: 655360 events read in total (14318ms).
[18:47:14.631] <TB1> INFO: Expecting 655360 events.
[18:47:29.262] <TB1> INFO: 655360 events read in total (14228ms).
[18:47:29.278] <TB1> INFO: Expecting 655360 events.
[18:47:43.898] <TB1> INFO: 655360 events read in total (14217ms).
[18:47:43.919] <TB1> INFO: Expecting 655360 events.
[18:47:58.655] <TB1> INFO: 655360 events read in total (14333ms).
[18:47:58.685] <TB1> INFO: Expecting 655360 events.
[18:48:13.547] <TB1> INFO: 655360 events read in total (14459ms).
[18:48:13.576] <TB1> INFO: Expecting 655360 events.
[18:48:28.374] <TB1> INFO: 655360 events read in total (14395ms).
[18:48:28.408] <TB1> INFO: Expecting 655360 events.
[18:48:43.015] <TB1> INFO: 655360 events read in total (14204ms).
[18:48:43.068] <TB1> INFO: Expecting 655360 events.
[18:48:57.819] <TB1> INFO: 655360 events read in total (14348ms).
[18:48:57.874] <TB1> INFO: Expecting 655360 events.
[18:49:12.544] <TB1> INFO: 655360 events read in total (14267ms).
[18:49:12.593] <TB1> INFO: Expecting 655360 events.
[18:49:27.101] <TB1> INFO: 655360 events read in total (14105ms).
[18:49:27.169] <TB1> INFO: Expecting 655360 events.
[18:49:41.719] <TB1> INFO: 655360 events read in total (14147ms).
[18:49:41.815] <TB1> INFO: Expecting 655360 events.
[18:49:56.392] <TB1> INFO: 655360 events read in total (14173ms).
[18:49:56.467] <TB1> INFO: Expecting 655360 events.
[18:50:10.976] <TB1> INFO: 655360 events read in total (14106ms).
[18:50:11.059] <TB1> INFO: Expecting 655360 events.
[18:50:25.567] <TB1> INFO: 655360 events read in total (14105ms).
[18:50:25.651] <TB1> INFO: Expecting 655360 events.
[18:50:40.244] <TB1> INFO: 655360 events read in total (14190ms).
[18:50:40.337] <TB1> INFO: Expecting 655360 events.
[18:50:54.880] <TB1> INFO: 655360 events read in total (14139ms).
[18:50:54.998] <TB1> INFO: Test took 235594ms.
[18:50:55.095] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:50:55.352] <TB1> INFO: Expecting 655360 events.
[18:51:09.908] <TB1> INFO: 655360 events read in total (13964ms).
[18:51:09.922] <TB1> INFO: Expecting 655360 events.
[18:51:23.993] <TB1> INFO: 655360 events read in total (13668ms).
[18:51:24.009] <TB1> INFO: Expecting 655360 events.
[18:51:38.416] <TB1> INFO: 655360 events read in total (14004ms).
[18:51:38.437] <TB1> INFO: Expecting 655360 events.
[18:51:52.837] <TB1> INFO: 655360 events read in total (13997ms).
[18:51:52.867] <TB1> INFO: Expecting 655360 events.
[18:52:07.356] <TB1> INFO: 655360 events read in total (14086ms).
[18:52:07.387] <TB1> INFO: Expecting 655360 events.
[18:52:21.845] <TB1> INFO: 655360 events read in total (14055ms).
[18:52:21.879] <TB1> INFO: Expecting 655360 events.
[18:52:36.214] <TB1> INFO: 655360 events read in total (13931ms).
[18:52:36.255] <TB1> INFO: Expecting 655360 events.
[18:52:50.507] <TB1> INFO: 655360 events read in total (13849ms).
[18:52:50.561] <TB1> INFO: Expecting 655360 events.
[18:53:05.079] <TB1> INFO: 655360 events read in total (14115ms).
[18:53:05.129] <TB1> INFO: Expecting 655360 events.
[18:53:19.560] <TB1> INFO: 655360 events read in total (14028ms).
[18:53:19.648] <TB1> INFO: Expecting 655360 events.
[18:53:34.186] <TB1> INFO: 655360 events read in total (14135ms).
[18:53:34.267] <TB1> INFO: Expecting 655360 events.
[18:53:48.426] <TB1> INFO: 655360 events read in total (13756ms).
[18:53:48.500] <TB1> INFO: Expecting 655360 events.
[18:54:02.882] <TB1> INFO: 655360 events read in total (13979ms).
[18:54:02.991] <TB1> INFO: Expecting 655360 events.
[18:54:17.325] <TB1> INFO: 655360 events read in total (13932ms).
[18:54:17.411] <TB1> INFO: Expecting 655360 events.
[18:54:31.742] <TB1> INFO: 655360 events read in total (13928ms).
[18:54:31.832] <TB1> INFO: Expecting 655360 events.
[18:54:46.421] <TB1> INFO: 655360 events read in total (14186ms).
[18:54:46.524] <TB1> INFO: Test took 231429ms.
[18:54:46.708] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.715] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:54:46.721] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:54:46.727] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[18:54:46.733] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[18:54:46.739] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[18:54:46.745] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[18:54:46.751] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[18:54:46.757] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[18:54:46.764] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.770] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:54:46.776] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:54:46.782] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[18:54:46.788] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[18:54:46.794] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[18:54:46.801] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.807] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.814] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.820] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.827] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.833] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.839] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.846] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:54:46.852] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.858] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.864] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.870] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:54:46.876] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:54:46.882] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[18:54:46.888] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[18:54:46.894] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[18:54:46.900] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.906] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:54:46.912] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:54:46.918] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[18:54:46.924] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.930] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:54:46.936] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:54:46.942] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.948] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[18:54:46.954] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[18:54:46.960] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[18:54:46.966] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[18:54:46.972] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[18:54:46.979] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[18:54:46.985] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[18:54:47.021] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C0.dat
[18:54:47.022] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C1.dat
[18:54:47.022] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C2.dat
[18:54:47.022] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C3.dat
[18:54:47.022] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C4.dat
[18:54:47.023] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C5.dat
[18:54:47.023] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C6.dat
[18:54:47.023] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C7.dat
[18:54:47.023] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C8.dat
[18:54:47.023] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C9.dat
[18:54:47.023] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C10.dat
[18:54:47.024] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C11.dat
[18:54:47.024] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C12.dat
[18:54:47.024] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C13.dat
[18:54:47.024] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C14.dat
[18:54:47.024] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//dacParameters35_C15.dat
[18:54:47.267] <TB1> INFO: Expecting 41600 events.
[18:54:50.384] <TB1> INFO: 41600 events read in total (2526ms).
[18:54:50.385] <TB1> INFO: Test took 3357ms.
[18:54:50.841] <TB1> INFO: Expecting 41600 events.
[18:54:53.875] <TB1> INFO: 41600 events read in total (2442ms).
[18:54:53.876] <TB1> INFO: Test took 3277ms.
[18:54:54.327] <TB1> INFO: Expecting 41600 events.
[18:54:57.488] <TB1> INFO: 41600 events read in total (2570ms).
[18:54:57.489] <TB1> INFO: Test took 3398ms.
[18:54:57.712] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:54:57.801] <TB1> INFO: Expecting 2560 events.
[18:54:58.686] <TB1> INFO: 2560 events read in total (293ms).
[18:54:58.687] <TB1> INFO: Test took 975ms.
[18:54:58.689] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:54:58.996] <TB1> INFO: Expecting 2560 events.
[18:54:59.883] <TB1> INFO: 2560 events read in total (296ms).
[18:54:59.884] <TB1> INFO: Test took 1195ms.
[18:54:59.887] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:00.193] <TB1> INFO: Expecting 2560 events.
[18:55:01.076] <TB1> INFO: 2560 events read in total (291ms).
[18:55:01.076] <TB1> INFO: Test took 1189ms.
[18:55:01.078] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:01.384] <TB1> INFO: Expecting 2560 events.
[18:55:02.270] <TB1> INFO: 2560 events read in total (294ms).
[18:55:02.271] <TB1> INFO: Test took 1193ms.
[18:55:02.273] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:02.579] <TB1> INFO: Expecting 2560 events.
[18:55:03.471] <TB1> INFO: 2560 events read in total (300ms).
[18:55:03.472] <TB1> INFO: Test took 1199ms.
[18:55:03.474] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:03.780] <TB1> INFO: Expecting 2560 events.
[18:55:04.667] <TB1> INFO: 2560 events read in total (295ms).
[18:55:04.667] <TB1> INFO: Test took 1193ms.
[18:55:04.670] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:04.976] <TB1> INFO: Expecting 2560 events.
[18:55:05.860] <TB1> INFO: 2560 events read in total (292ms).
[18:55:05.860] <TB1> INFO: Test took 1190ms.
[18:55:05.862] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:06.169] <TB1> INFO: Expecting 2560 events.
[18:55:07.053] <TB1> INFO: 2560 events read in total (292ms).
[18:55:07.053] <TB1> INFO: Test took 1191ms.
[18:55:07.055] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:07.363] <TB1> INFO: Expecting 2560 events.
[18:55:08.248] <TB1> INFO: 2560 events read in total (293ms).
[18:55:08.249] <TB1> INFO: Test took 1194ms.
[18:55:08.252] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:08.556] <TB1> INFO: Expecting 2560 events.
[18:55:09.438] <TB1> INFO: 2560 events read in total (290ms).
[18:55:09.439] <TB1> INFO: Test took 1187ms.
[18:55:09.441] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:09.747] <TB1> INFO: Expecting 2560 events.
[18:55:10.635] <TB1> INFO: 2560 events read in total (296ms).
[18:55:10.636] <TB1> INFO: Test took 1195ms.
[18:55:10.639] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:10.944] <TB1> INFO: Expecting 2560 events.
[18:55:11.827] <TB1> INFO: 2560 events read in total (292ms).
[18:55:11.827] <TB1> INFO: Test took 1188ms.
[18:55:11.829] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:12.136] <TB1> INFO: Expecting 2560 events.
[18:55:13.023] <TB1> INFO: 2560 events read in total (295ms).
[18:55:13.023] <TB1> INFO: Test took 1194ms.
[18:55:13.026] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:13.332] <TB1> INFO: Expecting 2560 events.
[18:55:14.217] <TB1> INFO: 2560 events read in total (294ms).
[18:55:14.218] <TB1> INFO: Test took 1192ms.
[18:55:14.221] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:14.526] <TB1> INFO: Expecting 2560 events.
[18:55:15.407] <TB1> INFO: 2560 events read in total (289ms).
[18:55:15.408] <TB1> INFO: Test took 1187ms.
[18:55:15.410] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:15.715] <TB1> INFO: Expecting 2560 events.
[18:55:16.599] <TB1> INFO: 2560 events read in total (292ms).
[18:55:16.599] <TB1> INFO: Test took 1189ms.
[18:55:16.603] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:16.908] <TB1> INFO: Expecting 2560 events.
[18:55:17.797] <TB1> INFO: 2560 events read in total (298ms).
[18:55:17.798] <TB1> INFO: Test took 1195ms.
[18:55:17.799] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:18.106] <TB1> INFO: Expecting 2560 events.
[18:55:18.989] <TB1> INFO: 2560 events read in total (292ms).
[18:55:18.990] <TB1> INFO: Test took 1191ms.
[18:55:18.992] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:19.298] <TB1> INFO: Expecting 2560 events.
[18:55:20.182] <TB1> INFO: 2560 events read in total (292ms).
[18:55:20.182] <TB1> INFO: Test took 1190ms.
[18:55:20.185] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:20.490] <TB1> INFO: Expecting 2560 events.
[18:55:21.377] <TB1> INFO: 2560 events read in total (296ms).
[18:55:21.378] <TB1> INFO: Test took 1194ms.
[18:55:21.381] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:21.685] <TB1> INFO: Expecting 2560 events.
[18:55:22.573] <TB1> INFO: 2560 events read in total (296ms).
[18:55:22.574] <TB1> INFO: Test took 1193ms.
[18:55:22.576] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:22.882] <TB1> INFO: Expecting 2560 events.
[18:55:23.763] <TB1> INFO: 2560 events read in total (289ms).
[18:55:23.763] <TB1> INFO: Test took 1187ms.
[18:55:23.767] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:24.071] <TB1> INFO: Expecting 2560 events.
[18:55:24.954] <TB1> INFO: 2560 events read in total (291ms).
[18:55:24.954] <TB1> INFO: Test took 1187ms.
[18:55:24.958] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:25.262] <TB1> INFO: Expecting 2560 events.
[18:55:26.145] <TB1> INFO: 2560 events read in total (291ms).
[18:55:26.146] <TB1> INFO: Test took 1189ms.
[18:55:26.148] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:26.454] <TB1> INFO: Expecting 2560 events.
[18:55:27.338] <TB1> INFO: 2560 events read in total (292ms).
[18:55:27.339] <TB1> INFO: Test took 1191ms.
[18:55:27.340] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:27.647] <TB1> INFO: Expecting 2560 events.
[18:55:28.531] <TB1> INFO: 2560 events read in total (292ms).
[18:55:28.531] <TB1> INFO: Test took 1191ms.
[18:55:28.534] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:28.840] <TB1> INFO: Expecting 2560 events.
[18:55:29.730] <TB1> INFO: 2560 events read in total (298ms).
[18:55:29.731] <TB1> INFO: Test took 1197ms.
[18:55:29.733] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:30.039] <TB1> INFO: Expecting 2560 events.
[18:55:30.924] <TB1> INFO: 2560 events read in total (293ms).
[18:55:30.925] <TB1> INFO: Test took 1192ms.
[18:55:30.928] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:31.233] <TB1> INFO: Expecting 2560 events.
[18:55:32.124] <TB1> INFO: 2560 events read in total (299ms).
[18:55:32.125] <TB1> INFO: Test took 1197ms.
[18:55:32.127] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:32.433] <TB1> INFO: Expecting 2560 events.
[18:55:33.318] <TB1> INFO: 2560 events read in total (293ms).
[18:55:33.319] <TB1> INFO: Test took 1192ms.
[18:55:33.321] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:33.627] <TB1> INFO: Expecting 2560 events.
[18:55:34.513] <TB1> INFO: 2560 events read in total (294ms).
[18:55:34.513] <TB1> INFO: Test took 1192ms.
[18:55:34.516] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:55:34.822] <TB1> INFO: Expecting 2560 events.
[18:55:35.716] <TB1> INFO: 2560 events read in total (303ms).
[18:55:35.716] <TB1> INFO: Test took 1200ms.
[18:55:36.191] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 643 seconds
[18:55:36.191] <TB1> INFO: PH scale (per ROC): 40 39 34 35 43 36 32 43 30 34 30 31 50 38 49 48
[18:55:36.191] <TB1> INFO: PH offset (per ROC): 112 98 100 109 89 96 107 101 100 95 97 106 127 112 124 127
[18:55:36.198] <TB1> INFO: Decoding statistics:
[18:55:36.198] <TB1> INFO: General information:
[18:55:36.198] <TB1> INFO: 16bit words read: 127888
[18:55:36.198] <TB1> INFO: valid events total: 20480
[18:55:36.198] <TB1> INFO: empty events: 17976
[18:55:36.198] <TB1> INFO: valid events with pixels: 2504
[18:55:36.198] <TB1> INFO: valid pixel hits: 2504
[18:55:36.198] <TB1> INFO: Event errors: 0
[18:55:36.198] <TB1> INFO: start marker: 0
[18:55:36.198] <TB1> INFO: stop marker: 0
[18:55:36.198] <TB1> INFO: overflow: 0
[18:55:36.198] <TB1> INFO: invalid 5bit words: 0
[18:55:36.198] <TB1> INFO: invalid XOR eye diagram: 0
[18:55:36.198] <TB1> INFO: frame (failed synchr.): 0
[18:55:36.198] <TB1> INFO: idle data (no TBM trl): 0
[18:55:36.198] <TB1> INFO: no data (only TBM hdr): 0
[18:55:36.198] <TB1> INFO: TBM errors: 0
[18:55:36.198] <TB1> INFO: flawed TBM headers: 0
[18:55:36.198] <TB1> INFO: flawed TBM trailers: 0
[18:55:36.198] <TB1> INFO: event ID mismatches: 0
[18:55:36.198] <TB1> INFO: ROC errors: 0
[18:55:36.198] <TB1> INFO: missing ROC header(s): 0
[18:55:36.198] <TB1> INFO: misplaced readback start: 0
[18:55:36.198] <TB1> INFO: Pixel decoding errors: 0
[18:55:36.198] <TB1> INFO: pixel data incomplete: 0
[18:55:36.199] <TB1> INFO: pixel address: 0
[18:55:36.199] <TB1> INFO: pulse height fill bit: 0
[18:55:36.199] <TB1> INFO: buffer corruption: 0
[18:55:36.359] <TB1> INFO: ######################################################################
[18:55:36.359] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[18:55:36.359] <TB1> INFO: ######################################################################
[18:55:36.374] <TB1> INFO: scanning low vcal = 10
[18:55:36.610] <TB1> INFO: Expecting 41600 events.
[18:55:40.204] <TB1> INFO: 41600 events read in total (3002ms).
[18:55:40.205] <TB1> INFO: Test took 3831ms.
[18:55:40.207] <TB1> INFO: scanning low vcal = 20
[18:55:40.500] <TB1> INFO: Expecting 41600 events.
[18:55:44.077] <TB1> INFO: 41600 events read in total (2985ms).
[18:55:44.078] <TB1> INFO: Test took 3871ms.
[18:55:44.079] <TB1> INFO: scanning low vcal = 30
[18:55:44.374] <TB1> INFO: Expecting 41600 events.
[18:55:48.012] <TB1> INFO: 41600 events read in total (3046ms).
[18:55:48.012] <TB1> INFO: Test took 3933ms.
[18:55:48.015] <TB1> INFO: scanning low vcal = 40
[18:55:48.292] <TB1> INFO: Expecting 41600 events.
[18:55:52.253] <TB1> INFO: 41600 events read in total (3370ms).
[18:55:52.255] <TB1> INFO: Test took 4240ms.
[18:55:52.258] <TB1> INFO: scanning low vcal = 50
[18:55:52.535] <TB1> INFO: Expecting 41600 events.
[18:55:56.497] <TB1> INFO: 41600 events read in total (3370ms).
[18:55:56.498] <TB1> INFO: Test took 4240ms.
[18:55:56.501] <TB1> INFO: scanning low vcal = 60
[18:55:56.777] <TB1> INFO: Expecting 41600 events.
[18:56:00.750] <TB1> INFO: 41600 events read in total (3381ms).
[18:56:00.751] <TB1> INFO: Test took 4250ms.
[18:56:00.754] <TB1> INFO: scanning low vcal = 70
[18:56:01.031] <TB1> INFO: Expecting 41600 events.
[18:56:04.000] <TB1> INFO: 41600 events read in total (3377ms).
[18:56:04.001] <TB1> INFO: Test took 4247ms.
[18:56:05.004] <TB1> INFO: scanning low vcal = 80
[18:56:05.282] <TB1> INFO: Expecting 41600 events.
[18:56:09.248] <TB1> INFO: 41600 events read in total (3375ms).
[18:56:09.249] <TB1> INFO: Test took 4245ms.
[18:56:09.252] <TB1> INFO: scanning low vcal = 90
[18:56:09.529] <TB1> INFO: Expecting 41600 events.
[18:56:13.546] <TB1> INFO: 41600 events read in total (3425ms).
[18:56:13.547] <TB1> INFO: Test took 4294ms.
[18:56:13.551] <TB1> INFO: scanning low vcal = 100
[18:56:13.827] <TB1> INFO: Expecting 41600 events.
[18:56:17.802] <TB1> INFO: 41600 events read in total (3382ms).
[18:56:17.803] <TB1> INFO: Test took 4252ms.
[18:56:17.806] <TB1> INFO: scanning low vcal = 110
[18:56:18.084] <TB1> INFO: Expecting 41600 events.
[18:56:22.075] <TB1> INFO: 41600 events read in total (3400ms).
[18:56:22.076] <TB1> INFO: Test took 4270ms.
[18:56:22.080] <TB1> INFO: scanning low vcal = 120
[18:56:22.356] <TB1> INFO: Expecting 41600 events.
[18:56:26.423] <TB1> INFO: 41600 events read in total (3475ms).
[18:56:26.424] <TB1> INFO: Test took 4344ms.
[18:56:26.427] <TB1> INFO: scanning low vcal = 130
[18:56:26.704] <TB1> INFO: Expecting 41600 events.
[18:56:30.749] <TB1> INFO: 41600 events read in total (3453ms).
[18:56:30.749] <TB1> INFO: Test took 4322ms.
[18:56:30.753] <TB1> INFO: scanning low vcal = 140
[18:56:31.030] <TB1> INFO: Expecting 41600 events.
[18:56:35.006] <TB1> INFO: 41600 events read in total (3385ms).
[18:56:35.007] <TB1> INFO: Test took 4254ms.
[18:56:35.010] <TB1> INFO: scanning low vcal = 150
[18:56:35.287] <TB1> INFO: Expecting 41600 events.
[18:56:39.278] <TB1> INFO: 41600 events read in total (3399ms).
[18:56:39.279] <TB1> INFO: Test took 4269ms.
[18:56:39.283] <TB1> INFO: scanning low vcal = 160
[18:56:39.559] <TB1> INFO: Expecting 41600 events.
[18:56:43.597] <TB1> INFO: 41600 events read in total (3446ms).
[18:56:43.598] <TB1> INFO: Test took 4315ms.
[18:56:43.601] <TB1> INFO: scanning low vcal = 170
[18:56:43.878] <TB1> INFO: Expecting 41600 events.
[18:56:47.867] <TB1> INFO: 41600 events read in total (3397ms).
[18:56:47.868] <TB1> INFO: Test took 4267ms.
[18:56:47.873] <TB1> INFO: scanning low vcal = 180
[18:56:48.147] <TB1> INFO: Expecting 41600 events.
[18:56:52.169] <TB1> INFO: 41600 events read in total (3430ms).
[18:56:52.170] <TB1> INFO: Test took 4296ms.
[18:56:52.173] <TB1> INFO: scanning low vcal = 190
[18:56:52.450] <TB1> INFO: Expecting 41600 events.
[18:56:56.463] <TB1> INFO: 41600 events read in total (3421ms).
[18:56:56.465] <TB1> INFO: Test took 4292ms.
[18:56:56.468] <TB1> INFO: scanning low vcal = 200
[18:56:56.745] <TB1> INFO: Expecting 41600 events.
[18:57:00.779] <TB1> INFO: 41600 events read in total (3442ms).
[18:57:00.779] <TB1> INFO: Test took 4311ms.
[18:57:00.783] <TB1> INFO: scanning low vcal = 210
[18:57:01.060] <TB1> INFO: Expecting 41600 events.
[18:57:05.097] <TB1> INFO: 41600 events read in total (3445ms).
[18:57:05.098] <TB1> INFO: Test took 4315ms.
[18:57:05.101] <TB1> INFO: scanning low vcal = 220
[18:57:05.379] <TB1> INFO: Expecting 41600 events.
[18:57:09.445] <TB1> INFO: 41600 events read in total (3474ms).
[18:57:09.446] <TB1> INFO: Test took 4345ms.
[18:57:09.449] <TB1> INFO: scanning low vcal = 230
[18:57:09.727] <TB1> INFO: Expecting 41600 events.
[18:57:13.795] <TB1> INFO: 41600 events read in total (3477ms).
[18:57:13.796] <TB1> INFO: Test took 4346ms.
[18:57:13.799] <TB1> INFO: scanning low vcal = 240
[18:57:14.075] <TB1> INFO: Expecting 41600 events.
[18:57:18.107] <TB1> INFO: 41600 events read in total (3440ms).
[18:57:18.108] <TB1> INFO: Test took 4309ms.
[18:57:18.111] <TB1> INFO: scanning low vcal = 250
[18:57:18.387] <TB1> INFO: Expecting 41600 events.
[18:57:22.401] <TB1> INFO: 41600 events read in total (3422ms).
[18:57:22.402] <TB1> INFO: Test took 4291ms.
[18:57:22.406] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[18:57:22.682] <TB1> INFO: Expecting 41600 events.
[18:57:26.694] <TB1> INFO: 41600 events read in total (3421ms).
[18:57:26.695] <TB1> INFO: Test took 4289ms.
[18:57:26.698] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[18:57:26.974] <TB1> INFO: Expecting 41600 events.
[18:57:30.989] <TB1> INFO: 41600 events read in total (3423ms).
[18:57:30.989] <TB1> INFO: Test took 4291ms.
[18:57:30.993] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[18:57:31.269] <TB1> INFO: Expecting 41600 events.
[18:57:35.304] <TB1> INFO: 41600 events read in total (3443ms).
[18:57:35.305] <TB1> INFO: Test took 4312ms.
[18:57:35.308] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[18:57:35.584] <TB1> INFO: Expecting 41600 events.
[18:57:39.588] <TB1> INFO: 41600 events read in total (3413ms).
[18:57:39.588] <TB1> INFO: Test took 4280ms.
[18:57:39.592] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[18:57:39.868] <TB1> INFO: Expecting 41600 events.
[18:57:43.900] <TB1> INFO: 41600 events read in total (3440ms).
[18:57:43.900] <TB1> INFO: Test took 4308ms.
[18:57:44.365] <TB1> INFO: PixTestGainPedestal::measure() done
[18:58:16.996] <TB1> INFO: PixTestGainPedestal::fit() done
[18:58:16.996] <TB1> INFO: non-linearity mean: 0.939 0.928 0.905 0.930 0.932 0.936 0.936 0.953 0.945 0.934 0.966 0.943 0.980 0.922 0.983 0.983
[18:58:16.996] <TB1> INFO: non-linearity RMS: 0.063 0.094 0.125 0.089 0.078 0.160 0.108 0.049 0.129 0.135 0.187 0.139 0.004 0.112 0.003 0.003
[18:58:16.996] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C0.dat
[18:58:17.015] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C1.dat
[18:58:17.028] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C2.dat
[18:58:17.041] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C3.dat
[18:58:17.054] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C4.dat
[18:58:17.068] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C5.dat
[18:58:17.081] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C6.dat
[18:58:17.094] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C7.dat
[18:58:17.107] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C8.dat
[18:58:17.120] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C9.dat
[18:58:17.133] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C10.dat
[18:58:17.146] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C11.dat
[18:58:17.160] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C12.dat
[18:58:17.173] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C13.dat
[18:58:17.186] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C14.dat
[18:58:17.199] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1074_FullQualification_2016-10-25_15h07m_1477400838//003_Fulltest_p17//phCalibrationFitErr35_C15.dat
[18:58:17.212] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 160 seconds
[18:58:17.212] <TB1> INFO: Decoding statistics:
[18:58:17.212] <TB1> INFO: General information:
[18:58:17.212] <TB1> INFO: 16bit words read: 3308422
[18:58:17.212] <TB1> INFO: valid events total: 332800
[18:58:17.212] <TB1> INFO: empty events: 562
[18:58:17.212] <TB1> INFO: valid events with pixels: 332238
[18:58:17.212] <TB1> INFO: valid pixel hits: 655811
[18:58:17.212] <TB1> INFO: Event errors: 0
[18:58:17.212] <TB1> INFO: start marker: 0
[18:58:17.212] <TB1> INFO: stop marker: 0
[18:58:17.212] <TB1> INFO: overflow: 0
[18:58:17.212] <TB1> INFO: invalid 5bit words: 0
[18:58:17.212] <TB1> INFO: invalid XOR eye diagram: 0
[18:58:17.212] <TB1> INFO: frame (failed synchr.): 0
[18:58:17.212] <TB1> INFO: idle data (no TBM trl): 0
[18:58:17.212] <TB1> INFO: no data (only TBM hdr): 0
[18:58:17.212] <TB1> INFO: TBM errors: 0
[18:58:17.212] <TB1> INFO: flawed TBM headers: 0
[18:58:17.212] <TB1> INFO: flawed TBM trailers: 0
[18:58:17.212] <TB1> INFO: event ID mismatches: 0
[18:58:17.212] <TB1> INFO: ROC errors: 0
[18:58:17.212] <TB1> INFO: missing ROC header(s): 0
[18:58:17.212] <TB1> INFO: misplaced readback start: 0
[18:58:17.212] <TB1> INFO: Pixel decoding errors: 0
[18:58:17.212] <TB1> INFO: pixel data incomplete: 0
[18:58:17.212] <TB1> INFO: pixel address: 0
[18:58:17.212] <TB1> INFO: pulse height fill bit: 0
[18:58:17.212] <TB1> INFO: buffer corruption: 0
[18:58:17.228] <TB1> INFO: Decoding statistics:
[18:58:17.228] <TB1> INFO: General information:
[18:58:17.228] <TB1> INFO: 16bit words read: 3437846
[18:58:17.228] <TB1> INFO: valid events total: 353536
[18:58:17.228] <TB1> INFO: empty events: 18794
[18:58:17.228] <TB1> INFO: valid events with pixels: 334742
[18:58:17.228] <TB1> INFO: valid pixel hits: 658315
[18:58:17.228] <TB1> INFO: Event errors: 0
[18:58:17.228] <TB1> INFO: start marker: 0
[18:58:17.228] <TB1> INFO: stop marker: 0
[18:58:17.228] <TB1> INFO: overflow: 0
[18:58:17.228] <TB1> INFO: invalid 5bit words: 0
[18:58:17.228] <TB1> INFO: invalid XOR eye diagram: 0
[18:58:17.228] <TB1> INFO: frame (failed synchr.): 0
[18:58:17.229] <TB1> INFO: idle data (no TBM trl): 0
[18:58:17.229] <TB1> INFO: no data (only TBM hdr): 0
[18:58:17.229] <TB1> INFO: TBM errors: 0
[18:58:17.229] <TB1> INFO: flawed TBM headers: 0
[18:58:17.229] <TB1> INFO: flawed TBM trailers: 0
[18:58:17.229] <TB1> INFO: event ID mismatches: 0
[18:58:17.229] <TB1> INFO: ROC errors: 0
[18:58:17.229] <TB1> INFO: missing ROC header(s): 0
[18:58:17.229] <TB1> INFO: misplaced readback start: 0
[18:58:17.229] <TB1> INFO: Pixel decoding errors: 0
[18:58:17.229] <TB1> INFO: pixel data incomplete: 0
[18:58:17.229] <TB1> INFO: pixel address: 0
[18:58:17.229] <TB1> INFO: pulse height fill bit: 0
[18:58:17.229] <TB1> INFO: buffer corruption: 0
[18:58:17.229] <TB1> INFO: enter test to run
[18:58:17.229] <TB1> INFO: test: exit no parameter change
[18:58:17.355] <TB1> QUIET: Connection to board 154 closed.
[18:58:17.356] <TB1> INFO: pXar: this is the end, my friend