[14:34:28.299] <TB1> INFO: *** Welcome to pxar ***
[14:34:28.299] <TB1> INFO: *** Today: 2016/10/26
[14:34:28.305] <TB1> INFO: *** Version: c8ba-dirty
[14:34:28.305] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C15.dat
[14:34:28.306] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[14:34:28.306] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//defaultMaskFile.dat
[14:34:28.306] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters_C15.dat
[14:34:28.382] <TB1> INFO: clk: 4
[14:34:28.382] <TB1> INFO: ctr: 4
[14:34:28.382] <TB1> INFO: sda: 19
[14:34:28.382] <TB1> INFO: tin: 9
[14:34:28.382] <TB1> INFO: level: 15
[14:34:28.382] <TB1> INFO: triggerdelay: 0
[14:34:28.382] <TB1> QUIET: Instanciating API for pxar v2.7.6+61~g7f4a123
[14:34:28.382] <TB1> INFO: Log level: INFO
[14:34:28.391] <TB1> INFO: Found DTB DTB_WXC03A
[14:34:28.402] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[14:34:28.404] <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:
------------------------------------------------------
[14:34:28.406] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[14:34:29.896] <TB1> INFO: DUT info:
[14:34:29.896] <TB1> INFO: The DUT currently contains the following objects:
[14:34:29.896] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[14:34:29.896] <TB1> INFO: TBM Core alpha (0): 7 registers set
[14:34:29.896] <TB1> INFO: TBM Core beta (1): 7 registers set
[14:34:29.897] <TB1> INFO: TBM Core alpha (2): 7 registers set
[14:34:29.897] <TB1> INFO: TBM Core beta (3): 7 registers set
[14:34:29.897] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[14:34:29.897] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:29.897] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:30.299] <TB1> INFO: enter 'restricted' command line mode
[14:34:30.299] <TB1> INFO: enter test to run
[14:34:30.299] <TB1> INFO: test: pretest no parameter change
[14:34:30.299] <TB1> INFO: running: pretest
[14:34:30.304] <TB1> INFO: ######################################################################
[14:34:30.304] <TB1> INFO: PixTestPretest::doTest()
[14:34:30.304] <TB1> INFO: ######################################################################
[14:34:30.305] <TB1> INFO: ----------------------------------------------------------------------
[14:34:30.305] <TB1> INFO: PixTestPretest::programROC()
[14:34:30.305] <TB1> INFO: ----------------------------------------------------------------------
[14:34:48.318] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[14:34:48.318] <TB1> INFO: IA differences per ROC: 20.9 16.9 19.3 20.1 17.7 19.3 19.3 20.1 18.5 19.3 20.9 19.3 20.1 19.3 19.3 18.5
[14:34:48.377] <TB1> INFO: ----------------------------------------------------------------------
[14:34:48.377] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[14:34:48.377] <TB1> INFO: ----------------------------------------------------------------------
[14:34:55.482] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 383.5 mA = 23.9688 mA/ROC
[14:34:55.482] <TB1> INFO: i(loss) [mA/ROC]: 19.3 19.3 19.3 20.1 20.1 19.3 20.1 20.1 19.3 19.3 20.1 19.3 20.1 20.1 20.1 19.3
[14:34:55.516] <TB1> INFO: ----------------------------------------------------------------------
[14:34:55.516] <TB1> INFO: PixTestPretest::findTiming()
[14:34:55.516] <TB1> INFO: ----------------------------------------------------------------------
[14:34:55.516] <TB1> INFO: PixTestCmd::init()

[14:35:28.142] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[14:35:28.142] <TB1> INFO: (success/tries = 100/100), width = 4
[14:35:29.646] <TB1> INFO: ----------------------------------------------------------------------
[14:35:29.646] <TB1> INFO: PixTestPretest::findWorkingPixel()
[14:35:29.646] <TB1> INFO: ----------------------------------------------------------------------
[14:35:29.743] <TB1> INFO: Expecting 231680 events.
[14:35:39.554] <TB1> INFO: 231680 events read in total (9219ms).
[14:35:39.562] <TB1> INFO: Test took 9909ms.
[14:35:39.808] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[14:35:39.843] <TB1> INFO: ----------------------------------------------------------------------
[14:35:39.843] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[14:35:39.843] <TB1> INFO: ----------------------------------------------------------------------
[14:35:39.938] <TB1> INFO: Expecting 231680 events.
[14:35:49.773] <TB1> INFO: 231680 events read in total (9243ms).
[14:35:49.785] <TB1> INFO: Test took 9936ms.
[14:35:50.038] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[14:35:50.038] <TB1> INFO: CalDel: 82 78 87 87 76 80 87 107 91 97 84 103 88 95 103 90
[14:35:50.038] <TB1> INFO: VthrComp: 51 51 51 51 52 55 51 51 52 52 54 51 52 51 57 51
[14:35:50.041] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C0.dat
[14:35:50.041] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C1.dat
[14:35:50.041] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C2.dat
[14:35:50.041] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C3.dat
[14:35:50.041] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C4.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C5.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C6.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C7.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C8.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C9.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C10.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C11.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C12.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C13.dat
[14:35:50.042] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C14.dat
[14:35:50.043] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters_C15.dat
[14:35:50.043] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C0a.dat
[14:35:50.043] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C0b.dat
[14:35:50.043] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C1a.dat
[14:35:50.043] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[14:35:50.043] <TB1> INFO: PixTestPretest::doTest() done, duration: 79 seconds
[14:35:50.096] <TB1> INFO: enter test to run
[14:35:50.096] <TB1> INFO: test: fulltest no parameter change
[14:35:50.096] <TB1> INFO: running: fulltest
[14:35:50.096] <TB1> INFO: ######################################################################
[14:35:50.096] <TB1> INFO: PixTestFullTest::doTest()
[14:35:50.096] <TB1> INFO: ######################################################################
[14:35:50.098] <TB1> INFO: ######################################################################
[14:35:50.098] <TB1> INFO: PixTestAlive::doTest()
[14:35:50.098] <TB1> INFO: ######################################################################
[14:35:50.099] <TB1> INFO: ----------------------------------------------------------------------
[14:35:50.099] <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)
[14:35:50.099] <TB1> INFO: ----------------------------------------------------------------------
[14:35:50.338] <TB1> INFO: Expecting 41600 events.
[14:35:53.996] <TB1> INFO: 41600 events read in total (3066ms).
[14:35:53.997] <TB1> INFO: Test took 3896ms.
[14:35:54.229] <TB1> INFO: PixTestAlive::aliveTest() done
[14:35:54.229] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:35:54.230] <TB1> INFO: ----------------------------------------------------------------------
[14:35:54.231] <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)
[14:35:54.231] <TB1> INFO: ----------------------------------------------------------------------
[14:35:54.474] <TB1> INFO: Expecting 41600 events.
[14:35:57.446] <TB1> INFO: 41600 events read in total (2380ms).
[14:35:57.447] <TB1> INFO: Test took 3212ms.
[14:35:57.447] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[14:35:57.687] <TB1> INFO: PixTestAlive::maskTest() done
[14:35:57.687] <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
[14:35:57.688] <TB1> INFO: ----------------------------------------------------------------------
[14:35:57.688] <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)
[14:35:57.688] <TB1> INFO: ----------------------------------------------------------------------
[14:35:57.931] <TB1> INFO: Expecting 41600 events.
[14:36:01.466] <TB1> INFO: 41600 events read in total (2943ms).
[14:36:01.467] <TB1> INFO: Test took 3777ms.
[14:36:01.706] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[14:36:01.706] <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
[14:36:01.706] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[14:36:01.707] <TB1> INFO: Decoding statistics:
[14:36:01.707] <TB1> INFO: General information:
[14:36:01.707] <TB1> INFO: 16bit words read: 0
[14:36:01.707] <TB1> INFO: valid events total: 0
[14:36:01.707] <TB1> INFO: empty events: 0
[14:36:01.707] <TB1> INFO: valid events with pixels: 0
[14:36:01.707] <TB1> INFO: valid pixel hits: 0
[14:36:01.707] <TB1> INFO: Event errors: 0
[14:36:01.707] <TB1> INFO: start marker: 0
[14:36:01.707] <TB1> INFO: stop marker: 0
[14:36:01.707] <TB1> INFO: overflow: 0
[14:36:01.707] <TB1> INFO: invalid 5bit words: 0
[14:36:01.707] <TB1> INFO: invalid XOR eye diagram: 0
[14:36:01.707] <TB1> INFO: frame (failed synchr.): 0
[14:36:01.707] <TB1> INFO: idle data (no TBM trl): 0
[14:36:01.707] <TB1> INFO: no data (only TBM hdr): 0
[14:36:01.707] <TB1> INFO: TBM errors: 0
[14:36:01.707] <TB1> INFO: flawed TBM headers: 0
[14:36:01.707] <TB1> INFO: flawed TBM trailers: 0
[14:36:01.707] <TB1> INFO: event ID mismatches: 0
[14:36:01.707] <TB1> INFO: ROC errors: 0
[14:36:01.707] <TB1> INFO: missing ROC header(s): 0
[14:36:01.707] <TB1> INFO: misplaced readback start: 0
[14:36:01.707] <TB1> INFO: Pixel decoding errors: 0
[14:36:01.707] <TB1> INFO: pixel data incomplete: 0
[14:36:01.707] <TB1> INFO: pixel address: 0
[14:36:01.707] <TB1> INFO: pulse height fill bit: 0
[14:36:01.707] <TB1> INFO: buffer corruption: 0
[14:36:01.716] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:36:01.717] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr_C15.dat

[14:36:01.717] <TB1> INFO: ######################################################################
[14:36:01.717] <TB1> INFO: PixTestReadback::doTest()
[14:36:01.717] <TB1> INFO: ######################################################################
[14:36:01.717] <TB1> INFO: ----------------------------------------------------------------------
[14:36:01.717] <TB1> INFO: PixTestReadback::CalibrateVd()
[14:36:01.717] <TB1> INFO: ----------------------------------------------------------------------
[14:36:11.693] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C0.dat
[14:36:11.693] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C1.dat
[14:36:11.693] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C2.dat
[14:36:11.693] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C3.dat
[14:36:11.693] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C4.dat
[14:36:11.693] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C5.dat
[14:36:11.693] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C6.dat
[14:36:11.694] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C7.dat
[14:36:11.694] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C8.dat
[14:36:11.694] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C9.dat
[14:36:11.694] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C10.dat
[14:36:11.694] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C11.dat
[14:36:11.695] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C12.dat
[14:36:11.695] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C13.dat
[14:36:11.695] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C14.dat
[14:36:11.695] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:36:11.723] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:36:11.723] <TB1> INFO: ----------------------------------------------------------------------
[14:36:11.723] <TB1> INFO: PixTestReadback::CalibrateVa()
[14:36:11.723] <TB1> INFO: ----------------------------------------------------------------------
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C0.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C1.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C2.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C3.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C4.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C5.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C6.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C7.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C8.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C9.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C10.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C11.dat
[14:36:21.648] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C12.dat
[14:36:21.649] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C13.dat
[14:36:21.649] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C14.dat
[14:36:21.649] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:36:21.681] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:36:21.681] <TB1> INFO: ----------------------------------------------------------------------
[14:36:21.681] <TB1> INFO: PixTestReadback::readbackVbg()
[14:36:21.681] <TB1> INFO: ----------------------------------------------------------------------
[14:36:29.352] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:36:29.352] <TB1> INFO: ----------------------------------------------------------------------
[14:36:29.352] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[14:36:29.352] <TB1> INFO: ----------------------------------------------------------------------
[14:36:29.352] <TB1> INFO: Vbg will be calibrated using Vd calibration
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 163.9calibrated Vbg = 1.1957 :::*/*/*/*/
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 147.2calibrated Vbg = 1.20086 :::*/*/*/*/
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 156.8calibrated Vbg = 1.193 :::*/*/*/*/
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 165.6calibrated Vbg = 1.19116 :::*/*/*/*/
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 157.5calibrated Vbg = 1.19035 :::*/*/*/*/
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 151.5calibrated Vbg = 1.19311 :::*/*/*/*/
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 158.7calibrated Vbg = 1.19707 :::*/*/*/*/
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 153.1calibrated Vbg = 1.20356 :::*/*/*/*/
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 151.5calibrated Vbg = 1.1888 :::*/*/*/*/
[14:36:29.352] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 157.9calibrated Vbg = 1.18873 :::*/*/*/*/
[14:36:29.353] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 155.1calibrated Vbg = 1.18942 :::*/*/*/*/
[14:36:29.353] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 158calibrated Vbg = 1.18283 :::*/*/*/*/
[14:36:29.353] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 149.1calibrated Vbg = 1.18814 :::*/*/*/*/
[14:36:29.353] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 149.2calibrated Vbg = 1.19563 :::*/*/*/*/
[14:36:29.353] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 151.8calibrated Vbg = 1.19944 :::*/*/*/*/
[14:36:29.353] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 155.1calibrated Vbg = 1.19187 :::*/*/*/*/
[14:36:29.356] <TB1> INFO: ----------------------------------------------------------------------
[14:36:29.356] <TB1> INFO: PixTestReadback::CalibrateIa()
[14:36:29.356] <TB1> INFO: ----------------------------------------------------------------------
[14:39:10.218] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C0.dat
[14:39:10.218] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C1.dat
[14:39:10.218] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C2.dat
[14:39:10.218] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C3.dat
[14:39:10.218] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C4.dat
[14:39:10.218] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C5.dat
[14:39:10.218] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C6.dat
[14:39:10.218] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C7.dat
[14:39:10.219] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C8.dat
[14:39:10.219] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C9.dat
[14:39:10.219] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C10.dat
[14:39:10.219] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C11.dat
[14:39:10.219] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C12.dat
[14:39:10.219] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C13.dat
[14:39:10.219] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C14.dat
[14:39:10.219] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//readbackCal_C15.dat
[14:39:10.251] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[14:39:10.253] <TB1> INFO: PixTestReadback::doTest() done
[14:39:10.253] <TB1> INFO: Decoding statistics:
[14:39:10.253] <TB1> INFO: General information:
[14:39:10.253] <TB1> INFO: 16bit words read: 1536
[14:39:10.253] <TB1> INFO: valid events total: 256
[14:39:10.253] <TB1> INFO: empty events: 256
[14:39:10.253] <TB1> INFO: valid events with pixels: 0
[14:39:10.253] <TB1> INFO: valid pixel hits: 0
[14:39:10.253] <TB1> INFO: Event errors: 0
[14:39:10.253] <TB1> INFO: start marker: 0
[14:39:10.254] <TB1> INFO: stop marker: 0
[14:39:10.254] <TB1> INFO: overflow: 0
[14:39:10.254] <TB1> INFO: invalid 5bit words: 0
[14:39:10.254] <TB1> INFO: invalid XOR eye diagram: 0
[14:39:10.254] <TB1> INFO: frame (failed synchr.): 0
[14:39:10.254] <TB1> INFO: idle data (no TBM trl): 0
[14:39:10.254] <TB1> INFO: no data (only TBM hdr): 0
[14:39:10.254] <TB1> INFO: TBM errors: 0
[14:39:10.254] <TB1> INFO: flawed TBM headers: 0
[14:39:10.254] <TB1> INFO: flawed TBM trailers: 0
[14:39:10.254] <TB1> INFO: event ID mismatches: 0
[14:39:10.254] <TB1> INFO: ROC errors: 0
[14:39:10.254] <TB1> INFO: missing ROC header(s): 0
[14:39:10.254] <TB1> INFO: misplaced readback start: 0
[14:39:10.254] <TB1> INFO: Pixel decoding errors: 0
[14:39:10.254] <TB1> INFO: pixel data incomplete: 0
[14:39:10.254] <TB1> INFO: pixel address: 0
[14:39:10.254] <TB1> INFO: pulse height fill bit: 0
[14:39:10.254] <TB1> INFO: buffer corruption: 0
[14:39:10.308] <TB1> INFO: ######################################################################
[14:39:10.308] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[14:39:10.308] <TB1> INFO: ######################################################################
[14:39:10.310] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[14:39:10.354] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:39:10.354] <TB1> INFO: run 1 of 1
[14:39:10.593] <TB1> INFO: Expecting 3120000 events.
[14:39:42.213] <TB1> INFO: 676480 events read in total (31027ms).











[14:40:12.693] <TB1> INFO: 1347605 events read in total (61507ms).











[14:40:42.906] <TB1> INFO: 2014825 events read in total (91720ms).











[14:41:13.511] <TB1> INFO: 2683040 events read in total (122325ms).











[14:41:33.401] <TB1> INFO: 3120000 events read in total (142216ms).
[14:41:33.507] <TB1> INFO: Test took 143154ms.
[14:42:01.528] <TB1> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 171 seconds
[14:42:01.528] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 1 1 0 0 0 0 0 0 13
[14:42:01.528] <TB1> INFO: separation cut (per ROC): 123 106 117 123 125 110 111 110 101 104 105 108 109 107 107 105
[14:42:01.528] <TB1> INFO: Decoding statistics:
[14:42:01.528] <TB1> INFO: General information:
[14:42:01.528] <TB1> INFO: 16bit words read: 0
[14:42:01.528] <TB1> INFO: valid events total: 0
[14:42:01.528] <TB1> INFO: empty events: 0
[14:42:01.528] <TB1> INFO: valid events with pixels: 0
[14:42:01.528] <TB1> INFO: valid pixel hits: 0
[14:42:01.528] <TB1> INFO: Event errors: 0
[14:42:01.528] <TB1> INFO: start marker: 0
[14:42:01.528] <TB1> INFO: stop marker: 0
[14:42:01.528] <TB1> INFO: overflow: 0
[14:42:01.528] <TB1> INFO: invalid 5bit words: 0
[14:42:01.528] <TB1> INFO: invalid XOR eye diagram: 0
[14:42:01.528] <TB1> INFO: frame (failed synchr.): 0
[14:42:01.528] <TB1> INFO: idle data (no TBM trl): 0
[14:42:01.528] <TB1> INFO: no data (only TBM hdr): 0
[14:42:01.528] <TB1> INFO: TBM errors: 0
[14:42:01.529] <TB1> INFO: flawed TBM headers: 0
[14:42:01.529] <TB1> INFO: flawed TBM trailers: 0
[14:42:01.529] <TB1> INFO: event ID mismatches: 0
[14:42:01.529] <TB1> INFO: ROC errors: 0
[14:42:01.529] <TB1> INFO: missing ROC header(s): 0
[14:42:01.529] <TB1> INFO: misplaced readback start: 0
[14:42:01.529] <TB1> INFO: Pixel decoding errors: 0
[14:42:01.529] <TB1> INFO: pixel data incomplete: 0
[14:42:01.529] <TB1> INFO: pixel address: 0
[14:42:01.529] <TB1> INFO: pulse height fill bit: 0
[14:42:01.529] <TB1> INFO: buffer corruption: 0
[14:42:01.569] <TB1> INFO: ######################################################################
[14:42:01.569] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:42:01.569] <TB1> INFO: ######################################################################
[14:42:01.569] <TB1> INFO: ----------------------------------------------------------------------
[14:42:01.569] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[14:42:01.569] <TB1> INFO: ----------------------------------------------------------------------
[14:42:01.569] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[14:42:01.584] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[14:42:01.584] <TB1> INFO: run 1 of 1
[14:42:01.836] <TB1> INFO: Expecting 36608000 events.
[14:42:25.956] <TB1> INFO: 709850 events read in total (23529ms).
[14:42:48.826] <TB1> INFO: 1397350 events read in total (46399ms).
[14:43:11.884] <TB1> INFO: 2089050 events read in total (69457ms).
[14:43:34.831] <TB1> INFO: 2776750 events read in total (92404ms).
[14:43:57.923] <TB1> INFO: 3467200 events read in total (115496ms).
[14:44:20.993] <TB1> INFO: 4156250 events read in total (138566ms).
[14:44:43.899] <TB1> INFO: 4847500 events read in total (161472ms).
[14:45:06.611] <TB1> INFO: 5534450 events read in total (184185ms).
[14:45:29.935] <TB1> INFO: 6225450 events read in total (207508ms).
[14:45:52.771] <TB1> INFO: 6913100 events read in total (230344ms).
[14:46:15.730] <TB1> INFO: 7602700 events read in total (253303ms).
[14:46:38.602] <TB1> INFO: 8292250 events read in total (276175ms).
[14:47:01.769] <TB1> INFO: 8982050 events read in total (299342ms).
[14:47:24.583] <TB1> INFO: 9669000 events read in total (322156ms).
[14:47:47.443] <TB1> INFO: 10356550 events read in total (345016ms).
[14:48:10.494] <TB1> INFO: 11041900 events read in total (368067ms).
[14:48:33.617] <TB1> INFO: 11728300 events read in total (391190ms).
[14:48:56.673] <TB1> INFO: 12414750 events read in total (414246ms).
[14:49:19.805] <TB1> INFO: 13100450 events read in total (437378ms).
[14:49:42.754] <TB1> INFO: 13784400 events read in total (460327ms).
[14:50:05.769] <TB1> INFO: 14468350 events read in total (483342ms).
[14:50:29.143] <TB1> INFO: 15153800 events read in total (506716ms).
[14:50:52.380] <TB1> INFO: 15839350 events read in total (529953ms).
[14:51:15.515] <TB1> INFO: 16524500 events read in total (553088ms).
[14:51:38.679] <TB1> INFO: 17208700 events read in total (576252ms).
[14:52:01.602] <TB1> INFO: 17888150 events read in total (599175ms).
[14:52:24.775] <TB1> INFO: 18568350 events read in total (622348ms).
[14:52:47.807] <TB1> INFO: 19247100 events read in total (645380ms).
[14:53:10.805] <TB1> INFO: 19926450 events read in total (668378ms).
[14:53:33.894] <TB1> INFO: 20606000 events read in total (691467ms).
[14:53:56.709] <TB1> INFO: 21284300 events read in total (714282ms).
[14:54:19.947] <TB1> INFO: 21963000 events read in total (737520ms).
[14:54:42.938] <TB1> INFO: 22640500 events read in total (760511ms).
[14:55:05.846] <TB1> INFO: 23318600 events read in total (783419ms).
[14:55:29.122] <TB1> INFO: 23997000 events read in total (806695ms).
[14:55:52.035] <TB1> INFO: 24675450 events read in total (829608ms).
[14:56:15.360] <TB1> INFO: 25354800 events read in total (852933ms).
[14:56:38.303] <TB1> INFO: 26032350 events read in total (875876ms).
[14:57:01.326] <TB1> INFO: 26707600 events read in total (898899ms).
[14:57:24.360] <TB1> INFO: 27384400 events read in total (921933ms).
[14:57:47.271] <TB1> INFO: 28060200 events read in total (944844ms).
[14:58:10.051] <TB1> INFO: 28736100 events read in total (967624ms).
[14:58:32.954] <TB1> INFO: 29409450 events read in total (990527ms).
[14:58:55.962] <TB1> INFO: 30086750 events read in total (1013535ms).
[14:59:18.706] <TB1> INFO: 30761850 events read in total (1036279ms).
[14:59:41.782] <TB1> INFO: 31437500 events read in total (1059355ms).
[15:00:04.918] <TB1> INFO: 32111300 events read in total (1082491ms).
[15:00:27.679] <TB1> INFO: 32786850 events read in total (1105252ms).
[15:00:50.850] <TB1> INFO: 33464250 events read in total (1128423ms).
[15:01:14.044] <TB1> INFO: 34142500 events read in total (1151617ms).
[15:01:36.994] <TB1> INFO: 34820800 events read in total (1174567ms).
[15:01:59.902] <TB1> INFO: 35498150 events read in total (1197475ms).
[15:02:23.049] <TB1> INFO: 36183700 events read in total (1220622ms).
[15:02:37.174] <TB1> INFO: 36608000 events read in total (1234747ms).
[15:02:37.286] <TB1> INFO: Test took 1235702ms.
[15:02:37.688] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:39.552] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:41.646] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:43.590] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:45.499] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:47.415] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:49.733] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:51.541] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:53.421] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:55.196] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:57.028] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:02:58.791] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:00.589] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:02.224] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:04.067] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:05.909] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[15:03:07.883] <TB1> INFO: PixTestScurves::scurves() done
[15:03:07.883] <TB1> INFO: Vcal mean: 130.07 121.76 129.19 133.07 135.46 126.76 119.06 124.25 125.93 132.67 130.60 128.76 133.12 133.52 127.08 124.82
[15:03:07.883] <TB1> INFO: Vcal RMS: 6.23 6.55 5.82 6.05 6.56 7.82 5.73 6.28 6.71 6.62 6.68 9.43 6.55 6.07 7.82 6.19
[15:03:07.883] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1266 seconds
[15:03:07.883] <TB1> INFO: Decoding statistics:
[15:03:07.883] <TB1> INFO: General information:
[15:03:07.883] <TB1> INFO: 16bit words read: 0
[15:03:07.883] <TB1> INFO: valid events total: 0
[15:03:07.883] <TB1> INFO: empty events: 0
[15:03:07.883] <TB1> INFO: valid events with pixels: 0
[15:03:07.883] <TB1> INFO: valid pixel hits: 0
[15:03:07.883] <TB1> INFO: Event errors: 0
[15:03:07.883] <TB1> INFO: start marker: 0
[15:03:07.883] <TB1> INFO: stop marker: 0
[15:03:07.883] <TB1> INFO: overflow: 0
[15:03:07.883] <TB1> INFO: invalid 5bit words: 0
[15:03:07.883] <TB1> INFO: invalid XOR eye diagram: 0
[15:03:07.883] <TB1> INFO: frame (failed synchr.): 0
[15:03:07.883] <TB1> INFO: idle data (no TBM trl): 0
[15:03:07.883] <TB1> INFO: no data (only TBM hdr): 0
[15:03:07.883] <TB1> INFO: TBM errors: 0
[15:03:07.883] <TB1> INFO: flawed TBM headers: 0
[15:03:07.883] <TB1> INFO: flawed TBM trailers: 0
[15:03:07.883] <TB1> INFO: event ID mismatches: 0
[15:03:07.883] <TB1> INFO: ROC errors: 0
[15:03:07.883] <TB1> INFO: missing ROC header(s): 0
[15:03:07.883] <TB1> INFO: misplaced readback start: 0
[15:03:07.883] <TB1> INFO: Pixel decoding errors: 0
[15:03:07.883] <TB1> INFO: pixel data incomplete: 0
[15:03:07.883] <TB1> INFO: pixel address: 0
[15:03:07.883] <TB1> INFO: pulse height fill bit: 0
[15:03:07.883] <TB1> INFO: buffer corruption: 0
[15:03:07.953] <TB1> INFO: ######################################################################
[15:03:07.953] <TB1> INFO: PixTestTrim::doTest()
[15:03:07.953] <TB1> INFO: ######################################################################
[15:03:07.954] <TB1> INFO: ----------------------------------------------------------------------
[15:03:07.954] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[15:03:07.954] <TB1> INFO: ----------------------------------------------------------------------
[15:03:07.998] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[15:03:07.998] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:03:08.011] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:03:08.011] <TB1> INFO: run 1 of 1
[15:03:08.300] <TB1> INFO: Expecting 5025280 events.
[15:03:39.274] <TB1> INFO: 834928 events read in total (30369ms).
[15:04:09.514] <TB1> INFO: 1667960 events read in total (60610ms).
[15:04:39.382] <TB1> INFO: 2497816 events read in total (90477ms).
[15:05:09.140] <TB1> INFO: 3324008 events read in total (120235ms).
[15:05:39.370] <TB1> INFO: 4146648 events read in total (150466ms).
[15:06:09.660] <TB1> INFO: 4968304 events read in total (180755ms).
[15:06:12.219] <TB1> INFO: 5025280 events read in total (183314ms).
[15:06:12.293] <TB1> INFO: Test took 184282ms.
[15:06:30.416] <TB1> INFO: ROC 0 VthrComp = 131
[15:06:30.416] <TB1> INFO: ROC 1 VthrComp = 116
[15:06:30.416] <TB1> INFO: ROC 2 VthrComp = 124
[15:06:30.417] <TB1> INFO: ROC 3 VthrComp = 131
[15:06:30.417] <TB1> INFO: ROC 4 VthrComp = 130
[15:06:30.417] <TB1> INFO: ROC 5 VthrComp = 121
[15:06:30.417] <TB1> INFO: ROC 6 VthrComp = 122
[15:06:30.417] <TB1> INFO: ROC 7 VthrComp = 120
[15:06:30.417] <TB1> INFO: ROC 8 VthrComp = 115
[15:06:30.417] <TB1> INFO: ROC 9 VthrComp = 120
[15:06:30.417] <TB1> INFO: ROC 10 VthrComp = 126
[15:06:30.417] <TB1> INFO: ROC 11 VthrComp = 114
[15:06:30.417] <TB1> INFO: ROC 12 VthrComp = 129
[15:06:30.417] <TB1> INFO: ROC 13 VthrComp = 126
[15:06:30.418] <TB1> INFO: ROC 14 VthrComp = 127
[15:06:30.418] <TB1> INFO: ROC 15 VthrComp = 119
[15:06:30.743] <TB1> INFO: Expecting 41600 events.
[15:06:34.217] <TB1> INFO: 41600 events read in total (2882ms).
[15:06:34.219] <TB1> INFO: Test took 3800ms.
[15:06:34.229] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[15:06:34.229] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:06:34.244] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:06:34.244] <TB1> INFO: run 1 of 1
[15:06:34.521] <TB1> INFO: Expecting 5025280 events.
[15:07:01.672] <TB1> INFO: 592936 events read in total (26559ms).
[15:07:27.481] <TB1> INFO: 1185448 events read in total (52368ms).
[15:07:52.759] <TB1> INFO: 1777368 events read in total (77646ms).
[15:08:18.153] <TB1> INFO: 2368896 events read in total (103040ms).
[15:08:44.756] <TB1> INFO: 2958288 events read in total (129643ms).
[15:09:10.364] <TB1> INFO: 3546216 events read in total (155251ms).
[15:09:35.977] <TB1> INFO: 4133232 events read in total (180865ms).
[15:10:01.723] <TB1> INFO: 4719344 events read in total (206610ms).
[15:10:15.528] <TB1> INFO: 5025280 events read in total (220415ms).
[15:10:15.627] <TB1> INFO: Test took 221384ms.
[15:10:42.898] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 61.2514 for pixel 20/6 mean/min/max = 46.8219/32.3689/61.2748
[15:10:42.899] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 63.3996 for pixel 12/13 mean/min/max = 48.1431/32.7721/63.5142
[15:10:42.899] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 63.3627 for pixel 6/0 mean/min/max = 47.9388/32.382/63.4957
[15:10:42.900] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 61.9948 for pixel 1/8 mean/min/max = 47.2694/32.4915/62.0474
[15:10:42.900] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 62.9338 for pixel 24/70 mean/min/max = 47.6298/32.2158/63.0438
[15:10:42.901] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 66.7845 for pixel 18/5 mean/min/max = 49.4914/32.1532/66.8296
[15:10:42.901] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 59.2191 for pixel 14/47 mean/min/max = 45.9784/32.3308/59.6259
[15:10:42.902] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 62.1943 for pixel 5/79 mean/min/max = 47.7554/33.2397/62.2712
[15:10:42.902] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 66.4941 for pixel 2/17 mean/min/max = 49.4899/32.4166/66.5631
[15:10:42.903] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 66.0947 for pixel 0/13 mean/min/max = 50.0792/33.9298/66.2286
[15:10:42.903] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 63.2636 for pixel 14/3 mean/min/max = 48.0079/32.6969/63.3188
[15:10:42.904] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 68.556 for pixel 3/2 mean/min/max = 49.9255/31.0556/68.7953
[15:10:42.904] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 62.0651 for pixel 11/37 mean/min/max = 46.6829/31.123/62.2429
[15:10:42.905] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 62.4573 for pixel 46/10 mean/min/max = 47.0295/31.5054/62.5536
[15:10:42.905] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 67.6548 for pixel 7/71 mean/min/max = 48.6815/29.6483/67.7147
[15:10:42.906] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 61.8749 for pixel 10/26 mean/min/max = 47.259/32.5322/61.9858
[15:10:42.906] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:10:42.995] <TB1> INFO: Expecting 411648 events.
[15:10:52.570] <TB1> INFO: 411648 events read in total (8984ms).
[15:10:52.580] <TB1> INFO: Expecting 411648 events.
[15:11:01.710] <TB1> INFO: 411648 events read in total (8727ms).
[15:11:01.721] <TB1> INFO: Expecting 411648 events.
[15:11:10.955] <TB1> INFO: 411648 events read in total (8831ms).
[15:11:10.969] <TB1> INFO: Expecting 411648 events.
[15:11:20.363] <TB1> INFO: 411648 events read in total (8991ms).
[15:11:20.382] <TB1> INFO: Expecting 411648 events.
[15:11:29.800] <TB1> INFO: 411648 events read in total (9015ms).
[15:11:29.818] <TB1> INFO: Expecting 411648 events.
[15:11:39.269] <TB1> INFO: 411648 events read in total (9047ms).
[15:11:39.295] <TB1> INFO: Expecting 411648 events.
[15:11:48.627] <TB1> INFO: 411648 events read in total (8928ms).
[15:11:48.651] <TB1> INFO: Expecting 411648 events.
[15:11:58.041] <TB1> INFO: 411648 events read in total (8987ms).
[15:11:58.068] <TB1> INFO: Expecting 411648 events.
[15:12:07.465] <TB1> INFO: 411648 events read in total (8994ms).
[15:12:07.501] <TB1> INFO: Expecting 411648 events.
[15:12:16.865] <TB1> INFO: 411648 events read in total (8961ms).
[15:12:16.898] <TB1> INFO: Expecting 411648 events.
[15:12:26.375] <TB1> INFO: 411648 events read in total (9074ms).
[15:12:26.429] <TB1> INFO: Expecting 411648 events.
[15:12:35.752] <TB1> INFO: 411648 events read in total (8920ms).
[15:12:35.791] <TB1> INFO: Expecting 411648 events.
[15:12:45.126] <TB1> INFO: 411648 events read in total (8931ms).
[15:12:45.173] <TB1> INFO: Expecting 411648 events.
[15:12:54.573] <TB1> INFO: 411648 events read in total (8996ms).
[15:12:54.619] <TB1> INFO: Expecting 411648 events.
[15:13:04.105] <TB1> INFO: 411648 events read in total (9083ms).
[15:13:04.201] <TB1> INFO: Expecting 411648 events.
[15:13:13.546] <TB1> INFO: 411648 events read in total (8942ms).
[15:13:13.598] <TB1> INFO: Test took 150692ms.
[15:13:14.249] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[15:13:14.262] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:13:14.262] <TB1> INFO: run 1 of 1
[15:13:14.504] <TB1> INFO: Expecting 5025280 events.
[15:13:40.996] <TB1> INFO: 592632 events read in total (25900ms).
[15:14:06.982] <TB1> INFO: 1182520 events read in total (51886ms).
[15:14:33.455] <TB1> INFO: 1771704 events read in total (78359ms).
[15:15:00.172] <TB1> INFO: 2359944 events read in total (105076ms).
[15:15:27.169] <TB1> INFO: 2948448 events read in total (132073ms).
[15:15:53.725] <TB1> INFO: 3539200 events read in total (158629ms).
[15:16:20.479] <TB1> INFO: 4131688 events read in total (185383ms).
[15:16:46.509] <TB1> INFO: 4720416 events read in total (211414ms).
[15:17:00.141] <TB1> INFO: 5025280 events read in total (225045ms).
[15:17:00.327] <TB1> INFO: Test took 226065ms.
[15:17:24.083] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 0.591855 .. 146.917877
[15:17:24.414] <TB1> INFO: Expecting 208000 events.
[15:17:34.190] <TB1> INFO: 208000 events read in total (9184ms).
[15:17:34.192] <TB1> INFO: Test took 10108ms.
[15:17:34.254] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 0 .. 156 (-1/-1) hits flags = 528 (plus default)
[15:17:34.267] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:17:34.267] <TB1> INFO: run 1 of 1
[15:17:34.545] <TB1> INFO: Expecting 5224960 events.
[15:18:01.134] <TB1> INFO: 585704 events read in total (25997ms).
[15:18:27.100] <TB1> INFO: 1171216 events read in total (51964ms).
[15:18:53.300] <TB1> INFO: 1756296 events read in total (78163ms).
[15:19:19.395] <TB1> INFO: 2341592 events read in total (104258ms).
[15:19:45.377] <TB1> INFO: 2927208 events read in total (130240ms).
[15:20:11.359] <TB1> INFO: 3512704 events read in total (156222ms).
[15:20:37.628] <TB1> INFO: 4097728 events read in total (182491ms).
[15:21:03.593] <TB1> INFO: 4682616 events read in total (208456ms).
[15:21:28.507] <TB1> INFO: 5224960 events read in total (233371ms).
[15:21:28.667] <TB1> INFO: Test took 234401ms.
[15:21:59.852] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 25.960499 .. 47.930011
[15:22:00.178] <TB1> INFO: Expecting 208000 events.
[15:22:10.411] <TB1> INFO: 208000 events read in total (9642ms).
[15:22:10.413] <TB1> INFO: Test took 10559ms.
[15:22:10.462] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 15 .. 57 (-1/-1) hits flags = 528 (plus default)
[15:22:10.476] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:22:10.476] <TB1> INFO: run 1 of 1
[15:22:10.755] <TB1> INFO: Expecting 1431040 events.
[15:22:39.303] <TB1> INFO: 661720 events read in total (27957ms).
[15:23:07.515] <TB1> INFO: 1321216 events read in total (56170ms).
[15:23:12.520] <TB1> INFO: 1431040 events read in total (61175ms).
[15:23:12.557] <TB1> INFO: Test took 62082ms.
[15:23:28.241] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 28.542480 .. 50.767020
[15:23:28.526] <TB1> INFO: Expecting 208000 events.
[15:23:38.398] <TB1> INFO: 208000 events read in total (9281ms).
[15:23:38.399] <TB1> INFO: Test took 10155ms.
[15:23:38.454] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 18 .. 60 (-1/-1) hits flags = 528 (plus default)
[15:23:38.469] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:23:38.469] <TB1> INFO: run 1 of 1
[15:23:38.747] <TB1> INFO: Expecting 1431040 events.
[15:24:06.842] <TB1> INFO: 639096 events read in total (27503ms).
[15:24:34.178] <TB1> INFO: 1277496 events read in total (54839ms).
[15:24:41.306] <TB1> INFO: 1431040 events read in total (61967ms).
[15:24:41.343] <TB1> INFO: Test took 62875ms.
[15:24:57.081] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 26.780037 .. 53.971607
[15:24:57.339] <TB1> INFO: Expecting 208000 events.
[15:25:07.232] <TB1> INFO: 208000 events read in total (9301ms).
[15:25:07.233] <TB1> INFO: Test took 10150ms.
[15:25:07.281] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 16 .. 63 (-1/-1) hits flags = 528 (plus default)
[15:25:07.294] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:25:07.294] <TB1> INFO: run 1 of 1
[15:25:07.574] <TB1> INFO: Expecting 1597440 events.
[15:25:35.524] <TB1> INFO: 637440 events read in total (27359ms).
[15:26:02.829] <TB1> INFO: 1273656 events read in total (54664ms).
[15:26:16.743] <TB1> INFO: 1597440 events read in total (68578ms).
[15:26:16.786] <TB1> INFO: Test took 69492ms.
[15:26:33.582] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[15:26:33.582] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[15:26:33.596] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:26:33.596] <TB1> INFO: run 1 of 1
[15:26:33.920] <TB1> INFO: Expecting 1364480 events.
[15:27:02.402] <TB1> INFO: 669200 events read in total (27890ms).
[15:27:30.383] <TB1> INFO: 1336760 events read in total (55871ms).
[15:27:31.943] <TB1> INFO: 1364480 events read in total (57431ms).
[15:27:31.975] <TB1> INFO: Test took 58380ms.
[15:27:44.709] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C0.dat
[15:27:44.709] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C1.dat
[15:27:44.709] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C2.dat
[15:27:44.709] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C3.dat
[15:27:44.709] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C4.dat
[15:27:44.709] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C5.dat
[15:27:44.709] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C6.dat
[15:27:44.709] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C7.dat
[15:27:44.709] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C8.dat
[15:27:44.710] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C9.dat
[15:27:44.710] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C10.dat
[15:27:44.710] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C11.dat
[15:27:44.710] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C12.dat
[15:27:44.710] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C13.dat
[15:27:44.710] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C14.dat
[15:27:44.710] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C15.dat
[15:27:44.710] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C0.dat
[15:27:44.715] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C1.dat
[15:27:44.720] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C2.dat
[15:27:44.725] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C3.dat
[15:27:44.730] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C4.dat
[15:27:44.734] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C5.dat
[15:27:44.739] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C6.dat
[15:27:44.744] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C7.dat
[15:27:44.748] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C8.dat
[15:27:44.753] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C9.dat
[15:27:44.758] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C10.dat
[15:27:44.763] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C11.dat
[15:27:44.767] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C12.dat
[15:27:44.772] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C13.dat
[15:27:44.777] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C14.dat
[15:27:44.782] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters35_C15.dat
[15:27:44.786] <TB1> INFO: PixTestTrim::trimTest() done
[15:27:44.786] <TB1> INFO: vtrim: 150 130 122 145 126 130 126 123 128 125 136 137 128 131 147 133
[15:27:44.786] <TB1> INFO: vthrcomp: 131 116 124 131 130 121 122 120 115 120 126 114 129 126 127 119
[15:27:44.786] <TB1> INFO: vcal mean: 34.99 35.48 35.18 35.04 35.16 36.02 35.09 34.98 36.62 35.99 35.29 35.50 35.92 35.40 35.53 35.07
[15:27:44.786] <TB1> INFO: vcal RMS: 1.07 1.74 1.29 1.51 1.30 2.28 1.05 1.13 2.65 2.33 1.47 1.93 2.17 1.71 1.82 1.17
[15:27:44.786] <TB1> INFO: bits mean: 9.66 9.38 8.98 9.84 9.18 9.97 9.40 8.42 9.71 9.20 9.64 9.61 10.16 9.95 9.65 9.76
[15:27:44.786] <TB1> INFO: bits RMS: 2.57 2.73 2.86 2.53 2.76 2.48 2.75 2.92 2.79 2.70 2.54 2.59 2.70 2.65 2.83 2.46
[15:27:44.794] <TB1> INFO: ----------------------------------------------------------------------
[15:27:44.794] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[15:27:44.794] <TB1> INFO: ----------------------------------------------------------------------
[15:27:44.797] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[15:27:44.810] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:27:44.810] <TB1> INFO: run 1 of 1
[15:27:45.046] <TB1> INFO: Expecting 4160000 events.
[15:28:18.346] <TB1> INFO: 783710 events read in total (32708ms).
[15:28:50.325] <TB1> INFO: 1560685 events read in total (64687ms).
[15:29:22.349] <TB1> INFO: 2330780 events read in total (96711ms).
[15:29:54.290] <TB1> INFO: 3095355 events read in total (128652ms).
[15:30:26.355] <TB1> INFO: 3856760 events read in total (160717ms).
[15:30:39.324] <TB1> INFO: 4160000 events read in total (173686ms).
[15:30:39.394] <TB1> INFO: Test took 174583ms.
[15:31:07.330] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 207 (-1/-1) hits flags = 528 (plus default)
[15:31:07.343] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:31:07.343] <TB1> INFO: run 1 of 1
[15:31:07.580] <TB1> INFO: Expecting 4326400 events.
[15:31:39.601] <TB1> INFO: 743960 events read in total (31429ms).
[15:32:11.064] <TB1> INFO: 1483145 events read in total (62892ms).
[15:32:42.699] <TB1> INFO: 2218235 events read in total (94527ms).
[15:33:14.092] <TB1> INFO: 2948715 events read in total (125920ms).
[15:33:45.229] <TB1> INFO: 3676640 events read in total (157057ms).
[15:34:13.224] <TB1> INFO: 4326400 events read in total (185052ms).
[15:34:13.329] <TB1> INFO: Test took 185985ms.
[15:34:42.037] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 209 (-1/-1) hits flags = 528 (plus default)
[15:34:42.051] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:34:42.051] <TB1> INFO: run 1 of 1
[15:34:42.377] <TB1> INFO: Expecting 4368000 events.
[15:35:14.338] <TB1> INFO: 741505 events read in total (31369ms).
[15:35:46.622] <TB1> INFO: 1478810 events read in total (63653ms).
[15:36:18.327] <TB1> INFO: 2211955 events read in total (95359ms).
[15:36:49.962] <TB1> INFO: 2940715 events read in total (126993ms).
[15:37:21.323] <TB1> INFO: 3667175 events read in total (158354ms).
[15:37:51.879] <TB1> INFO: 4368000 events read in total (188910ms).
[15:37:51.974] <TB1> INFO: Test took 189923ms.
[15:38:21.017] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 216 (-1/-1) hits flags = 528 (plus default)
[15:38:21.030] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:38:21.030] <TB1> INFO: run 1 of 1
[15:38:21.266] <TB1> INFO: Expecting 4513600 events.
[15:38:53.300] <TB1> INFO: 732925 events read in total (31443ms).
[15:39:24.491] <TB1> INFO: 1461755 events read in total (62634ms).
[15:39:55.940] <TB1> INFO: 2187025 events read in total (94084ms).
[15:40:27.332] <TB1> INFO: 2907240 events read in total (125475ms).
[15:40:58.862] <TB1> INFO: 3625755 events read in total (157005ms).
[15:41:29.967] <TB1> INFO: 4344240 events read in total (188110ms).
[15:41:37.760] <TB1> INFO: 4513600 events read in total (195903ms).
[15:41:37.855] <TB1> INFO: Test took 196825ms.
[15:42:03.245] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 214 (-1/-1) hits flags = 528 (plus default)
[15:42:03.258] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[15:42:03.258] <TB1> INFO: run 1 of 1
[15:42:03.533] <TB1> INFO: Expecting 4472000 events.
[15:42:35.701] <TB1> INFO: 735475 events read in total (31577ms).
[15:43:06.744] <TB1> INFO: 1467220 events read in total (62620ms).
[15:43:38.259] <TB1> INFO: 2194700 events read in total (94135ms).
[15:44:09.439] <TB1> INFO: 2917285 events read in total (125315ms).
[15:44:40.644] <TB1> INFO: 3638535 events read in total (156520ms).
[15:45:11.812] <TB1> INFO: 4359395 events read in total (187688ms).
[15:45:16.883] <TB1> INFO: 4472000 events read in total (192759ms).
[15:45:16.973] <TB1> INFO: Test took 193715ms.
[15:45:43.376] <TB1> INFO: PixTestTrim::trimBitTest() done
[15:45:43.378] <TB1> INFO: PixTestTrim::doTest() done, duration: 2555 seconds
[15:45:43.378] <TB1> INFO: Decoding statistics:
[15:45:43.378] <TB1> INFO: General information:
[15:45:43.378] <TB1> INFO: 16bit words read: 0
[15:45:43.378] <TB1> INFO: valid events total: 0
[15:45:43.378] <TB1> INFO: empty events: 0
[15:45:43.378] <TB1> INFO: valid events with pixels: 0
[15:45:43.378] <TB1> INFO: valid pixel hits: 0
[15:45:43.378] <TB1> INFO: Event errors: 0
[15:45:43.378] <TB1> INFO: start marker: 0
[15:45:43.378] <TB1> INFO: stop marker: 0
[15:45:43.378] <TB1> INFO: overflow: 0
[15:45:43.378] <TB1> INFO: invalid 5bit words: 0
[15:45:43.378] <TB1> INFO: invalid XOR eye diagram: 0
[15:45:43.378] <TB1> INFO: frame (failed synchr.): 0
[15:45:43.378] <TB1> INFO: idle data (no TBM trl): 0
[15:45:43.378] <TB1> INFO: no data (only TBM hdr): 0
[15:45:43.378] <TB1> INFO: TBM errors: 0
[15:45:43.378] <TB1> INFO: flawed TBM headers: 0
[15:45:43.378] <TB1> INFO: flawed TBM trailers: 0
[15:45:43.378] <TB1> INFO: event ID mismatches: 0
[15:45:43.378] <TB1> INFO: ROC errors: 0
[15:45:43.378] <TB1> INFO: missing ROC header(s): 0
[15:45:43.378] <TB1> INFO: misplaced readback start: 0
[15:45:43.378] <TB1> INFO: Pixel decoding errors: 0
[15:45:43.378] <TB1> INFO: pixel data incomplete: 0
[15:45:43.378] <TB1> INFO: pixel address: 0
[15:45:43.378] <TB1> INFO: pulse height fill bit: 0
[15:45:43.378] <TB1> INFO: buffer corruption: 0
[15:45:44.124] <TB1> INFO: ######################################################################
[15:45:44.124] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[15:45:44.124] <TB1> INFO: ######################################################################
[15:45:44.361] <TB1> INFO: Expecting 41600 events.
[15:45:47.808] <TB1> INFO: 41600 events read in total (2854ms).
[15:45:47.808] <TB1> INFO: Test took 3683ms.
[15:45:48.250] <TB1> INFO: Expecting 41600 events.
[15:45:51.777] <TB1> INFO: 41600 events read in total (2935ms).
[15:45:51.778] <TB1> INFO: Test took 3765ms.
[15:45:52.068] <TB1> INFO: Expecting 41600 events.
[15:45:55.748] <TB1> INFO: 41600 events read in total (3089ms).
[15:45:55.749] <TB1> INFO: Test took 3947ms.
[15:45:56.041] <TB1> INFO: Expecting 41600 events.
[15:45:59.519] <TB1> INFO: 41600 events read in total (2886ms).
[15:45:59.520] <TB1> INFO: Test took 3744ms.
[15:45:59.810] <TB1> INFO: Expecting 41600 events.
[15:46:03.267] <TB1> INFO: 41600 events read in total (2865ms).
[15:46:03.268] <TB1> INFO: Test took 3723ms.
[15:46:03.566] <TB1> INFO: Expecting 41600 events.
[15:46:07.173] <TB1> INFO: 41600 events read in total (3015ms).
[15:46:07.174] <TB1> INFO: Test took 3882ms.
[15:46:07.528] <TB1> INFO: Expecting 41600 events.
[15:46:11.106] <TB1> INFO: 41600 events read in total (2987ms).
[15:46:11.108] <TB1> INFO: Test took 3905ms.
[15:46:11.397] <TB1> INFO: Expecting 41600 events.
[15:46:14.974] <TB1> INFO: 41600 events read in total (2985ms).
[15:46:14.975] <TB1> INFO: Test took 3843ms.
[15:46:15.264] <TB1> INFO: Expecting 41600 events.
[15:46:18.801] <TB1> INFO: 41600 events read in total (2945ms).
[15:46:18.802] <TB1> INFO: Test took 3802ms.
[15:46:19.091] <TB1> INFO: Expecting 41600 events.
[15:46:22.561] <TB1> INFO: 41600 events read in total (2878ms).
[15:46:22.562] <TB1> INFO: Test took 3736ms.
[15:46:22.851] <TB1> INFO: Expecting 41600 events.
[15:46:26.361] <TB1> INFO: 41600 events read in total (2918ms).
[15:46:26.362] <TB1> INFO: Test took 3776ms.
[15:46:26.651] <TB1> INFO: Expecting 41600 events.
[15:46:30.185] <TB1> INFO: 41600 events read in total (2942ms).
[15:46:30.186] <TB1> INFO: Test took 3800ms.
[15:46:30.503] <TB1> INFO: Expecting 41600 events.
[15:46:34.107] <TB1> INFO: 41600 events read in total (3012ms).
[15:46:34.108] <TB1> INFO: Test took 3896ms.
[15:46:34.398] <TB1> INFO: Expecting 41600 events.
[15:46:37.918] <TB1> INFO: 41600 events read in total (2929ms).
[15:46:37.919] <TB1> INFO: Test took 3787ms.
[15:46:38.208] <TB1> INFO: Expecting 41600 events.
[15:46:41.685] <TB1> INFO: 41600 events read in total (2885ms).
[15:46:41.692] <TB1> INFO: Test took 3749ms.
[15:46:41.986] <TB1> INFO: Expecting 41600 events.
[15:46:45.543] <TB1> INFO: 41600 events read in total (2966ms).
[15:46:45.544] <TB1> INFO: Test took 3823ms.
[15:46:45.836] <TB1> INFO: Expecting 41600 events.
[15:46:49.298] <TB1> INFO: 41600 events read in total (2871ms).
[15:46:49.299] <TB1> INFO: Test took 3728ms.
[15:46:49.588] <TB1> INFO: Expecting 41600 events.
[15:46:53.073] <TB1> INFO: 41600 events read in total (2893ms).
[15:46:53.074] <TB1> INFO: Test took 3751ms.
[15:46:53.385] <TB1> INFO: Expecting 41600 events.
[15:46:56.864] <TB1> INFO: 41600 events read in total (2888ms).
[15:46:56.866] <TB1> INFO: Test took 3765ms.
[15:46:57.158] <TB1> INFO: Expecting 41600 events.
[15:47:00.664] <TB1> INFO: 41600 events read in total (2915ms).
[15:47:00.665] <TB1> INFO: Test took 3772ms.
[15:47:00.954] <TB1> INFO: Expecting 41600 events.
[15:47:04.478] <TB1> INFO: 41600 events read in total (2932ms).
[15:47:04.479] <TB1> INFO: Test took 3790ms.
[15:47:04.769] <TB1> INFO: Expecting 41600 events.
[15:47:08.264] <TB1> INFO: 41600 events read in total (2903ms).
[15:47:08.265] <TB1> INFO: Test took 3761ms.
[15:47:08.554] <TB1> INFO: Expecting 41600 events.
[15:47:12.099] <TB1> INFO: 41600 events read in total (2953ms).
[15:47:12.100] <TB1> INFO: Test took 3811ms.
[15:47:12.390] <TB1> INFO: Expecting 41600 events.
[15:47:15.963] <TB1> INFO: 41600 events read in total (2982ms).
[15:47:15.964] <TB1> INFO: Test took 3839ms.
[15:47:16.253] <TB1> INFO: Expecting 41600 events.
[15:47:19.897] <TB1> INFO: 41600 events read in total (3052ms).
[15:47:19.898] <TB1> INFO: Test took 3910ms.
[15:47:20.203] <TB1> INFO: Expecting 41600 events.
[15:47:23.890] <TB1> INFO: 41600 events read in total (3095ms).
[15:47:23.891] <TB1> INFO: Test took 3968ms.
[15:47:24.185] <TB1> INFO: Expecting 41600 events.
[15:47:27.757] <TB1> INFO: 41600 events read in total (2981ms).
[15:47:27.758] <TB1> INFO: Test took 3838ms.
[15:47:28.047] <TB1> INFO: Expecting 41600 events.
[15:47:31.564] <TB1> INFO: 41600 events read in total (2926ms).
[15:47:31.565] <TB1> INFO: Test took 3783ms.
[15:47:31.856] <TB1> INFO: Expecting 41600 events.
[15:47:35.339] <TB1> INFO: 41600 events read in total (2891ms).
[15:47:35.340] <TB1> INFO: Test took 3748ms.
[15:47:35.629] <TB1> INFO: Expecting 2560 events.
[15:47:36.522] <TB1> INFO: 2560 events read in total (301ms).
[15:47:36.522] <TB1> INFO: Test took 1170ms.
[15:47:36.831] <TB1> INFO: Expecting 2560 events.
[15:47:37.718] <TB1> INFO: 2560 events read in total (295ms).
[15:47:37.719] <TB1> INFO: Test took 1197ms.
[15:47:38.025] <TB1> INFO: Expecting 2560 events.
[15:47:38.914] <TB1> INFO: 2560 events read in total (297ms).
[15:47:38.915] <TB1> INFO: Test took 1196ms.
[15:47:39.223] <TB1> INFO: Expecting 2560 events.
[15:47:40.110] <TB1> INFO: 2560 events read in total (295ms).
[15:47:40.110] <TB1> INFO: Test took 1195ms.
[15:47:40.417] <TB1> INFO: Expecting 2560 events.
[15:47:41.305] <TB1> INFO: 2560 events read in total (296ms).
[15:47:41.305] <TB1> INFO: Test took 1194ms.
[15:47:41.613] <TB1> INFO: Expecting 2560 events.
[15:47:42.497] <TB1> INFO: 2560 events read in total (292ms).
[15:47:42.497] <TB1> INFO: Test took 1191ms.
[15:47:42.806] <TB1> INFO: Expecting 2560 events.
[15:47:43.686] <TB1> INFO: 2560 events read in total (288ms).
[15:47:43.686] <TB1> INFO: Test took 1188ms.
[15:47:43.995] <TB1> INFO: Expecting 2560 events.
[15:47:44.878] <TB1> INFO: 2560 events read in total (291ms).
[15:47:44.878] <TB1> INFO: Test took 1191ms.
[15:47:45.185] <TB1> INFO: Expecting 2560 events.
[15:47:46.072] <TB1> INFO: 2560 events read in total (295ms).
[15:47:46.072] <TB1> INFO: Test took 1193ms.
[15:47:46.380] <TB1> INFO: Expecting 2560 events.
[15:47:47.268] <TB1> INFO: 2560 events read in total (296ms).
[15:47:47.269] <TB1> INFO: Test took 1196ms.
[15:47:47.578] <TB1> INFO: Expecting 2560 events.
[15:47:48.459] <TB1> INFO: 2560 events read in total (289ms).
[15:47:48.459] <TB1> INFO: Test took 1190ms.
[15:47:48.766] <TB1> INFO: Expecting 2560 events.
[15:47:49.647] <TB1> INFO: 2560 events read in total (290ms).
[15:47:49.647] <TB1> INFO: Test took 1187ms.
[15:47:49.954] <TB1> INFO: Expecting 2560 events.
[15:47:50.842] <TB1> INFO: 2560 events read in total (296ms).
[15:47:50.842] <TB1> INFO: Test took 1194ms.
[15:47:51.149] <TB1> INFO: Expecting 2560 events.
[15:47:52.039] <TB1> INFO: 2560 events read in total (298ms).
[15:47:52.040] <TB1> INFO: Test took 1197ms.
[15:47:52.347] <TB1> INFO: Expecting 2560 events.
[15:47:53.230] <TB1> INFO: 2560 events read in total (291ms).
[15:47:53.230] <TB1> INFO: Test took 1187ms.
[15:47:53.539] <TB1> INFO: Expecting 2560 events.
[15:47:54.425] <TB1> INFO: 2560 events read in total (295ms).
[15:47:54.425] <TB1> INFO: Test took 1194ms.
[15:47:54.430] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:47:54.737] <TB1> INFO: Expecting 655360 events.
[15:48:09.741] <TB1> INFO: 655360 events read in total (14412ms).
[15:48:09.756] <TB1> INFO: Expecting 655360 events.
[15:48:24.640] <TB1> INFO: 655360 events read in total (14481ms).
[15:48:24.659] <TB1> INFO: Expecting 655360 events.
[15:48:39.323] <TB1> INFO: 655360 events read in total (14261ms).
[15:48:39.347] <TB1> INFO: Expecting 655360 events.
[15:48:54.085] <TB1> INFO: 655360 events read in total (14335ms).
[15:48:54.113] <TB1> INFO: Expecting 655360 events.
[15:49:08.919] <TB1> INFO: 655360 events read in total (14403ms).
[15:49:08.950] <TB1> INFO: Expecting 655360 events.
[15:49:23.584] <TB1> INFO: 655360 events read in total (14231ms).
[15:49:23.625] <TB1> INFO: Expecting 655360 events.
[15:49:38.322] <TB1> INFO: 655360 events read in total (14295ms).
[15:49:38.384] <TB1> INFO: Expecting 655360 events.
[15:49:53.047] <TB1> INFO: 655360 events read in total (14260ms).
[15:49:53.101] <TB1> INFO: Expecting 655360 events.
[15:50:07.788] <TB1> INFO: 655360 events read in total (14284ms).
[15:50:07.849] <TB1> INFO: Expecting 655360 events.
[15:50:22.519] <TB1> INFO: 655360 events read in total (14267ms).
[15:50:22.630] <TB1> INFO: Expecting 655360 events.
[15:50:37.179] <TB1> INFO: 655360 events read in total (14146ms).
[15:50:37.254] <TB1> INFO: Expecting 655360 events.
[15:50:51.878] <TB1> INFO: 655360 events read in total (14221ms).
[15:50:51.982] <TB1> INFO: Expecting 655360 events.
[15:51:06.716] <TB1> INFO: 655360 events read in total (14331ms).
[15:51:06.784] <TB1> INFO: Expecting 655360 events.
[15:51:21.554] <TB1> INFO: 655360 events read in total (14367ms).
[15:51:21.653] <TB1> INFO: Expecting 655360 events.
[15:51:36.290] <TB1> INFO: 655360 events read in total (14234ms).
[15:51:36.429] <TB1> INFO: Expecting 655360 events.
[15:51:50.002] <TB1> INFO: 655360 events read in total (14170ms).
[15:51:51.104] <TB1> INFO: Test took 236674ms.
[15:51:51.202] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:51:51.458] <TB1> INFO: Expecting 655360 events.
[15:52:06.111] <TB1> INFO: 655360 events read in total (14061ms).
[15:52:06.123] <TB1> INFO: Expecting 655360 events.
[15:52:20.536] <TB1> INFO: 655360 events read in total (14010ms).
[15:52:20.553] <TB1> INFO: Expecting 655360 events.
[15:52:34.920] <TB1> INFO: 655360 events read in total (13964ms).
[15:52:34.939] <TB1> INFO: Expecting 655360 events.
[15:52:49.345] <TB1> INFO: 655360 events read in total (14002ms).
[15:52:49.369] <TB1> INFO: Expecting 655360 events.
[15:53:04.046] <TB1> INFO: 655360 events read in total (14274ms).
[15:53:04.078] <TB1> INFO: Expecting 655360 events.
[15:53:18.550] <TB1> INFO: 655360 events read in total (14069ms).
[15:53:18.592] <TB1> INFO: Expecting 655360 events.
[15:53:33.220] <TB1> INFO: 655360 events read in total (14225ms).
[15:53:33.265] <TB1> INFO: Expecting 655360 events.
[15:53:47.741] <TB1> INFO: 655360 events read in total (14073ms).
[15:53:47.796] <TB1> INFO: Expecting 655360 events.
[15:54:02.167] <TB1> INFO: 655360 events read in total (13968ms).
[15:54:02.215] <TB1> INFO: Expecting 655360 events.
[15:54:16.639] <TB1> INFO: 655360 events read in total (14022ms).
[15:54:16.764] <TB1> INFO: Expecting 655360 events.
[15:54:31.271] <TB1> INFO: 655360 events read in total (14105ms).
[15:54:31.329] <TB1> INFO: Expecting 655360 events.
[15:54:45.725] <TB1> INFO: 655360 events read in total (13992ms).
[15:54:45.799] <TB1> INFO: Expecting 655360 events.
[15:55:00.317] <TB1> INFO: 655360 events read in total (14115ms).
[15:55:00.384] <TB1> INFO: Expecting 655360 events.
[15:55:14.769] <TB1> INFO: 655360 events read in total (13982ms).
[15:55:14.866] <TB1> INFO: Expecting 655360 events.
[15:55:29.339] <TB1> INFO: 655360 events read in total (14070ms).
[15:55:29.463] <TB1> INFO: Expecting 655360 events.
[15:55:43.991] <TB1> INFO: 655360 events read in total (14125ms).
[15:55:44.124] <TB1> INFO: Test took 232923ms.
[15:55:44.300] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.306] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.312] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:55:44.318] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.325] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.330] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:55:44.336] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.343] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.349] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.355] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.361] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:55:44.367] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[15:55:44.373] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.379] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:55:44.384] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[15:55:44.390] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[15:55:44.396] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.401] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:55:44.407] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.413] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:55:44.419] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[15:55:44.424] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[15:55:44.430] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[15:55:44.435] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[15:55:44.441] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[15:55:44.446] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.452] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:55:44.457] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[15:55:44.463] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[15:55:44.468] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[15:55:44.474] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[15:55:44.480] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.485] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.491] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[15:55:44.497] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.502] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[15:55:44.540] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C0.dat
[15:55:44.541] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C1.dat
[15:55:44.541] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C2.dat
[15:55:44.541] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C3.dat
[15:55:44.541] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C4.dat
[15:55:44.541] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C5.dat
[15:55:44.541] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C6.dat
[15:55:44.542] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C7.dat
[15:55:44.542] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C8.dat
[15:55:44.542] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C9.dat
[15:55:44.542] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C10.dat
[15:55:44.542] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C11.dat
[15:55:44.542] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C12.dat
[15:55:44.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C13.dat
[15:55:44.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C14.dat
[15:55:44.543] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters35_C15.dat
[15:55:44.802] <TB1> INFO: Expecting 41600 events.
[15:55:47.950] <TB1> INFO: 41600 events read in total (2556ms).
[15:55:47.951] <TB1> INFO: Test took 3403ms.
[15:55:48.406] <TB1> INFO: Expecting 41600 events.
[15:55:51.429] <TB1> INFO: 41600 events read in total (2431ms).
[15:55:51.430] <TB1> INFO: Test took 3267ms.
[15:55:51.906] <TB1> INFO: Expecting 41600 events.
[15:55:55.061] <TB1> INFO: 41600 events read in total (2563ms).
[15:55:55.062] <TB1> INFO: Test took 3417ms.
[15:55:55.282] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:55:55.372] <TB1> INFO: Expecting 2560 events.
[15:55:56.256] <TB1> INFO: 2560 events read in total (293ms).
[15:55:56.256] <TB1> INFO: Test took 974ms.
[15:55:56.260] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:55:56.564] <TB1> INFO: Expecting 2560 events.
[15:55:57.453] <TB1> INFO: 2560 events read in total (298ms).
[15:55:57.453] <TB1> INFO: Test took 1193ms.
[15:55:57.456] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:55:57.764] <TB1> INFO: Expecting 2560 events.
[15:55:58.649] <TB1> INFO: 2560 events read in total (293ms).
[15:55:58.649] <TB1> INFO: Test took 1193ms.
[15:55:58.651] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:55:58.958] <TB1> INFO: Expecting 2560 events.
[15:55:59.844] <TB1> INFO: 2560 events read in total (294ms).
[15:55:59.845] <TB1> INFO: Test took 1194ms.
[15:55:59.848] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:00.152] <TB1> INFO: Expecting 2560 events.
[15:56:01.038] <TB1> INFO: 2560 events read in total (294ms).
[15:56:01.038] <TB1> INFO: Test took 1191ms.
[15:56:01.040] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:01.346] <TB1> INFO: Expecting 2560 events.
[15:56:02.237] <TB1> INFO: 2560 events read in total (299ms).
[15:56:02.238] <TB1> INFO: Test took 1198ms.
[15:56:02.240] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:02.546] <TB1> INFO: Expecting 2560 events.
[15:56:03.434] <TB1> INFO: 2560 events read in total (297ms).
[15:56:03.435] <TB1> INFO: Test took 1195ms.
[15:56:03.438] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:03.743] <TB1> INFO: Expecting 2560 events.
[15:56:04.635] <TB1> INFO: 2560 events read in total (300ms).
[15:56:04.635] <TB1> INFO: Test took 1197ms.
[15:56:04.637] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:04.943] <TB1> INFO: Expecting 2560 events.
[15:56:05.835] <TB1> INFO: 2560 events read in total (300ms).
[15:56:05.835] <TB1> INFO: Test took 1198ms.
[15:56:05.840] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:06.143] <TB1> INFO: Expecting 2560 events.
[15:56:07.024] <TB1> INFO: 2560 events read in total (289ms).
[15:56:07.024] <TB1> INFO: Test took 1185ms.
[15:56:07.027] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:07.333] <TB1> INFO: Expecting 2560 events.
[15:56:08.220] <TB1> INFO: 2560 events read in total (295ms).
[15:56:08.221] <TB1> INFO: Test took 1194ms.
[15:56:08.225] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:08.528] <TB1> INFO: Expecting 2560 events.
[15:56:09.412] <TB1> INFO: 2560 events read in total (290ms).
[15:56:09.412] <TB1> INFO: Test took 1188ms.
[15:56:09.416] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:09.719] <TB1> INFO: Expecting 2560 events.
[15:56:10.612] <TB1> INFO: 2560 events read in total (302ms).
[15:56:10.612] <TB1> INFO: Test took 1197ms.
[15:56:10.615] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:10.920] <TB1> INFO: Expecting 2560 events.
[15:56:11.800] <TB1> INFO: 2560 events read in total (289ms).
[15:56:11.800] <TB1> INFO: Test took 1185ms.
[15:56:11.805] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:12.107] <TB1> INFO: Expecting 2560 events.
[15:56:12.987] <TB1> INFO: 2560 events read in total (288ms).
[15:56:12.988] <TB1> INFO: Test took 1183ms.
[15:56:12.992] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:13.295] <TB1> INFO: Expecting 2560 events.
[15:56:14.183] <TB1> INFO: 2560 events read in total (296ms).
[15:56:14.184] <TB1> INFO: Test took 1192ms.
[15:56:14.188] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:14.491] <TB1> INFO: Expecting 2560 events.
[15:56:15.378] <TB1> INFO: 2560 events read in total (295ms).
[15:56:15.379] <TB1> INFO: Test took 1191ms.
[15:56:15.383] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:15.686] <TB1> INFO: Expecting 2560 events.
[15:56:16.568] <TB1> INFO: 2560 events read in total (291ms).
[15:56:16.568] <TB1> INFO: Test took 1185ms.
[15:56:16.571] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:16.876] <TB1> INFO: Expecting 2560 events.
[15:56:17.764] <TB1> INFO: 2560 events read in total (297ms).
[15:56:17.765] <TB1> INFO: Test took 1195ms.
[15:56:17.767] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:18.073] <TB1> INFO: Expecting 2560 events.
[15:56:18.957] <TB1> INFO: 2560 events read in total (293ms).
[15:56:18.958] <TB1> INFO: Test took 1191ms.
[15:56:18.960] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:19.266] <TB1> INFO: Expecting 2560 events.
[15:56:20.148] <TB1> INFO: 2560 events read in total (290ms).
[15:56:20.148] <TB1> INFO: Test took 1188ms.
[15:56:20.154] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:20.459] <TB1> INFO: Expecting 2560 events.
[15:56:21.348] <TB1> INFO: 2560 events read in total (298ms).
[15:56:21.348] <TB1> INFO: Test took 1194ms.
[15:56:21.351] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:21.657] <TB1> INFO: Expecting 2560 events.
[15:56:22.549] <TB1> INFO: 2560 events read in total (300ms).
[15:56:22.549] <TB1> INFO: Test took 1198ms.
[15:56:22.554] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:22.858] <TB1> INFO: Expecting 2560 events.
[15:56:23.743] <TB1> INFO: 2560 events read in total (293ms).
[15:56:23.743] <TB1> INFO: Test took 1190ms.
[15:56:23.746] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:24.052] <TB1> INFO: Expecting 2560 events.
[15:56:24.942] <TB1> INFO: 2560 events read in total (298ms).
[15:56:24.943] <TB1> INFO: Test took 1197ms.
[15:56:24.947] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:25.251] <TB1> INFO: Expecting 2560 events.
[15:56:26.142] <TB1> INFO: 2560 events read in total (299ms).
[15:56:26.143] <TB1> INFO: Test took 1197ms.
[15:56:26.146] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:26.450] <TB1> INFO: Expecting 2560 events.
[15:56:27.334] <TB1> INFO: 2560 events read in total (292ms).
[15:56:27.334] <TB1> INFO: Test took 1188ms.
[15:56:27.336] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:27.642] <TB1> INFO: Expecting 2560 events.
[15:56:28.532] <TB1> INFO: 2560 events read in total (298ms).
[15:56:28.532] <TB1> INFO: Test took 1196ms.
[15:56:28.535] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:28.840] <TB1> INFO: Expecting 2560 events.
[15:56:29.734] <TB1> INFO: 2560 events read in total (303ms).
[15:56:29.734] <TB1> INFO: Test took 1199ms.
[15:56:29.739] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:30.042] <TB1> INFO: Expecting 2560 events.
[15:56:30.926] <TB1> INFO: 2560 events read in total (292ms).
[15:56:30.926] <TB1> INFO: Test took 1187ms.
[15:56:30.928] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:31.235] <TB1> INFO: Expecting 2560 events.
[15:56:32.129] <TB1> INFO: 2560 events read in total (302ms).
[15:56:32.130] <TB1> INFO: Test took 1202ms.
[15:56:32.132] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[15:56:32.438] <TB1> INFO: Expecting 2560 events.
[15:56:33.332] <TB1> INFO: 2560 events read in total (302ms).
[15:56:33.332] <TB1> INFO: Test took 1200ms.
[15:56:33.817] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 649 seconds
[15:56:33.817] <TB1> INFO: PH scale (per ROC): 49 45 49 31 38 45 35 42 46 49 30 31 31 51 52 37
[15:56:33.817] <TB1> INFO: PH offset (per ROC): 120 113 124 95 101 100 112 115 133 117 107 91 93 126 127 90
[15:56:33.824] <TB1> INFO: Decoding statistics:
[15:56:33.824] <TB1> INFO: General information:
[15:56:33.824] <TB1> INFO: 16bit words read: 127882
[15:56:33.824] <TB1> INFO: valid events total: 20480
[15:56:33.824] <TB1> INFO: empty events: 17979
[15:56:33.824] <TB1> INFO: valid events with pixels: 2501
[15:56:33.824] <TB1> INFO: valid pixel hits: 2501
[15:56:33.824] <TB1> INFO: Event errors: 0
[15:56:33.824] <TB1> INFO: start marker: 0
[15:56:33.824] <TB1> INFO: stop marker: 0
[15:56:33.824] <TB1> INFO: overflow: 0
[15:56:33.824] <TB1> INFO: invalid 5bit words: 0
[15:56:33.824] <TB1> INFO: invalid XOR eye diagram: 0
[15:56:33.824] <TB1> INFO: frame (failed synchr.): 0
[15:56:33.824] <TB1> INFO: idle data (no TBM trl): 0
[15:56:33.824] <TB1> INFO: no data (only TBM hdr): 0
[15:56:33.824] <TB1> INFO: TBM errors: 0
[15:56:33.824] <TB1> INFO: flawed TBM headers: 0
[15:56:33.824] <TB1> INFO: flawed TBM trailers: 0
[15:56:33.824] <TB1> INFO: event ID mismatches: 0
[15:56:33.824] <TB1> INFO: ROC errors: 0
[15:56:33.824] <TB1> INFO: missing ROC header(s): 0
[15:56:33.824] <TB1> INFO: misplaced readback start: 0
[15:56:33.824] <TB1> INFO: Pixel decoding errors: 0
[15:56:33.824] <TB1> INFO: pixel data incomplete: 0
[15:56:33.824] <TB1> INFO: pixel address: 0
[15:56:33.824] <TB1> INFO: pulse height fill bit: 0
[15:56:33.824] <TB1> INFO: buffer corruption: 0
[15:56:33.988] <TB1> INFO: ######################################################################
[15:56:33.988] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[15:56:33.988] <TB1> INFO: ######################################################################
[15:56:34.003] <TB1> INFO: scanning low vcal = 10
[15:56:34.241] <TB1> INFO: Expecting 41600 events.
[15:56:37.835] <TB1> INFO: 41600 events read in total (3002ms).
[15:56:37.835] <TB1> INFO: Test took 3832ms.
[15:56:37.837] <TB1> INFO: scanning low vcal = 20
[15:56:38.130] <TB1> INFO: Expecting 41600 events.
[15:56:41.738] <TB1> INFO: 41600 events read in total (3016ms).
[15:56:41.739] <TB1> INFO: Test took 3902ms.
[15:56:41.742] <TB1> INFO: scanning low vcal = 30
[15:56:42.035] <TB1> INFO: Expecting 41600 events.
[15:56:45.707] <TB1> INFO: 41600 events read in total (3080ms).
[15:56:45.708] <TB1> INFO: Test took 3966ms.
[15:56:45.710] <TB1> INFO: scanning low vcal = 40
[15:56:45.988] <TB1> INFO: Expecting 41600 events.
[15:56:49.993] <TB1> INFO: 41600 events read in total (3413ms).
[15:56:49.994] <TB1> INFO: Test took 4283ms.
[15:56:49.997] <TB1> INFO: scanning low vcal = 50
[15:56:50.274] <TB1> INFO: Expecting 41600 events.
[15:56:54.302] <TB1> INFO: 41600 events read in total (3436ms).
[15:56:54.303] <TB1> INFO: Test took 4306ms.
[15:56:54.307] <TB1> INFO: scanning low vcal = 60
[15:56:54.584] <TB1> INFO: Expecting 41600 events.
[15:56:58.590] <TB1> INFO: 41600 events read in total (3414ms).
[15:56:58.591] <TB1> INFO: Test took 4284ms.
[15:56:58.595] <TB1> INFO: scanning low vcal = 70
[15:56:58.871] <TB1> INFO: Expecting 41600 events.
[15:57:02.886] <TB1> INFO: 41600 events read in total (3423ms).
[15:57:02.887] <TB1> INFO: Test took 4292ms.
[15:57:02.889] <TB1> INFO: scanning low vcal = 80
[15:57:03.167] <TB1> INFO: Expecting 41600 events.
[15:57:07.174] <TB1> INFO: 41600 events read in total (3415ms).
[15:57:07.175] <TB1> INFO: Test took 4285ms.
[15:57:07.178] <TB1> INFO: scanning low vcal = 90
[15:57:07.456] <TB1> INFO: Expecting 41600 events.
[15:57:11.459] <TB1> INFO: 41600 events read in total (3411ms).
[15:57:11.460] <TB1> INFO: Test took 4282ms.
[15:57:11.464] <TB1> INFO: scanning low vcal = 100
[15:57:11.740] <TB1> INFO: Expecting 41600 events.
[15:57:15.765] <TB1> INFO: 41600 events read in total (3433ms).
[15:57:15.766] <TB1> INFO: Test took 4302ms.
[15:57:15.770] <TB1> INFO: scanning low vcal = 110
[15:57:16.047] <TB1> INFO: Expecting 41600 events.
[15:57:20.083] <TB1> INFO: 41600 events read in total (3444ms).
[15:57:20.084] <TB1> INFO: Test took 4314ms.
[15:57:20.087] <TB1> INFO: scanning low vcal = 120
[15:57:20.364] <TB1> INFO: Expecting 41600 events.
[15:57:24.380] <TB1> INFO: 41600 events read in total (3424ms).
[15:57:24.381] <TB1> INFO: Test took 4294ms.
[15:57:24.384] <TB1> INFO: scanning low vcal = 130
[15:57:24.662] <TB1> INFO: Expecting 41600 events.
[15:57:28.693] <TB1> INFO: 41600 events read in total (3440ms).
[15:57:28.694] <TB1> INFO: Test took 4310ms.
[15:57:28.697] <TB1> INFO: scanning low vcal = 140
[15:57:28.975] <TB1> INFO: Expecting 41600 events.
[15:57:33.010] <TB1> INFO: 41600 events read in total (3443ms).
[15:57:33.011] <TB1> INFO: Test took 4314ms.
[15:57:33.014] <TB1> INFO: scanning low vcal = 150
[15:57:33.291] <TB1> INFO: Expecting 41600 events.
[15:57:37.338] <TB1> INFO: 41600 events read in total (3454ms).
[15:57:37.339] <TB1> INFO: Test took 4325ms.
[15:57:37.342] <TB1> INFO: scanning low vcal = 160
[15:57:37.620] <TB1> INFO: Expecting 41600 events.
[15:57:41.619] <TB1> INFO: 41600 events read in total (3407ms).
[15:57:41.620] <TB1> INFO: Test took 4278ms.
[15:57:41.623] <TB1> INFO: scanning low vcal = 170
[15:57:41.901] <TB1> INFO: Expecting 41600 events.
[15:57:45.922] <TB1> INFO: 41600 events read in total (3429ms).
[15:57:45.923] <TB1> INFO: Test took 4300ms.
[15:57:45.929] <TB1> INFO: scanning low vcal = 180
[15:57:46.203] <TB1> INFO: Expecting 41600 events.
[15:57:50.240] <TB1> INFO: 41600 events read in total (3445ms).
[15:57:50.241] <TB1> INFO: Test took 4312ms.
[15:57:50.244] <TB1> INFO: scanning low vcal = 190
[15:57:50.521] <TB1> INFO: Expecting 41600 events.
[15:57:54.551] <TB1> INFO: 41600 events read in total (3438ms).
[15:57:54.552] <TB1> INFO: Test took 4308ms.
[15:57:54.556] <TB1> INFO: scanning low vcal = 200
[15:57:54.833] <TB1> INFO: Expecting 41600 events.
[15:57:58.830] <TB1> INFO: 41600 events read in total (3406ms).
[15:57:58.831] <TB1> INFO: Test took 4275ms.
[15:57:58.834] <TB1> INFO: scanning low vcal = 210
[15:57:59.120] <TB1> INFO: Expecting 41600 events.
[15:58:03.128] <TB1> INFO: 41600 events read in total (3417ms).
[15:58:03.129] <TB1> INFO: Test took 4295ms.
[15:58:03.132] <TB1> INFO: scanning low vcal = 220
[15:58:03.409] <TB1> INFO: Expecting 41600 events.
[15:58:07.434] <TB1> INFO: 41600 events read in total (3433ms).
[15:58:07.435] <TB1> INFO: Test took 4303ms.
[15:58:07.438] <TB1> INFO: scanning low vcal = 230
[15:58:07.716] <TB1> INFO: Expecting 41600 events.
[15:58:11.695] <TB1> INFO: 41600 events read in total (3387ms).
[15:58:11.696] <TB1> INFO: Test took 4258ms.
[15:58:11.699] <TB1> INFO: scanning low vcal = 240
[15:58:11.976] <TB1> INFO: Expecting 41600 events.
[15:58:15.981] <TB1> INFO: 41600 events read in total (3413ms).
[15:58:15.982] <TB1> INFO: Test took 4283ms.
[15:58:15.986] <TB1> INFO: scanning low vcal = 250
[15:58:16.263] <TB1> INFO: Expecting 41600 events.
[15:58:20.248] <TB1> INFO: 41600 events read in total (3393ms).
[15:58:20.248] <TB1> INFO: Test took 4262ms.
[15:58:20.253] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[15:58:20.529] <TB1> INFO: Expecting 41600 events.
[15:58:24.565] <TB1> INFO: 41600 events read in total (3444ms).
[15:58:24.566] <TB1> INFO: Test took 4313ms.
[15:58:24.569] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[15:58:24.846] <TB1> INFO: Expecting 41600 events.
[15:58:28.874] <TB1> INFO: 41600 events read in total (3436ms).
[15:58:28.876] <TB1> INFO: Test took 4307ms.
[15:58:28.879] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[15:58:29.157] <TB1> INFO: Expecting 41600 events.
[15:58:33.189] <TB1> INFO: 41600 events read in total (3441ms).
[15:58:33.190] <TB1> INFO: Test took 4311ms.
[15:58:33.194] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[15:58:33.471] <TB1> INFO: Expecting 41600 events.
[15:58:37.482] <TB1> INFO: 41600 events read in total (3419ms).
[15:58:37.483] <TB1> INFO: Test took 4289ms.
[15:58:37.486] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[15:58:37.764] <TB1> INFO: Expecting 41600 events.
[15:58:41.745] <TB1> INFO: 41600 events read in total (3390ms).
[15:58:41.746] <TB1> INFO: Test took 4260ms.
[15:58:42.161] <TB1> INFO: PixTestGainPedestal::measure() done
[15:59:20.588] <TB1> INFO: PixTestGainPedestal::fit() done
[15:59:20.588] <TB1> INFO: non-linearity mean: 0.980 0.952 0.981 1.001 0.936 0.975 0.944 0.954 0.985 0.987 0.947 0.935 0.924 0.987 0.986 0.930
[15:59:20.588] <TB1> INFO: non-linearity RMS: 0.004 0.062 0.004 0.184 0.075 0.009 0.157 0.039 0.003 0.002 0.168 0.119 0.126 0.002 0.003 0.147
[15:59:20.588] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C0.dat
[15:59:20.601] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C1.dat
[15:59:20.614] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C2.dat
[15:59:20.627] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C3.dat
[15:59:20.641] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C4.dat
[15:59:20.654] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C5.dat
[15:59:20.668] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C6.dat
[15:59:20.682] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C7.dat
[15:59:20.696] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C8.dat
[15:59:20.709] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C9.dat
[15:59:20.722] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C10.dat
[15:59:20.736] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C11.dat
[15:59:20.750] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C12.dat
[15:59:20.763] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C13.dat
[15:59:20.777] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C14.dat
[15:59:20.791] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//phCalibrationFitErr35_C15.dat
[15:59:20.805] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 166 seconds
[15:59:20.805] <TB1> INFO: Decoding statistics:
[15:59:20.805] <TB1> INFO: General information:
[15:59:20.805] <TB1> INFO: 16bit words read: 3244826
[15:59:20.805] <TB1> INFO: valid events total: 332800
[15:59:20.805] <TB1> INFO: empty events: 2611
[15:59:20.805] <TB1> INFO: valid events with pixels: 330189
[15:59:20.805] <TB1> INFO: valid pixel hits: 624013
[15:59:20.805] <TB1> INFO: Event errors: 0
[15:59:20.805] <TB1> INFO: start marker: 0
[15:59:20.805] <TB1> INFO: stop marker: 0
[15:59:20.805] <TB1> INFO: overflow: 0
[15:59:20.805] <TB1> INFO: invalid 5bit words: 0
[15:59:20.805] <TB1> INFO: invalid XOR eye diagram: 0
[15:59:20.805] <TB1> INFO: frame (failed synchr.): 0
[15:59:20.805] <TB1> INFO: idle data (no TBM trl): 0
[15:59:20.805] <TB1> INFO: no data (only TBM hdr): 0
[15:59:20.805] <TB1> INFO: TBM errors: 0
[15:59:20.805] <TB1> INFO: flawed TBM headers: 0
[15:59:20.805] <TB1> INFO: flawed TBM trailers: 0
[15:59:20.805] <TB1> INFO: event ID mismatches: 0
[15:59:20.805] <TB1> INFO: ROC errors: 0
[15:59:20.805] <TB1> INFO: missing ROC header(s): 0
[15:59:20.805] <TB1> INFO: misplaced readback start: 0
[15:59:20.805] <TB1> INFO: Pixel decoding errors: 0
[15:59:20.805] <TB1> INFO: pixel data incomplete: 0
[15:59:20.805] <TB1> INFO: pixel address: 0
[15:59:20.805] <TB1> INFO: pulse height fill bit: 0
[15:59:20.805] <TB1> INFO: buffer corruption: 0
[15:59:20.827] <TB1> INFO: Decoding statistics:
[15:59:20.827] <TB1> INFO: General information:
[15:59:20.827] <TB1> INFO: 16bit words read: 3374244
[15:59:20.827] <TB1> INFO: valid events total: 353536
[15:59:20.827] <TB1> INFO: empty events: 20846
[15:59:20.827] <TB1> INFO: valid events with pixels: 332690
[15:59:20.827] <TB1> INFO: valid pixel hits: 626514
[15:59:20.827] <TB1> INFO: Event errors: 0
[15:59:20.827] <TB1> INFO: start marker: 0
[15:59:20.827] <TB1> INFO: stop marker: 0
[15:59:20.827] <TB1> INFO: overflow: 0
[15:59:20.827] <TB1> INFO: invalid 5bit words: 0
[15:59:20.827] <TB1> INFO: invalid XOR eye diagram: 0
[15:59:20.827] <TB1> INFO: frame (failed synchr.): 0
[15:59:20.827] <TB1> INFO: idle data (no TBM trl): 0
[15:59:20.827] <TB1> INFO: no data (only TBM hdr): 0
[15:59:20.827] <TB1> INFO: TBM errors: 0
[15:59:20.827] <TB1> INFO: flawed TBM headers: 0
[15:59:20.827] <TB1> INFO: flawed TBM trailers: 0
[15:59:20.827] <TB1> INFO: event ID mismatches: 0
[15:59:20.827] <TB1> INFO: ROC errors: 0
[15:59:20.827] <TB1> INFO: missing ROC header(s): 0
[15:59:20.827] <TB1> INFO: misplaced readback start: 0
[15:59:20.827] <TB1> INFO: Pixel decoding errors: 0
[15:59:20.827] <TB1> INFO: pixel data incomplete: 0
[15:59:20.827] <TB1> INFO: pixel address: 0
[15:59:20.827] <TB1> INFO: pulse height fill bit: 0
[15:59:20.827] <TB1> INFO: buffer corruption: 0
[15:59:20.827] <TB1> INFO: enter test to run
[15:59:20.827] <TB1> INFO: test: trim80 no parameter change
[15:59:20.827] <TB1> INFO: running: trim80
[15:59:20.829] <TB1> INFO: ######################################################################
[15:59:20.829] <TB1> INFO: PixTestTrim80::doTest()
[15:59:20.829] <TB1> INFO: ######################################################################
[15:59:20.831] <TB1> INFO: ----------------------------------------------------------------------
[15:59:20.831] <TB1> INFO: PixTestTrim80::trimTest() ntrig = 8, vcal = 80
[15:59:20.831] <TB1> INFO: ----------------------------------------------------------------------
[15:59:20.873] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[15:59:20.873] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[15:59:20.886] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[15:59:20.886] <TB1> INFO: run 1 of 1
[15:59:21.148] <TB1> INFO: Expecting 5025280 events.
[15:59:48.924] <TB1> INFO: 687728 events read in total (27183ms).
[16:00:16.255] <TB1> INFO: 1370960 events read in total (54514ms).
[16:00:43.539] <TB1> INFO: 2051512 events read in total (81798ms).
[16:01:10.952] <TB1> INFO: 2730000 events read in total (109211ms).
[16:01:38.145] <TB1> INFO: 3409296 events read in total (136404ms).
[16:02:05.628] <TB1> INFO: 4087384 events read in total (163887ms).
[16:02:32.981] <TB1> INFO: 4765360 events read in total (191240ms).
[16:02:43.674] <TB1> INFO: 5025280 events read in total (201933ms).
[16:02:43.762] <TB1> INFO: Test took 202876ms.
[16:03:05.889] <TB1> INFO: ROC 0 VthrComp = 80
[16:03:05.889] <TB1> INFO: ROC 1 VthrComp = 73
[16:03:05.889] <TB1> INFO: ROC 2 VthrComp = 78
[16:03:05.889] <TB1> INFO: ROC 3 VthrComp = 82
[16:03:05.890] <TB1> INFO: ROC 4 VthrComp = 83
[16:03:05.890] <TB1> INFO: ROC 5 VthrComp = 78
[16:03:05.890] <TB1> INFO: ROC 6 VthrComp = 73
[16:03:05.890] <TB1> INFO: ROC 7 VthrComp = 74
[16:03:05.890] <TB1> INFO: ROC 8 VthrComp = 75
[16:03:05.890] <TB1> INFO: ROC 9 VthrComp = 79
[16:03:05.890] <TB1> INFO: ROC 10 VthrComp = 81
[16:03:05.890] <TB1> INFO: ROC 11 VthrComp = 73
[16:03:05.890] <TB1> INFO: ROC 12 VthrComp = 81
[16:03:05.890] <TB1> INFO: ROC 13 VthrComp = 80
[16:03:05.890] <TB1> INFO: ROC 14 VthrComp = 80
[16:03:05.890] <TB1> INFO: ROC 15 VthrComp = 74
[16:03:06.128] <TB1> INFO: Expecting 41600 events.
[16:03:09.639] <TB1> INFO: 41600 events read in total (2919ms).
[16:03:09.640] <TB1> INFO: Test took 3748ms.
[16:03:09.651] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[16:03:09.651] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[16:03:09.665] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[16:03:09.665] <TB1> INFO: run 1 of 1
[16:03:09.943] <TB1> INFO: Expecting 5025280 events.
[16:03:38.017] <TB1> INFO: 688400 events read in total (27482ms).
[16:04:05.684] <TB1> INFO: 1373472 events read in total (55149ms).
[16:04:33.342] <TB1> INFO: 2057176 events read in total (82807ms).
[16:05:00.963] <TB1> INFO: 2738320 events read in total (110428ms).
[16:05:27.973] <TB1> INFO: 3417248 events read in total (137438ms).
[16:05:55.176] <TB1> INFO: 4094816 events read in total (164641ms).
[16:06:22.569] <TB1> INFO: 4771960 events read in total (192034ms).
[16:06:32.887] <TB1> INFO: 5025280 events read in total (202352ms).
[16:06:32.951] <TB1> INFO: Test took 203286ms.
[16:06:57.026] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 107.363 for pixel 0/46 mean/min/max = 91.5874/75.648/107.527
[16:06:57.027] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 111.662 for pixel 0/64 mean/min/max = 94.7637/77.8012/111.726
[16:06:57.027] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 110.435 for pixel 0/2 mean/min/max = 94.1591/77.8483/110.47
[16:06:57.027] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 108.121 for pixel 0/16 mean/min/max = 91.7242/75.3127/108.136
[16:06:57.028] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 109.615 for pixel 0/2 mean/min/max = 92.149/74.6365/109.662
[16:06:57.028] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 116.814 for pixel 0/74 mean/min/max = 97.1526/77.4118/116.893
[16:06:57.028] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 110.652 for pixel 42/5 mean/min/max = 94.0519/77.3831/110.721
[16:06:57.029] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 111.593 for pixel 51/79 mean/min/max = 94.8245/77.7009/111.948
[16:06:57.029] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 114.049 for pixel 0/2 mean/min/max = 95.7326/77.2231/114.242
[16:06:57.030] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 112.247 for pixel 0/35 mean/min/max = 95.4479/78.5009/112.395
[16:06:57.030] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 109.051 for pixel 0/34 mean/min/max = 92.1439/74.8669/109.421
[16:06:57.031] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 121.865 for pixel 2/77 mean/min/max = 98.8573/75.5505/122.164
[16:06:57.031] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 109.27 for pixel 51/77 mean/min/max = 92.448/75.4692/109.427
[16:06:57.031] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 109.916 for pixel 44/76 mean/min/max = 92.5909/75.2212/109.961
[16:06:57.032] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 116.042 for pixel 0/19 mean/min/max = 94.718/73.0942/116.342
[16:06:57.032] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 111.295 for pixel 0/2 mean/min/max = 94.781/78.225/111.337
[16:06:57.033] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[16:06:57.122] <TB1> INFO: Expecting 411648 events.
[16:07:06.506] <TB1> INFO: 411648 events read in total (8793ms).
[16:07:06.514] <TB1> INFO: Expecting 411648 events.
[16:07:15.799] <TB1> INFO: 411648 events read in total (8882ms).
[16:07:15.811] <TB1> INFO: Expecting 411648 events.
[16:07:25.118] <TB1> INFO: 411648 events read in total (8904ms).
[16:07:25.135] <TB1> INFO: Expecting 411648 events.
[16:07:34.318] <TB1> INFO: 411648 events read in total (8780ms).
[16:07:34.338] <TB1> INFO: Expecting 411648 events.
[16:07:43.689] <TB1> INFO: 411648 events read in total (8948ms).
[16:07:43.709] <TB1> INFO: Expecting 411648 events.
[16:07:52.990] <TB1> INFO: 411648 events read in total (8878ms).
[16:07:53.019] <TB1> INFO: Expecting 411648 events.
[16:08:02.099] <TB1> INFO: 411648 events read in total (8677ms).
[16:08:02.127] <TB1> INFO: Expecting 411648 events.
[16:08:11.274] <TB1> INFO: 411648 events read in total (8745ms).
[16:08:11.303] <TB1> INFO: Expecting 411648 events.
[16:08:20.784] <TB1> INFO: 411648 events read in total (9078ms).
[16:08:20.824] <TB1> INFO: Expecting 411648 events.
[16:08:30.320] <TB1> INFO: 411648 events read in total (9093ms).
[16:08:30.364] <TB1> INFO: Expecting 411648 events.
[16:08:39.850] <TB1> INFO: 411648 events read in total (9082ms).
[16:08:39.896] <TB1> INFO: Expecting 411648 events.
[16:08:49.398] <TB1> INFO: 411648 events read in total (9099ms).
[16:08:49.449] <TB1> INFO: Expecting 411648 events.
[16:08:59.022] <TB1> INFO: 411648 events read in total (9170ms).
[16:08:59.067] <TB1> INFO: Expecting 411648 events.
[16:09:08.444] <TB1> INFO: 411648 events read in total (8974ms).
[16:09:08.497] <TB1> INFO: Expecting 411648 events.
[16:09:17.910] <TB1> INFO: 411648 events read in total (9010ms).
[16:09:17.983] <TB1> INFO: Expecting 411648 events.
[16:09:27.352] <TB1> INFO: 411648 events read in total (8966ms).
[16:09:27.439] <TB1> INFO: Test took 150406ms.
[16:09:29.092] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[16:09:29.109] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[16:09:29.109] <TB1> INFO: run 1 of 1
[16:09:29.362] <TB1> INFO: Expecting 5025280 events.
[16:09:57.581] <TB1> INFO: 671584 events read in total (27627ms).
[16:10:24.665] <TB1> INFO: 1340840 events read in total (54711ms).
[16:10:51.837] <TB1> INFO: 2008336 events read in total (81883ms).
[16:11:18.674] <TB1> INFO: 2672728 events read in total (108720ms).
[16:11:45.478] <TB1> INFO: 3331208 events read in total (135524ms).
[16:12:12.219] <TB1> INFO: 3988984 events read in total (162265ms).
[16:12:38.849] <TB1> INFO: 4644944 events read in total (188895ms).
[16:12:54.648] <TB1> INFO: 5025280 events read in total (204694ms).
[16:12:54.714] <TB1> INFO: Test took 205604ms.
[16:13:18.797] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 51.379418 .. 108.016862
[16:13:19.088] <TB1> INFO: Expecting 208000 events.
[16:13:28.835] <TB1> INFO: 208000 events read in total (9154ms).
[16:13:28.836] <TB1> INFO: Test took 10037ms.
[16:13:28.883] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 41 .. 118 (-1/-1) hits flags = 528 (plus default)
[16:13:28.896] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[16:13:28.896] <TB1> INFO: run 1 of 1
[16:13:29.174] <TB1> INFO: Expecting 2595840 events.
[16:13:57.782] <TB1> INFO: 670536 events read in total (28015ms).
[16:14:25.344] <TB1> INFO: 1342568 events read in total (55578ms).
[16:15:40.429] <TB1> INFO: 2012320 events read in total (130662ms).
[16:16:15.921] <TB1> INFO: 2595840 events read in total (166154ms).
[16:16:16.111] <TB1> INFO: Test took 167215ms.
[16:17:08.496] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 60.221965 .. 93.756402
[16:17:08.794] <TB1> INFO: Expecting 208000 events.
[16:17:19.401] <TB1> INFO: 208000 events read in total (10016ms).
[16:17:19.402] <TB1> INFO: Test took 10904ms.
[16:17:19.482] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 50 .. 103 (-1/-1) hits flags = 528 (plus default)
[16:17:19.497] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[16:17:19.497] <TB1> INFO: run 1 of 1
[16:17:19.825] <TB1> INFO: Expecting 1797120 events.
[16:18:38.141] <TB1> INFO: 691448 events read in total (77724ms).
[16:19:40.439] <TB1> INFO: 1382056 events read in total (140023ms).
[16:20:13.903] <TB1> INFO: 1797120 events read in total (173486ms).
[16:20:13.947] <TB1> INFO: Test took 174450ms.
[16:20:35.001] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 65.759871 .. 88.298146
[16:20:36.733] <TB1> INFO: Expecting 208000 events.
[16:21:01.075] <TB1> INFO: 208000 events read in total (23740ms).
[16:21:01.076] <TB1> INFO: Test took 25006ms.
[16:21:01.158] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 55 .. 98 (-1/-1) hits flags = 528 (plus default)
[16:21:01.174] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[16:21:01.174] <TB1> INFO: run 1 of 1
[16:21:01.513] <TB1> INFO: Expecting 1464320 events.
[16:21:50.362] <TB1> INFO: 696728 events read in total (48257ms).
[16:23:12.198] <TB1> INFO: 1392816 events read in total (130094ms).
[16:23:15.626] <TB1> INFO: 1464320 events read in total (133522ms).
[16:23:15.661] <TB1> INFO: Test took 134487ms.
[16:23:40.665] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 68.807007 .. 87.342113
[16:23:41.043] <TB1> INFO: Expecting 208000 events.
[16:24:15.308] <TB1> INFO: 208000 events read in total (33665ms).
[16:24:15.310] <TB1> INFO: Test took 34640ms.
[16:24:15.392] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 58 .. 97 (-1/-1) hits flags = 528 (plus default)
[16:24:15.407] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[16:24:15.407] <TB1> INFO: run 1 of 1
[16:24:15.713] <TB1> INFO: Expecting 1331200 events.
[16:24:57.487] <TB1> INFO: 692616 events read in total (41182ms).
[16:25:23.417] <TB1> INFO: 1331200 events read in total (67112ms).
[16:25:23.449] <TB1> INFO: Test took 68043ms.
[16:25:42.636] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 60 .. 100
[16:25:42.636] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 60 .. 100 (-1/-1) hits flags = 528 (plus default)
[16:25:42.650] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[16:25:42.650] <TB1> INFO: run 1 of 1
[16:25:42.887] <TB1> INFO: Expecting 1364480 events.
[16:26:11.072] <TB1> INFO: 669328 events read in total (27593ms).
[16:26:38.813] <TB1> INFO: 1337840 events read in total (55334ms).
[16:26:40.576] <TB1> INFO: 1364480 events read in total (57097ms).
[16:26:40.611] <TB1> INFO: Test took 57962ms.
[16:26:59.184] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C0.dat
[16:26:59.184] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C1.dat
[16:26:59.184] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C2.dat
[16:26:59.184] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C3.dat
[16:26:59.184] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C4.dat
[16:26:59.184] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C5.dat
[16:26:59.185] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C6.dat
[16:26:59.185] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C7.dat
[16:26:59.185] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C8.dat
[16:26:59.185] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C9.dat
[16:26:59.185] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C10.dat
[16:26:59.185] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C11.dat
[16:26:59.185] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C12.dat
[16:26:59.186] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C13.dat
[16:26:59.186] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C14.dat
[16:26:59.186] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//dacParameters80_C15.dat
[16:26:59.186] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C0.dat
[16:26:59.195] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C1.dat
[16:26:59.201] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C2.dat
[16:26:59.206] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C3.dat
[16:26:59.211] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C4.dat
[16:26:59.216] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C5.dat
[16:26:59.220] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C6.dat
[16:26:59.225] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C7.dat
[16:26:59.230] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C8.dat
[16:26:59.234] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C9.dat
[16:26:59.239] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C10.dat
[16:26:59.244] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C11.dat
[16:26:59.248] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C12.dat
[16:26:59.253] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C13.dat
[16:26:59.258] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C14.dat
[16:26:59.262] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1087_FullQualification_2016-10-26_12h02m_1477476121//003_FulltestTrim80_p17//trimParameters80_C15.dat
[16:26:59.267] <TB1> INFO: PixTestTrim80::trimTest() done
[16:26:59.267] <TB1> INFO: vtrim: 103 97 98 98 102 98 105 99 109 98 97 97 84 101 121 101
[16:26:59.267] <TB1> INFO: vthrcomp: 80 73 78 82 83 78 73 74 75 79 81 73 81 80 80 74
[16:26:59.267] <TB1> INFO: vcal mean: 79.99 80.08 80.05 80.00 80.06 80.04 80.01 80.04 80.01 80.03 80.04 80.06 80.05 80.00 80.01 80.05
[16:26:59.267] <TB1> INFO: vcal RMS: 0.69 0.75 0.75 0.75 0.79 0.81 0.70 0.72 0.83 0.80 0.80 0.90 0.79 0.77 0.85 0.77
[16:26:59.267] <TB1> INFO: bits mean: 9.75 8.79 9.19 9.69 10.03 9.05 9.36 8.72 9.52 9.11 9.97 7.92 8.96 9.85 9.81 9.43
[16:26:59.267] <TB1> INFO: bits RMS: 2.45 2.43 2.32 2.49 2.41 2.33 2.25 2.43 2.23 2.26 2.43 2.81 2.80 2.36 2.58 2.14
[16:26:59.274] <TB1> INFO: ----------------------------------------------------------------------
[16:26:59.274] <TB1> INFO: PixTestTrim80::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[16:26:59.274] <TB1> INFO: ----------------------------------------------------------------------
[16:26:59.277] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[16:26:59.293] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[16:26:59.293] <TB1> INFO: run 1 of 1
[16:26:59.541] <TB1> INFO: Expecting 4160000 events.
[16:27:32.820] <TB1> INFO: 784090 events read in total (32687ms).
[16:28:05.235] <TB1> INFO: 1561045 events read in total (65102ms).
[16:28:37.867] <TB1> INFO: 2330380 events read in total (97734ms).
[16:29:09.568] <TB1> INFO: 3093890 events read in total (129435ms).
[16:29:41.585] <TB1> INFO: 3854250 events read in total (161452ms).
[16:29:55.043] <TB1> INFO: 4160000 events read in total (174910ms).
[16:29:55.111] <TB1> INFO: Test took 175819ms.
[16:30:22.472] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 223 (-1/-1) hits flags = 528 (plus default)
[16:30:22.486] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[16:30:22.486] <TB1> INFO: run 1 of 1
[16:30:22.740] <TB1> INFO: Expecting 4659200 events.
[16:30:54.586] <TB1> INFO: 722990 events read in total (31254ms).
[16:31:25.850] <TB1> INFO: 1442500 events read in total (62518ms).
[16:31:56.970] <TB1> INFO: 2159115 events read in total (93638ms).
[16:32:28.068] <TB1> INFO: 2870685 events read in total (124736ms).
[16:32:58.907] <TB1> INFO: 3580980 events read in total (155575ms).
[16:33:29.563] <TB1> INFO: 4289960 events read in total (186231ms).
[16:33:45.828] <TB1> INFO: 4659200 events read in total (202496ms).
[16:33:45.918] <TB1> INFO: Test took 203431ms.
[16:34:13.222] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 212 (-1/-1) hits flags = 528 (plus default)
[16:34:13.237] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[16:34:13.237] <TB1> INFO: run 1 of 1
[16:34:13.495] <TB1> INFO: Expecting 4430400 events.
[16:34:46.246] <TB1> INFO: 737380 events read in total (32160ms).
[16:35:18.062] <TB1> INFO: 1470720 events read in total (63976ms).
[16:35:49.742] <TB1> INFO: 2199975 events read in total (95656ms).
[16:36:21.273] <TB1> INFO: 2924510 events read in total (127187ms).
[16:36:52.669] <TB1> INFO: 3647450 events read in total (158583ms).
[16:37:24.093] <TB1> INFO: 4370950 events read in total (190007ms).
[16:37:27.070] <TB1> INFO: 4430400 events read in total (192984ms).
[16:37:27.172] <TB1> INFO: Test took 193935ms.
[16:37:54.348] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 214 (-1/-1) hits flags = 528 (plus default)
[16:37:54.363] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[16:37:54.363] <TB1> INFO: run 1 of 1
[16:37:54.639] <TB1> INFO: Expecting 4472000 events.
[16:38:27.970] <TB1> INFO: 735350 events read in total (32740ms).
[16:38:59.541] <TB1> INFO: 1466730 events read in total (64311ms).
[16:39:30.969] <TB1> INFO: 2193865 events read in total (95739ms).
[16:40:02.624] <TB1> INFO: 2916575 events read in total (127394ms).
[16:40:33.918] <TB1> INFO: 3637500 events read in total (158688ms).
[16:41:05.024] <TB1> INFO: 4357970 events read in total (189794ms).
[16:41:10.123] <TB1> INFO: 4472000 events read in total (194893ms).
[16:41:10.228] <TB1> INFO: Test took 195865ms.
[16:41:39.745] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 212 (-1/-1) hits flags = 528 (plus default)
[16:41:39.762] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[16:41:39.762] <TB1> INFO: run 1 of 1
[16:41:40.061] <TB1> INFO: Expecting 4430400 events.
[16:42:12.057] <TB1> INFO: 738550 events read in total (31404ms).
[16:42:43.313] <TB1> INFO: 1472690 events read in total (62660ms).
[16:43:14.678] <TB1> INFO: 2202390 events read in total (94026ms).
[16:43:45.876] <TB1> INFO: 2928120 events read in total (125223ms).
[16:44:17.154] <TB1> INFO: 3651815 events read in total (156501ms).
[16:44:48.206] <TB1> INFO: 4376365 events read in total (187553ms).
[16:44:50.928] <TB1> INFO: 4430400 events read in total (190275ms).
[16:44:51.052] <TB1> INFO: Test took 191289ms.
[16:45:18.313] <TB1> INFO: PixTestTrim80::trimBitTest() done
[16:45:18.315] <TB1> INFO: PixTestTrim80::doTest() done, duration: 2757 seconds
[16:45:19.077] <TB1> INFO: enter test to run
[16:45:19.077] <TB1> INFO: test: exit no parameter change
[16:45:19.301] <TB1> QUIET: Connection to board 154 closed.
[16:45:19.302] <TB1> INFO: pXar: this is the end, my friend