[11:31:55.977] <TB1> INFO: *** Welcome to pxar ***
[11:31:55.977] <TB1> INFO: *** Today: 2016/11/03
[11:31:55.984] <TB1> INFO: *** Version: c8ba-dirty
[11:31:55.984] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C15.dat
[11:31:55.984] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[11:31:55.985] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//defaultMaskFile.dat
[11:31:55.985] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters_C15.dat
[11:31:56.086] <TB1> INFO: clk: 4
[11:31:56.086] <TB1> INFO: ctr: 4
[11:31:56.086] <TB1> INFO: sda: 19
[11:31:56.086] <TB1> INFO: tin: 9
[11:31:56.086] <TB1> INFO: level: 15
[11:31:56.086] <TB1> INFO: triggerdelay: 0
[11:31:56.086] <TB1> QUIET: Instanciating API for pxar v2.7.6+61~g7f4a123
[11:31:56.086] <TB1> INFO: Log level: INFO
[11:31:56.096] <TB1> INFO: Found DTB DTB_WXC03A
[11:31:56.108] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[11:31:56.110] <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:
------------------------------------------------------
[11:31:56.112] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[11:31:57.670] <TB1> INFO: DUT info:
[11:31:57.670] <TB1> INFO: The DUT currently contains the following objects:
[11:31:57.671] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[11:31:57.671] <TB1> INFO: TBM Core alpha (0): 7 registers set
[11:31:57.671] <TB1> INFO: TBM Core beta (1): 7 registers set
[11:31:57.671] <TB1> INFO: TBM Core alpha (2): 7 registers set
[11:31:57.671] <TB1> INFO: TBM Core beta (3): 7 registers set
[11:31:57.671] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[11:31:57.671] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:57.671] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:31:58.072] <TB1> INFO: enter 'restricted' command line mode
[11:31:58.073] <TB1> INFO: enter test to run
[11:31:58.073] <TB1> INFO: test: pretest no parameter change
[11:31:58.073] <TB1> INFO: running: pretest
[11:31:58.076] <TB1> INFO: ######################################################################
[11:31:58.076] <TB1> INFO: PixTestPretest::doTest()
[11:31:58.076] <TB1> INFO: ######################################################################
[11:31:58.078] <TB1> INFO: ----------------------------------------------------------------------
[11:31:58.078] <TB1> INFO: PixTestPretest::programROC()
[11:31:58.078] <TB1> INFO: ----------------------------------------------------------------------
[11:32:16.091] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[11:32:16.091] <TB1> INFO: IA differences per ROC: 20.1 18.5 18.5 20.9 18.5 17.7 20.9 20.1 20.9 20.1 16.1 19.3 16.9 20.1 17.7 17.7
[11:32:16.148] <TB1> INFO: ----------------------------------------------------------------------
[11:32:16.148] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[11:32:16.149] <TB1> INFO: ----------------------------------------------------------------------
[11:32:37.400] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 382.7 mA = 23.9187 mA/ROC
[11:32:37.400] <TB1> INFO: i(loss) [mA/ROC]: 20.9 20.1 19.3 19.3 20.1 19.3 20.1 19.3 20.1 20.1 19.3 19.3 19.3 19.3 20.1 20.1
[11:32:37.431] <TB1> INFO: ----------------------------------------------------------------------
[11:32:37.431] <TB1> INFO: PixTestPretest::findTiming()
[11:32:37.431] <TB1> INFO: ----------------------------------------------------------------------
[11:32:37.431] <TB1> INFO: PixTestCmd::init()

[11:33:08.947] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[11:33:08.947] <TB1> INFO: (success/tries = 100/100), width = 4
[11:33:10.454] <TB1> INFO: ----------------------------------------------------------------------
[11:33:10.454] <TB1> INFO: PixTestPretest::findWorkingPixel()
[11:33:10.454] <TB1> INFO: ----------------------------------------------------------------------
[11:33:10.546] <TB1> INFO: Expecting 231680 events.
[11:33:20.248] <TB1> INFO: 231680 events read in total (9110ms).
[11:33:20.258] <TB1> INFO: Test took 9801ms.
[11:33:20.498] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[11:33:20.531] <TB1> INFO: ----------------------------------------------------------------------
[11:33:20.531] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[11:33:20.531] <TB1> INFO: ----------------------------------------------------------------------
[11:33:20.624] <TB1> INFO: Expecting 231680 events.
[11:33:30.378] <TB1> INFO: 231680 events read in total (9163ms).
[11:33:30.389] <TB1> INFO: Test took 9854ms.
[11:33:30.640] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[11:33:30.640] <TB1> INFO: CalDel: 67 89 84 78 77 85 75 79 99 95 85 93 80 90 88 78
[11:33:30.640] <TB1> INFO: VthrComp: 54 52 51 51 51 51 51 53 51 51 51 52 51 51 51 54
[11:33:30.643] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C0.dat
[11:33:30.643] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C1.dat
[11:33:30.643] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C2.dat
[11:33:30.643] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C3.dat
[11:33:30.643] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C4.dat
[11:33:30.643] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C5.dat
[11:33:30.643] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C6.dat
[11:33:30.644] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C7.dat
[11:33:30.644] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C8.dat
[11:33:30.644] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C9.dat
[11:33:30.644] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C10.dat
[11:33:30.644] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C11.dat
[11:33:30.644] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C12.dat
[11:33:30.644] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C13.dat
[11:33:30.644] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C14.dat
[11:33:30.644] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters_C15.dat
[11:33:30.644] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//tbmParameters_C0a.dat
[11:33:30.645] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//tbmParameters_C0b.dat
[11:33:30.645] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//tbmParameters_C1a.dat
[11:33:30.645] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[11:33:30.645] <TB1> INFO: PixTestPretest::doTest() done, duration: 92 seconds
[11:33:30.696] <TB1> INFO: enter test to run
[11:33:30.696] <TB1> INFO: test: fulltest no parameter change
[11:33:30.696] <TB1> INFO: running: fulltest
[11:33:30.697] <TB1> INFO: ######################################################################
[11:33:30.697] <TB1> INFO: PixTestFullTest::doTest()
[11:33:30.697] <TB1> INFO: ######################################################################
[11:33:30.698] <TB1> INFO: ######################################################################
[11:33:30.698] <TB1> INFO: PixTestAlive::doTest()
[11:33:30.698] <TB1> INFO: ######################################################################
[11:33:30.699] <TB1> INFO: ----------------------------------------------------------------------
[11:33:30.699] <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)
[11:33:30.699] <TB1> INFO: ----------------------------------------------------------------------
[11:33:30.942] <TB1> INFO: Expecting 41600 events.
[11:33:34.399] <TB1> INFO: 41600 events read in total (2866ms).
[11:33:34.400] <TB1> INFO: Test took 3699ms.
[11:33:34.628] <TB1> INFO: PixTestAlive::aliveTest() done
[11:33:34.628] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0
[11:33:34.629] <TB1> INFO: ----------------------------------------------------------------------
[11:33:34.630] <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)
[11:33:34.630] <TB1> INFO: ----------------------------------------------------------------------
[11:33:34.868] <TB1> INFO: Expecting 41600 events.
[11:33:37.869] <TB1> INFO: 41600 events read in total (2410ms).
[11:33:37.869] <TB1> INFO: Test took 3238ms.
[11:33:37.869] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[11:33:38.109] <TB1> INFO: PixTestAlive::maskTest() done
[11:33:38.109] <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
[11:33:38.110] <TB1> INFO: ----------------------------------------------------------------------
[11:33:38.110] <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)
[11:33:38.110] <TB1> INFO: ----------------------------------------------------------------------
[11:33:38.356] <TB1> INFO: Expecting 41600 events.
[11:33:41.804] <TB1> INFO: 41600 events read in total (2856ms).
[11:33:41.805] <TB1> INFO: Test took 3692ms.
[11:33:42.035] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[11:33:42.035] <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
[11:33:42.035] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[11:33:42.035] <TB1> INFO: Decoding statistics:
[11:33:42.035] <TB1> INFO: General information:
[11:33:42.035] <TB1> INFO: 16bit words read: 0
[11:33:42.035] <TB1> INFO: valid events total: 0
[11:33:42.035] <TB1> INFO: empty events: 0
[11:33:42.035] <TB1> INFO: valid events with pixels: 0
[11:33:42.035] <TB1> INFO: valid pixel hits: 0
[11:33:42.035] <TB1> INFO: Event errors: 0
[11:33:42.035] <TB1> INFO: start marker: 0
[11:33:42.035] <TB1> INFO: stop marker: 0
[11:33:42.035] <TB1> INFO: overflow: 0
[11:33:42.035] <TB1> INFO: invalid 5bit words: 0
[11:33:42.035] <TB1> INFO: invalid XOR eye diagram: 0
[11:33:42.035] <TB1> INFO: frame (failed synchr.): 0
[11:33:42.035] <TB1> INFO: idle data (no TBM trl): 0
[11:33:42.035] <TB1> INFO: no data (only TBM hdr): 0
[11:33:42.035] <TB1> INFO: TBM errors: 0
[11:33:42.035] <TB1> INFO: flawed TBM headers: 0
[11:33:42.035] <TB1> INFO: flawed TBM trailers: 0
[11:33:42.035] <TB1> INFO: event ID mismatches: 0
[11:33:42.035] <TB1> INFO: ROC errors: 0
[11:33:42.035] <TB1> INFO: missing ROC header(s): 0
[11:33:42.035] <TB1> INFO: misplaced readback start: 0
[11:33:42.035] <TB1> INFO: Pixel decoding errors: 0
[11:33:42.035] <TB1> INFO: pixel data incomplete: 0
[11:33:42.035] <TB1> INFO: pixel address: 0
[11:33:42.035] <TB1> INFO: pulse height fill bit: 0
[11:33:42.035] <TB1> INFO: buffer corruption: 0
[11:33:42.040] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C15.dat
[11:33:42.040] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr_C15.dat

[11:33:42.041] <TB1> INFO: ######################################################################
[11:33:42.041] <TB1> INFO: PixTestReadback::doTest()
[11:33:42.041] <TB1> INFO: ######################################################################
[11:33:42.041] <TB1> INFO: ----------------------------------------------------------------------
[11:33:42.041] <TB1> INFO: PixTestReadback::CalibrateVd()
[11:33:42.041] <TB1> INFO: ----------------------------------------------------------------------
[11:33:51.967] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C0.dat
[11:33:51.967] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C1.dat
[11:33:51.967] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C2.dat
[11:33:51.967] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C3.dat
[11:33:51.967] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C4.dat
[11:33:51.967] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C5.dat
[11:33:51.967] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C6.dat
[11:33:51.968] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C7.dat
[11:33:51.968] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C8.dat
[11:33:51.968] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C9.dat
[11:33:51.968] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C10.dat
[11:33:51.968] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C11.dat
[11:33:51.968] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C12.dat
[11:33:51.968] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C13.dat
[11:33:51.968] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C14.dat
[11:33:51.968] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C15.dat
[11:33:51.998] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[11:33:51.998] <TB1> INFO: ----------------------------------------------------------------------
[11:33:51.998] <TB1> INFO: PixTestReadback::CalibrateVa()
[11:33:51.998] <TB1> INFO: ----------------------------------------------------------------------
[11:34:01.894] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C0.dat
[11:34:01.894] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C1.dat
[11:34:01.894] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C2.dat
[11:34:01.894] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C3.dat
[11:34:01.894] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C4.dat
[11:34:01.894] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C5.dat
[11:34:01.894] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C6.dat
[11:34:01.894] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C7.dat
[11:34:01.894] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C8.dat
[11:34:01.895] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C9.dat
[11:34:01.895] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C10.dat
[11:34:01.895] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C11.dat
[11:34:01.895] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C12.dat
[11:34:01.895] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C13.dat
[11:34:01.895] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C14.dat
[11:34:01.895] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C15.dat
[11:34:01.926] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[11:34:01.926] <TB1> INFO: ----------------------------------------------------------------------
[11:34:01.926] <TB1> INFO: PixTestReadback::readbackVbg()
[11:34:01.926] <TB1> INFO: ----------------------------------------------------------------------
[11:34:09.571] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[11:34:09.571] <TB1> INFO: ----------------------------------------------------------------------
[11:34:09.571] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[11:34:09.571] <TB1> INFO: ----------------------------------------------------------------------
[11:34:09.571] <TB1> INFO: Vbg will be calibrated using Vd calibration
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 163.2calibrated Vbg = 1.19628 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 157.6calibrated Vbg = 1.19496 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 158calibrated Vbg = 1.18588 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 151.9calibrated Vbg = 1.18449 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 151calibrated Vbg = 1.1868 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 151.4calibrated Vbg = 1.19811 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 160calibrated Vbg = 1.19302 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 161.6calibrated Vbg = 1.19362 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 162.2calibrated Vbg = 1.19109 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 145.9calibrated Vbg = 1.19016 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 157.9calibrated Vbg = 1.19006 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 159.9calibrated Vbg = 1.18439 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 159.2calibrated Vbg = 1.18434 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 164.1calibrated Vbg = 1.19067 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 154.7calibrated Vbg = 1.19141 :::*/*/*/*/
[11:34:09.571] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 158calibrated Vbg = 1.19486 :::*/*/*/*/
[11:34:09.573] <TB1> INFO: ----------------------------------------------------------------------
[11:34:09.573] <TB1> INFO: PixTestReadback::CalibrateIa()
[11:34:09.573] <TB1> INFO: ----------------------------------------------------------------------
[11:36:49.939] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C0.dat
[11:36:49.939] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C1.dat
[11:36:49.939] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C2.dat
[11:36:49.939] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C3.dat
[11:36:49.939] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C4.dat
[11:36:49.939] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C5.dat
[11:36:49.939] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C6.dat
[11:36:49.939] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C7.dat
[11:36:49.939] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C8.dat
[11:36:49.940] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C9.dat
[11:36:49.940] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C10.dat
[11:36:49.940] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C11.dat
[11:36:49.940] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C12.dat
[11:36:49.940] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C13.dat
[11:36:49.940] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C14.dat
[11:36:49.940] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//readbackCal_C15.dat
[11:36:49.968] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[11:36:49.969] <TB1> INFO: PixTestReadback::doTest() done
[11:36:49.969] <TB1> INFO: Decoding statistics:
[11:36:49.969] <TB1> INFO: General information:
[11:36:49.969] <TB1> INFO: 16bit words read: 1536
[11:36:49.969] <TB1> INFO: valid events total: 256
[11:36:49.969] <TB1> INFO: empty events: 256
[11:36:49.969] <TB1> INFO: valid events with pixels: 0
[11:36:49.969] <TB1> INFO: valid pixel hits: 0
[11:36:49.969] <TB1> INFO: Event errors: 0
[11:36:49.969] <TB1> INFO: start marker: 0
[11:36:49.969] <TB1> INFO: stop marker: 0
[11:36:49.970] <TB1> INFO: overflow: 0
[11:36:49.970] <TB1> INFO: invalid 5bit words: 0
[11:36:49.970] <TB1> INFO: invalid XOR eye diagram: 0
[11:36:49.970] <TB1> INFO: frame (failed synchr.): 0
[11:36:49.970] <TB1> INFO: idle data (no TBM trl): 0
[11:36:49.970] <TB1> INFO: no data (only TBM hdr): 0
[11:36:49.970] <TB1> INFO: TBM errors: 0
[11:36:49.970] <TB1> INFO: flawed TBM headers: 0
[11:36:49.970] <TB1> INFO: flawed TBM trailers: 0
[11:36:49.970] <TB1> INFO: event ID mismatches: 0
[11:36:49.970] <TB1> INFO: ROC errors: 0
[11:36:49.970] <TB1> INFO: missing ROC header(s): 0
[11:36:49.970] <TB1> INFO: misplaced readback start: 0
[11:36:49.970] <TB1> INFO: Pixel decoding errors: 0
[11:36:49.970] <TB1> INFO: pixel data incomplete: 0
[11:36:49.970] <TB1> INFO: pixel address: 0
[11:36:49.970] <TB1> INFO: pulse height fill bit: 0
[11:36:49.970] <TB1> INFO: buffer corruption: 0
[11:36:50.021] <TB1> INFO: ######################################################################
[11:36:50.021] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[11:36:50.021] <TB1> INFO: ######################################################################
[11:36:50.023] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[11:36:50.071] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[11:36:50.071] <TB1> INFO: run 1 of 1
[11:36:50.312] <TB1> INFO: Expecting 3120000 events.
[11:37:22.045] <TB1> INFO: 688115 events read in total (31141ms).











[11:37:53.201] <TB1> INFO: 1374045 events read in total (62297ms).











[11:38:23.857] <TB1> INFO: 2056805 events read in total (92953ms).











[11:38:55.194] <TB1> INFO: 2740020 events read in total (124290ms).











[11:39:13.054] <TB1> INFO: 3120000 events read in total (142150ms).
[11:39:13.139] <TB1> INFO: Test took 143068ms.
[11:39:40.786] <TB1> INFO: PixTestBBMap::doTest() done, duration: 170 seconds
[11:39:40.786] <TB1> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 2 0 0 0 0 0 0 1 0 0
[11:39:40.786] <TB1> INFO: separation cut (per ROC): 138 136 107 132 120 110 124 136 120 113 104 125 107 110 117 125
[11:39:40.786] <TB1> INFO: Decoding statistics:
[11:39:40.786] <TB1> INFO: General information:
[11:39:40.786] <TB1> INFO: 16bit words read: 0
[11:39:40.786] <TB1> INFO: valid events total: 0
[11:39:40.786] <TB1> INFO: empty events: 0
[11:39:40.786] <TB1> INFO: valid events with pixels: 0
[11:39:40.786] <TB1> INFO: valid pixel hits: 0
[11:39:40.786] <TB1> INFO: Event errors: 0
[11:39:40.786] <TB1> INFO: start marker: 0
[11:39:40.786] <TB1> INFO: stop marker: 0
[11:39:40.786] <TB1> INFO: overflow: 0
[11:39:40.786] <TB1> INFO: invalid 5bit words: 0
[11:39:40.786] <TB1> INFO: invalid XOR eye diagram: 0
[11:39:40.786] <TB1> INFO: frame (failed synchr.): 0
[11:39:40.786] <TB1> INFO: idle data (no TBM trl): 0
[11:39:40.786] <TB1> INFO: no data (only TBM hdr): 0
[11:39:40.786] <TB1> INFO: TBM errors: 0
[11:39:40.786] <TB1> INFO: flawed TBM headers: 0
[11:39:40.786] <TB1> INFO: flawed TBM trailers: 0
[11:39:40.786] <TB1> INFO: event ID mismatches: 0
[11:39:40.786] <TB1> INFO: ROC errors: 0
[11:39:40.786] <TB1> INFO: missing ROC header(s): 0
[11:39:40.786] <TB1> INFO: misplaced readback start: 0
[11:39:40.786] <TB1> INFO: Pixel decoding errors: 0
[11:39:40.786] <TB1> INFO: pixel data incomplete: 0
[11:39:40.786] <TB1> INFO: pixel address: 0
[11:39:40.786] <TB1> INFO: pulse height fill bit: 0
[11:39:40.786] <TB1> INFO: buffer corruption: 0
[11:39:40.823] <TB1> INFO: ######################################################################
[11:39:40.823] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:39:40.823] <TB1> INFO: ######################################################################
[11:39:40.824] <TB1> INFO: ----------------------------------------------------------------------
[11:39:40.824] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[11:39:40.824] <TB1> INFO: ----------------------------------------------------------------------
[11:39:40.824] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[11:39:40.839] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[11:39:40.839] <TB1> INFO: run 1 of 1
[11:39:41.085] <TB1> INFO: Expecting 36608000 events.
[11:40:06.500] <TB1> INFO: 698500 events read in total (24824ms).
[11:40:30.211] <TB1> INFO: 1376600 events read in total (48535ms).
[11:40:54.245] <TB1> INFO: 2060600 events read in total (72569ms).
[11:41:17.826] <TB1> INFO: 2740150 events read in total (96150ms).
[11:41:41.458] <TB1> INFO: 3422550 events read in total (119782ms).
[11:42:05.286] <TB1> INFO: 4103400 events read in total (143610ms).
[11:42:29.322] <TB1> INFO: 4785650 events read in total (167646ms).
[11:42:53.273] <TB1> INFO: 5468300 events read in total (191597ms).
[11:43:16.938] <TB1> INFO: 6149450 events read in total (215262ms).
[11:43:40.706] <TB1> INFO: 6828150 events read in total (239030ms).
[11:44:04.579] <TB1> INFO: 7509600 events read in total (262903ms).
[11:44:28.430] <TB1> INFO: 8190750 events read in total (286754ms).
[11:44:52.109] <TB1> INFO: 8871450 events read in total (310433ms).
[11:45:15.875] <TB1> INFO: 9550450 events read in total (334199ms).
[11:45:39.346] <TB1> INFO: 10231000 events read in total (357670ms).
[11:46:02.938] <TB1> INFO: 10910800 events read in total (381262ms).
[11:46:26.615] <TB1> INFO: 11588850 events read in total (404939ms).
[11:46:50.356] <TB1> INFO: 12267550 events read in total (428680ms).
[11:47:14.079] <TB1> INFO: 12944450 events read in total (452403ms).
[11:47:37.319] <TB1> INFO: 13622300 events read in total (475643ms).
[11:48:00.818] <TB1> INFO: 14297850 events read in total (499142ms).
[11:48:24.270] <TB1> INFO: 14975550 events read in total (522594ms).
[11:48:47.755] <TB1> INFO: 15651850 events read in total (546079ms).
[11:49:11.412] <TB1> INFO: 16329650 events read in total (569736ms).
[11:49:34.542] <TB1> INFO: 17003500 events read in total (592866ms).
[11:49:58.150] <TB1> INFO: 17679450 events read in total (616474ms).
[11:50:21.806] <TB1> INFO: 18352250 events read in total (640130ms).
[11:50:45.489] <TB1> INFO: 19025600 events read in total (663813ms).
[11:51:08.800] <TB1> INFO: 19695800 events read in total (687124ms).
[11:51:32.319] <TB1> INFO: 20369400 events read in total (710643ms).
[11:51:55.788] <TB1> INFO: 21038800 events read in total (734112ms).
[11:52:18.937] <TB1> INFO: 21712100 events read in total (757261ms).
[11:52:42.509] <TB1> INFO: 22383900 events read in total (780833ms).
[11:53:05.913] <TB1> INFO: 23055150 events read in total (804237ms).
[11:53:29.230] <TB1> INFO: 23724350 events read in total (827554ms).
[11:53:52.494] <TB1> INFO: 24395100 events read in total (850818ms).
[11:54:15.741] <TB1> INFO: 25066200 events read in total (874065ms).
[11:54:39.214] <TB1> INFO: 25737100 events read in total (897538ms).
[11:55:02.480] <TB1> INFO: 26406500 events read in total (920804ms).
[11:55:25.520] <TB1> INFO: 27076700 events read in total (943844ms).
[11:55:48.488] <TB1> INFO: 27748200 events read in total (966812ms).
[11:56:11.508] <TB1> INFO: 28417900 events read in total (989832ms).
[11:56:34.760] <TB1> INFO: 29089950 events read in total (1013084ms).
[11:56:57.793] <TB1> INFO: 29759400 events read in total (1036117ms).
[11:57:21.250] <TB1> INFO: 30428250 events read in total (1059574ms).
[11:57:44.701] <TB1> INFO: 31095200 events read in total (1083025ms).
[11:58:08.016] <TB1> INFO: 31764350 events read in total (1106340ms).
[11:58:31.304] <TB1> INFO: 32431700 events read in total (1129628ms).
[11:58:54.877] <TB1> INFO: 33102850 events read in total (1153201ms).
[11:59:18.287] <TB1> INFO: 33773300 events read in total (1176611ms).
[11:59:41.803] <TB1> INFO: 34444900 events read in total (1200127ms).
[12:00:05.178] <TB1> INFO: 35112450 events read in total (1223502ms).
[12:00:28.851] <TB1> INFO: 35785750 events read in total (1247175ms).
[12:00:52.503] <TB1> INFO: 36467750 events read in total (1270827ms).
[12:00:57.789] <TB1> INFO: 36608000 events read in total (1276113ms).
[12:00:57.874] <TB1> INFO: Test took 1277035ms.
[12:00:58.251] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:00.141] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:01.702] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:03.617] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:05.706] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:08.056] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:09.813] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:11.316] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:12.935] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:14.606] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:16.150] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:18.128] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:19.686] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:21.678] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:23.786] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:25.894] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[12:01:28.352] <TB1> INFO: PixTestScurves::scurves() done
[12:01:28.352] <TB1> INFO: Vcal mean: 139.79 139.60 115.33 132.03 119.29 119.51 133.65 135.19 131.56 124.59 118.25 134.88 122.60 113.27 126.24 130.64
[12:01:28.352] <TB1> INFO: Vcal RMS: 5.92 6.32 5.77 6.09 5.99 5.92 6.32 6.20 6.54 5.92 6.21 6.00 6.53 5.38 6.10 6.29
[12:01:28.353] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1307 seconds
[12:01:28.353] <TB1> INFO: Decoding statistics:
[12:01:28.353] <TB1> INFO: General information:
[12:01:28.353] <TB1> INFO: 16bit words read: 0
[12:01:28.353] <TB1> INFO: valid events total: 0
[12:01:28.353] <TB1> INFO: empty events: 0
[12:01:28.353] <TB1> INFO: valid events with pixels: 0
[12:01:28.353] <TB1> INFO: valid pixel hits: 0
[12:01:28.353] <TB1> INFO: Event errors: 0
[12:01:28.353] <TB1> INFO: start marker: 0
[12:01:28.353] <TB1> INFO: stop marker: 0
[12:01:28.353] <TB1> INFO: overflow: 0
[12:01:28.353] <TB1> INFO: invalid 5bit words: 0
[12:01:28.353] <TB1> INFO: invalid XOR eye diagram: 0
[12:01:28.353] <TB1> INFO: frame (failed synchr.): 0
[12:01:28.353] <TB1> INFO: idle data (no TBM trl): 0
[12:01:28.353] <TB1> INFO: no data (only TBM hdr): 0
[12:01:28.353] <TB1> INFO: TBM errors: 0
[12:01:28.353] <TB1> INFO: flawed TBM headers: 0
[12:01:28.353] <TB1> INFO: flawed TBM trailers: 0
[12:01:28.353] <TB1> INFO: event ID mismatches: 0
[12:01:28.353] <TB1> INFO: ROC errors: 0
[12:01:28.353] <TB1> INFO: missing ROC header(s): 0
[12:01:28.353] <TB1> INFO: misplaced readback start: 0
[12:01:28.353] <TB1> INFO: Pixel decoding errors: 0
[12:01:28.353] <TB1> INFO: pixel data incomplete: 0
[12:01:28.353] <TB1> INFO: pixel address: 0
[12:01:28.353] <TB1> INFO: pulse height fill bit: 0
[12:01:28.353] <TB1> INFO: buffer corruption: 0
[12:01:28.454] <TB1> INFO: ######################################################################
[12:01:28.454] <TB1> INFO: PixTestTrim::doTest()
[12:01:28.454] <TB1> INFO: ######################################################################
[12:01:28.455] <TB1> INFO: ----------------------------------------------------------------------
[12:01:28.455] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[12:01:28.455] <TB1> INFO: ----------------------------------------------------------------------
[12:01:28.525] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:01:28.525] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:01:28.540] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:01:28.540] <TB1> INFO: run 1 of 1
[12:01:28.872] <TB1> INFO: Expecting 5025280 events.
[12:02:00.725] <TB1> INFO: 828352 events read in total (31249ms).
[12:02:31.231] <TB1> INFO: 1654232 events read in total (61756ms).
[12:03:01.943] <TB1> INFO: 2477000 events read in total (92468ms).
[12:03:32.307] <TB1> INFO: 3296696 events read in total (122831ms).
[12:04:03.158] <TB1> INFO: 4113624 events read in total (153682ms).
[12:04:33.750] <TB1> INFO: 4928736 events read in total (184274ms).
[12:04:37.835] <TB1> INFO: 5025280 events read in total (188359ms).
[12:04:37.898] <TB1> INFO: Test took 189359ms.
[12:04:54.602] <TB1> INFO: ROC 0 VthrComp = 138
[12:04:54.602] <TB1> INFO: ROC 1 VthrComp = 132
[12:04:54.609] <TB1> INFO: ROC 2 VthrComp = 119
[12:04:54.611] <TB1> INFO: ROC 3 VthrComp = 134
[12:04:54.613] <TB1> INFO: ROC 4 VthrComp = 126
[12:04:54.614] <TB1> INFO: ROC 5 VthrComp = 119
[12:04:54.615] <TB1> INFO: ROC 6 VthrComp = 132
[12:04:54.615] <TB1> INFO: ROC 7 VthrComp = 138
[12:04:54.617] <TB1> INFO: ROC 8 VthrComp = 127
[12:04:54.618] <TB1> INFO: ROC 9 VthrComp = 127
[12:04:54.620] <TB1> INFO: ROC 10 VthrComp = 118
[12:04:54.620] <TB1> INFO: ROC 11 VthrComp = 132
[12:04:54.620] <TB1> INFO: ROC 12 VthrComp = 120
[12:04:54.620] <TB1> INFO: ROC 13 VthrComp = 120
[12:04:54.621] <TB1> INFO: ROC 14 VthrComp = 125
[12:04:54.621] <TB1> INFO: ROC 15 VthrComp = 132
[12:04:54.947] <TB1> INFO: Expecting 41600 events.
[12:04:58.549] <TB1> INFO: 41600 events read in total (3010ms).
[12:04:58.550] <TB1> INFO: Test took 3927ms.
[12:04:58.561] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[12:04:58.561] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:04:58.575] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:04:58.576] <TB1> INFO: run 1 of 1
[12:04:58.853] <TB1> INFO: Expecting 5025280 events.
[12:05:26.169] <TB1> INFO: 590712 events read in total (26724ms).
[12:05:52.394] <TB1> INFO: 1179816 events read in total (52949ms).
[12:06:18.825] <TB1> INFO: 1769176 events read in total (79380ms).
[12:06:45.261] <TB1> INFO: 2357424 events read in total (105816ms).
[12:07:11.160] <TB1> INFO: 2943584 events read in total (131715ms).
[12:07:37.652] <TB1> INFO: 3528464 events read in total (158207ms).
[12:08:03.681] <TB1> INFO: 4112560 events read in total (184236ms).
[12:08:29.875] <TB1> INFO: 4696040 events read in total (210430ms).
[12:08:45.189] <TB1> INFO: 5025280 events read in total (225744ms).
[12:08:45.303] <TB1> INFO: Test took 226728ms.
[12:09:15.056] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 69.9258 for pixel 1/57 mean/min/max = 54.0454/37.7996/70.2913
[12:09:15.056] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 70.2237 for pixel 7/77 mean/min/max = 53.9378/37.5266/70.349
[12:09:15.057] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 58.3605 for pixel 14/64 mean/min/max = 44.794/31.1104/58.4776
[12:09:15.057] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 61.4087 for pixel 0/8 mean/min/max = 49.009/36.5685/61.4496
[12:09:15.058] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 56.5804 for pixel 0/57 mean/min/max = 44.0145/31.3894/56.6395
[12:09:15.058] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 59.311 for pixel 3/1 mean/min/max = 45.5291/31.544/59.5142
[12:09:15.058] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 62.5819 for pixel 9/3 mean/min/max = 47.8367/32.8557/62.8177
[12:09:15.059] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 66.2719 for pixel 6/78 mean/min/max = 51.5169/36.7039/66.33
[12:09:15.059] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 62.0234 for pixel 8/78 mean/min/max = 47.1204/32.0847/62.1561
[12:09:15.060] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 59.4511 for pixel 0/8 mean/min/max = 45.9759/32.0349/59.9169
[12:09:15.060] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 59.6904 for pixel 5/59 mean/min/max = 45.8179/31.8722/59.7636
[12:09:15.061] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 60.798 for pixel 0/16 mean/min/max = 46.2417/31.6848/60.7987
[12:09:15.061] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 60.9883 for pixel 29/47 mean/min/max = 47.6765/34.2607/61.0923
[12:09:15.061] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 58.3406 for pixel 0/48 mean/min/max = 45.5433/32.6288/58.4579
[12:09:15.062] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 62.705 for pixel 13/12 mean/min/max = 46.9396/30.8671/63.0121
[12:09:15.062] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 61.364 for pixel 1/79 mean/min/max = 46.6577/31.9291/61.3863
[12:09:15.062] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:09:15.151] <TB1> INFO: Expecting 411648 events.
[12:09:25.130] <TB1> INFO: 411648 events read in total (9387ms).
[12:09:25.138] <TB1> INFO: Expecting 411648 events.
[12:09:34.480] <TB1> INFO: 411648 events read in total (8939ms).
[12:09:34.493] <TB1> INFO: Expecting 411648 events.
[12:09:44.083] <TB1> INFO: 411648 events read in total (9186ms).
[12:09:44.102] <TB1> INFO: Expecting 411648 events.
[12:09:53.350] <TB1> INFO: 411648 events read in total (8839ms).
[12:09:53.369] <TB1> INFO: Expecting 411648 events.
[12:10:02.463] <TB1> INFO: 411648 events read in total (8691ms).
[12:10:02.483] <TB1> INFO: Expecting 411648 events.
[12:10:11.711] <TB1> INFO: 411648 events read in total (8825ms).
[12:10:11.733] <TB1> INFO: Expecting 411648 events.
[12:10:20.902] <TB1> INFO: 411648 events read in total (8766ms).
[12:10:20.939] <TB1> INFO: Expecting 411648 events.
[12:10:30.116] <TB1> INFO: 411648 events read in total (8774ms).
[12:10:30.144] <TB1> INFO: Expecting 411648 events.
[12:10:39.313] <TB1> INFO: 411648 events read in total (8766ms).
[12:10:39.351] <TB1> INFO: Expecting 411648 events.
[12:10:48.482] <TB1> INFO: 411648 events read in total (8727ms).
[12:10:48.520] <TB1> INFO: Expecting 411648 events.
[12:10:57.738] <TB1> INFO: 411648 events read in total (8815ms).
[12:10:57.798] <TB1> INFO: Expecting 411648 events.
[12:11:06.855] <TB1> INFO: 411648 events read in total (8654ms).
[12:11:06.897] <TB1> INFO: Expecting 411648 events.
[12:11:16.214] <TB1> INFO: 411648 events read in total (8914ms).
[12:11:16.283] <TB1> INFO: Expecting 411648 events.
[12:11:25.480] <TB1> INFO: 411648 events read in total (8795ms).
[12:11:25.537] <TB1> INFO: Expecting 411648 events.
[12:11:34.705] <TB1> INFO: 411648 events read in total (8765ms).
[12:11:34.753] <TB1> INFO: Expecting 411648 events.
[12:11:43.937] <TB1> INFO: 411648 events read in total (8781ms).
[12:11:44.003] <TB1> INFO: Test took 148941ms.
[12:11:44.910] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[12:11:44.924] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:11:44.924] <TB1> INFO: run 1 of 1
[12:11:45.166] <TB1> INFO: Expecting 5025280 events.
[12:12:11.692] <TB1> INFO: 587272 events read in total (25934ms).
[12:12:38.388] <TB1> INFO: 1174464 events read in total (52630ms).
[12:13:04.850] <TB1> INFO: 1758720 events read in total (79092ms).
[12:13:31.667] <TB1> INFO: 2345416 events read in total (105909ms).
[12:13:59.129] <TB1> INFO: 2933848 events read in total (133371ms).
[12:14:26.105] <TB1> INFO: 3523512 events read in total (160347ms).
[12:14:53.051] <TB1> INFO: 4111752 events read in total (187293ms).
[12:15:20.185] <TB1> INFO: 4699064 events read in total (214427ms).
[12:15:35.548] <TB1> INFO: 5025280 events read in total (229790ms).
[12:15:35.729] <TB1> INFO: Test took 230805ms.
[12:16:03.171] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 11.746174 .. 128.730605
[12:16:03.497] <TB1> INFO: Expecting 208000 events.
[12:16:13.982] <TB1> INFO: 208000 events read in total (9893ms).
[12:16:13.984] <TB1> INFO: Test took 10812ms.
[12:16:14.041] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 1 .. 138 (-1/-1) hits flags = 528 (plus default)
[12:16:14.056] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:16:14.056] <TB1> INFO: run 1 of 1
[12:16:14.334] <TB1> INFO: Expecting 4592640 events.
[12:16:42.411] <TB1> INFO: 591368 events read in total (27485ms).
[12:17:09.902] <TB1> INFO: 1183096 events read in total (54976ms).
[12:17:36.761] <TB1> INFO: 1774656 events read in total (81835ms).
[12:18:04.316] <TB1> INFO: 2366400 events read in total (109390ms).
[12:18:31.495] <TB1> INFO: 2957368 events read in total (136569ms).
[12:18:58.736] <TB1> INFO: 3547960 events read in total (163810ms).
[12:19:25.633] <TB1> INFO: 4137552 events read in total (190708ms).
[12:19:46.156] <TB1> INFO: 4592640 events read in total (211230ms).
[12:19:46.273] <TB1> INFO: Test took 212217ms.
[12:20:12.852] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 27.443012 .. 46.207104
[12:20:13.187] <TB1> INFO: Expecting 208000 events.
[12:20:23.387] <TB1> INFO: 208000 events read in total (9608ms).
[12:20:23.388] <TB1> INFO: Test took 10536ms.
[12:20:23.441] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 56 (-1/-1) hits flags = 528 (plus default)
[12:20:23.455] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:20:23.455] <TB1> INFO: run 1 of 1
[12:20:23.746] <TB1> INFO: Expecting 1331200 events.
[12:20:54.254] <TB1> INFO: 656856 events read in total (29917ms).
[12:21:22.855] <TB1> INFO: 1311512 events read in total (58518ms).
[12:21:24.194] <TB1> INFO: 1331200 events read in total (59858ms).
[12:21:24.239] <TB1> INFO: Test took 60785ms.
[12:21:40.104] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 26.881911 .. 49.839152
[12:21:40.480] <TB1> INFO: Expecting 208000 events.
[12:21:50.528] <TB1> INFO: 208000 events read in total (9456ms).
[12:21:50.530] <TB1> INFO: Test took 10424ms.
[12:21:50.612] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 59 (-1/-1) hits flags = 528 (plus default)
[12:21:50.627] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:21:50.627] <TB1> INFO: run 1 of 1
[12:21:50.905] <TB1> INFO: Expecting 1464320 events.
[12:22:21.104] <TB1> INFO: 649208 events read in total (29607ms).
[12:22:49.638] <TB1> INFO: 1297928 events read in total (58141ms).
[12:22:57.612] <TB1> INFO: 1464320 events read in total (66116ms).
[12:22:57.648] <TB1> INFO: Test took 67022ms.
[12:23:11.676] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 24.633593 .. 53.237067
[12:23:11.972] <TB1> INFO: Expecting 208000 events.
[12:23:21.866] <TB1> INFO: 208000 events read in total (9303ms).
[12:23:21.868] <TB1> INFO: Test took 10190ms.
[12:23:21.916] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 14 .. 63 (-1/-1) hits flags = 528 (plus default)
[12:23:21.930] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:23:21.930] <TB1> INFO: run 1 of 1
[12:23:22.208] <TB1> INFO: Expecting 1664000 events.
[12:23:51.598] <TB1> INFO: 644360 events read in total (28798ms).
[12:24:20.262] <TB1> INFO: 1288584 events read in total (57462ms).
[12:24:36.902] <TB1> INFO: 1664000 events read in total (74102ms).
[12:24:36.957] <TB1> INFO: Test took 75028ms.
[12:24:53.852] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[12:24:53.852] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[12:24:53.866] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:24:53.866] <TB1> INFO: run 1 of 1
[12:24:54.119] <TB1> INFO: Expecting 1364480 events.
[12:25:25.618] <TB1> INFO: 668768 events read in total (30906ms).
[12:25:54.519] <TB1> INFO: 1336520 events read in total (59807ms).
[12:25:56.125] <TB1> INFO: 1364480 events read in total (61413ms).
[12:25:56.155] <TB1> INFO: Test took 62289ms.
[12:26:10.956] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C0.dat
[12:26:10.956] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C1.dat
[12:26:10.956] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C2.dat
[12:26:10.956] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C3.dat
[12:26:10.956] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C4.dat
[12:26:10.956] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C5.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C6.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C7.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C8.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C9.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C10.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C11.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C12.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C13.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C14.dat
[12:26:10.957] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C15.dat
[12:26:10.958] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C0.dat
[12:26:10.963] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C1.dat
[12:26:10.967] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C2.dat
[12:26:10.972] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C3.dat
[12:26:10.977] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C4.dat
[12:26:10.981] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C5.dat
[12:26:10.986] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C6.dat
[12:26:10.991] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C7.dat
[12:26:10.995] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C8.dat
[12:26:10.000] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C9.dat
[12:26:11.005] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C10.dat
[12:26:11.010] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C11.dat
[12:26:11.014] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C12.dat
[12:26:11.019] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C13.dat
[12:26:11.024] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C14.dat
[12:26:11.028] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters35_C15.dat
[12:26:11.033] <TB1> INFO: PixTestTrim::trimTest() done
[12:26:11.033] <TB1> INFO: vtrim: 181 179 130 135 124 117 141 159 140 120 125 117 128 124 125 130
[12:26:11.033] <TB1> INFO: vthrcomp: 138 132 119 134 126 119 132 138 127 127 118 132 120 120 125 132
[12:26:11.033] <TB1> INFO: vcal mean: 35.34 35.68 35.05 35.01 34.98 35.01 35.18 36.01 35.17 35.06 35.26 35.39 35.15 34.99 36.07 35.21
[12:26:11.033] <TB1> INFO: vcal RMS: 1.46 1.90 1.12 0.97 1.14 1.17 1.34 2.15 1.31 1.23 1.51 1.58 1.32 0.94 2.21 1.29
[12:26:11.033] <TB1> INFO: bits mean: 7.57 8.19 10.22 7.38 10.16 9.58 9.47 8.57 9.42 9.29 9.79 9.38 9.31 8.93 10.16 9.59
[12:26:11.033] <TB1> INFO: bits RMS: 2.36 2.37 2.58 2.59 2.59 2.78 2.52 2.46 2.74 2.86 2.65 2.94 2.47 2.91 2.74 2.70
[12:26:11.044] <TB1> INFO: ----------------------------------------------------------------------
[12:26:11.044] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[12:26:11.044] <TB1> INFO: ----------------------------------------------------------------------
[12:26:11.047] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[12:26:11.061] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:26:11.061] <TB1> INFO: run 1 of 1
[12:26:11.329] <TB1> INFO: Expecting 4160000 events.
[12:26:45.503] <TB1> INFO: 773715 events read in total (33583ms).
[12:27:18.345] <TB1> INFO: 1542645 events read in total (66425ms).
[12:27:50.850] <TB1> INFO: 2304850 events read in total (98930ms).
[12:28:23.232] <TB1> INFO: 3061860 events read in total (131312ms).
[12:28:55.844] <TB1> INFO: 3816820 events read in total (163925ms).
[12:29:10.748] <TB1> INFO: 4160000 events read in total (178828ms).
[12:29:10.812] <TB1> INFO: Test took 179751ms.
[12:29:37.751] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 223 (-1/-1) hits flags = 528 (plus default)
[12:29:37.765] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:29:37.765] <TB1> INFO: run 1 of 1
[12:29:38.009] <TB1> INFO: Expecting 4659200 events.
[12:30:11.432] <TB1> INFO: 716615 events read in total (32829ms).
[12:30:43.028] <TB1> INFO: 1429640 events read in total (64425ms).
[12:31:13.756] <TB1> INFO: 2139605 events read in total (95153ms).
[12:31:44.493] <TB1> INFO: 2845575 events read in total (125890ms).
[12:32:15.327] <TB1> INFO: 3549435 events read in total (156724ms).
[12:32:46.143] <TB1> INFO: 4252105 events read in total (187540ms).
[12:33:04.508] <TB1> INFO: 4659200 events read in total (205905ms).
[12:33:04.606] <TB1> INFO: Test took 206841ms.
[12:33:38.098] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 208 (-1/-1) hits flags = 528 (plus default)
[12:33:38.116] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:33:38.117] <TB1> INFO: run 1 of 1
[12:33:38.443] <TB1> INFO: Expecting 4347200 events.
[12:34:11.220] <TB1> INFO: 735470 events read in total (32182ms).
[12:34:43.401] <TB1> INFO: 1466725 events read in total (64363ms).
[12:35:15.463] <TB1> INFO: 2193905 events read in total (96425ms).
[12:35:47.171] <TB1> INFO: 2916370 events read in total (128133ms).
[12:36:18.807] <TB1> INFO: 3636980 events read in total (159769ms).
[12:36:50.193] <TB1> INFO: 4347200 events read in total (191155ms).
[12:36:50.328] <TB1> INFO: Test took 192211ms.
[12:37:24.564] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 207 (-1/-1) hits flags = 528 (plus default)
[12:37:24.579] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:37:24.579] <TB1> INFO: run 1 of 1
[12:37:24.907] <TB1> INFO: Expecting 4326400 events.
[12:37:58.098] <TB1> INFO: 737015 events read in total (32599ms).
[12:38:30.094] <TB1> INFO: 1469565 events read in total (64595ms).
[12:39:01.866] <TB1> INFO: 2198215 events read in total (96367ms).
[12:39:33.371] <TB1> INFO: 2922170 events read in total (127872ms).
[12:40:04.612] <TB1> INFO: 3643940 events read in total (159113ms).
[12:40:34.642] <TB1> INFO: 4326400 events read in total (189143ms).
[12:40:34.762] <TB1> INFO: Test took 190182ms.
[12:41:07.439] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 208 (-1/-1) hits flags = 528 (plus default)
[12:41:07.455] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:41:07.455] <TB1> INFO: run 1 of 1
[12:41:07.719] <TB1> INFO: Expecting 4347200 events.
[12:41:40.866] <TB1> INFO: 735610 events read in total (32556ms).
[12:42:12.386] <TB1> INFO: 1467005 events read in total (64076ms).
[12:42:43.917] <TB1> INFO: 2194380 events read in total (95607ms).
[12:43:14.943] <TB1> INFO: 2917180 events read in total (126633ms).
[12:43:46.479] <TB1> INFO: 3638055 events read in total (158169ms).
[12:44:17.746] <TB1> INFO: 4347200 events read in total (189436ms).
[12:44:17.850] <TB1> INFO: Test took 190395ms.
[12:44:56.033] <TB1> INFO: PixTestTrim::trimBitTest() done
[12:44:56.035] <TB1> INFO: PixTestTrim::doTest() done, duration: 2607 seconds
[12:44:56.035] <TB1> INFO: Decoding statistics:
[12:44:56.035] <TB1> INFO: General information:
[12:44:56.035] <TB1> INFO: 16bit words read: 0
[12:44:56.035] <TB1> INFO: valid events total: 0
[12:44:56.035] <TB1> INFO: empty events: 0
[12:44:56.035] <TB1> INFO: valid events with pixels: 0
[12:44:56.035] <TB1> INFO: valid pixel hits: 0
[12:44:56.035] <TB1> INFO: Event errors: 0
[12:44:56.035] <TB1> INFO: start marker: 0
[12:44:56.035] <TB1> INFO: stop marker: 0
[12:44:56.035] <TB1> INFO: overflow: 0
[12:44:56.035] <TB1> INFO: invalid 5bit words: 0
[12:44:56.035] <TB1> INFO: invalid XOR eye diagram: 0
[12:44:56.035] <TB1> INFO: frame (failed synchr.): 0
[12:44:56.035] <TB1> INFO: idle data (no TBM trl): 0
[12:44:56.035] <TB1> INFO: no data (only TBM hdr): 0
[12:44:56.035] <TB1> INFO: TBM errors: 0
[12:44:56.036] <TB1> INFO: flawed TBM headers: 0
[12:44:56.036] <TB1> INFO: flawed TBM trailers: 0
[12:44:56.036] <TB1> INFO: event ID mismatches: 0
[12:44:56.036] <TB1> INFO: ROC errors: 0
[12:44:56.036] <TB1> INFO: missing ROC header(s): 0
[12:44:56.036] <TB1> INFO: misplaced readback start: 0
[12:44:56.036] <TB1> INFO: Pixel decoding errors: 0
[12:44:56.036] <TB1> INFO: pixel data incomplete: 0
[12:44:56.036] <TB1> INFO: pixel address: 0
[12:44:56.036] <TB1> INFO: pulse height fill bit: 0
[12:44:56.036] <TB1> INFO: buffer corruption: 0
[12:44:56.661] <TB1> INFO: ######################################################################
[12:44:56.661] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[12:44:56.661] <TB1> INFO: ######################################################################
[12:44:56.907] <TB1> INFO: Expecting 41600 events.
[12:45:00.434] <TB1> INFO: 41600 events read in total (2935ms).
[12:45:00.435] <TB1> INFO: Test took 3772ms.
[12:45:00.894] <TB1> INFO: Expecting 41600 events.
[12:45:04.688] <TB1> INFO: 41600 events read in total (3203ms).
[12:45:04.690] <TB1> INFO: Test took 4052ms.
[12:45:04.979] <TB1> INFO: Expecting 41600 events.
[12:45:08.864] <TB1> INFO: 41600 events read in total (3293ms).
[12:45:08.865] <TB1> INFO: Test took 4151ms.
[12:45:09.161] <TB1> INFO: Expecting 41600 events.
[12:45:13.017] <TB1> INFO: 41600 events read in total (3264ms).
[12:45:13.018] <TB1> INFO: Test took 4126ms.
[12:45:13.310] <TB1> INFO: Expecting 41600 events.
[12:45:16.968] <TB1> INFO: 41600 events read in total (3066ms).
[12:45:16.969] <TB1> INFO: Test took 3924ms.
[12:45:17.360] <TB1> INFO: Expecting 41600 events.
[12:45:21.114] <TB1> INFO: 41600 events read in total (3163ms).
[12:45:21.115] <TB1> INFO: Test took 4119ms.
[12:45:21.418] <TB1> INFO: Expecting 41600 events.
[12:45:25.053] <TB1> INFO: 41600 events read in total (3044ms).
[12:45:25.054] <TB1> INFO: Test took 3914ms.
[12:45:25.450] <TB1> INFO: Expecting 41600 events.
[12:45:29.040] <TB1> INFO: 41600 events read in total (2998ms).
[12:45:29.041] <TB1> INFO: Test took 3960ms.
[12:45:29.438] <TB1> INFO: Expecting 41600 events.
[12:45:33.029] <TB1> INFO: 41600 events read in total (2999ms).
[12:45:33.030] <TB1> INFO: Test took 3964ms.
[12:45:33.319] <TB1> INFO: Expecting 41600 events.
[12:45:36.910] <TB1> INFO: 41600 events read in total (2999ms).
[12:45:36.912] <TB1> INFO: Test took 3858ms.
[12:45:37.208] <TB1> INFO: Expecting 41600 events.
[12:45:40.772] <TB1> INFO: 41600 events read in total (2972ms).
[12:45:40.773] <TB1> INFO: Test took 3830ms.
[12:45:41.062] <TB1> INFO: Expecting 41600 events.
[12:45:44.616] <TB1> INFO: 41600 events read in total (2962ms).
[12:45:44.618] <TB1> INFO: Test took 3821ms.
[12:45:44.937] <TB1> INFO: Expecting 41600 events.
[12:45:48.467] <TB1> INFO: 41600 events read in total (2938ms).
[12:45:48.468] <TB1> INFO: Test took 3823ms.
[12:45:48.757] <TB1> INFO: Expecting 41600 events.
[12:45:52.239] <TB1> INFO: 41600 events read in total (2890ms).
[12:45:52.240] <TB1> INFO: Test took 3747ms.
[12:45:52.529] <TB1> INFO: Expecting 41600 events.
[12:45:56.025] <TB1> INFO: 41600 events read in total (2904ms).
[12:45:56.026] <TB1> INFO: Test took 3761ms.
[12:45:56.315] <TB1> INFO: Expecting 41600 events.
[12:45:59.798] <TB1> INFO: 41600 events read in total (2891ms).
[12:45:59.799] <TB1> INFO: Test took 3749ms.
[12:46:00.110] <TB1> INFO: Expecting 41600 events.
[12:46:03.690] <TB1> INFO: 41600 events read in total (2988ms).
[12:46:03.691] <TB1> INFO: Test took 3868ms.
[12:46:03.980] <TB1> INFO: Expecting 41600 events.
[12:46:07.565] <TB1> INFO: 41600 events read in total (2994ms).
[12:46:07.565] <TB1> INFO: Test took 3850ms.
[12:46:07.854] <TB1> INFO: Expecting 41600 events.
[12:46:11.551] <TB1> INFO: 41600 events read in total (3105ms).
[12:46:11.552] <TB1> INFO: Test took 3963ms.
[12:46:11.841] <TB1> INFO: Expecting 41600 events.
[12:46:15.405] <TB1> INFO: 41600 events read in total (2972ms).
[12:46:15.406] <TB1> INFO: Test took 3830ms.
[12:46:15.809] <TB1> INFO: Expecting 41600 events.
[12:46:19.307] <TB1> INFO: 41600 events read in total (2906ms).
[12:46:19.308] <TB1> INFO: Test took 3871ms.
[12:46:19.640] <TB1> INFO: Expecting 41600 events.
[12:46:23.162] <TB1> INFO: 41600 events read in total (2930ms).
[12:46:23.163] <TB1> INFO: Test took 3830ms.
[12:46:23.455] <TB1> INFO: Expecting 41600 events.
[12:46:27.026] <TB1> INFO: 41600 events read in total (2979ms).
[12:46:27.027] <TB1> INFO: Test took 3837ms.
[12:46:27.316] <TB1> INFO: Expecting 41600 events.
[12:46:30.825] <TB1> INFO: 41600 events read in total (2917ms).
[12:46:30.826] <TB1> INFO: Test took 3775ms.
[12:46:31.115] <TB1> INFO: Expecting 41600 events.
[12:46:34.781] <TB1> INFO: 41600 events read in total (3075ms).
[12:46:34.782] <TB1> INFO: Test took 3932ms.
[12:46:35.071] <TB1> INFO: Expecting 41600 events.
[12:46:38.751] <TB1> INFO: 41600 events read in total (3089ms).
[12:46:38.752] <TB1> INFO: Test took 3946ms.
[12:46:39.053] <TB1> INFO: Expecting 41600 events.
[12:46:42.607] <TB1> INFO: 41600 events read in total (2962ms).
[12:46:42.608] <TB1> INFO: Test took 3832ms.
[12:46:42.898] <TB1> INFO: Expecting 41600 events.
[12:46:46.541] <TB1> INFO: 41600 events read in total (3051ms).
[12:46:46.542] <TB1> INFO: Test took 3909ms.
[12:46:46.831] <TB1> INFO: Expecting 41600 events.
[12:46:50.467] <TB1> INFO: 41600 events read in total (3044ms).
[12:46:50.468] <TB1> INFO: Test took 3902ms.
[12:46:50.759] <TB1> INFO: Expecting 41600 events.
[12:46:54.235] <TB1> INFO: 41600 events read in total (2885ms).
[12:46:54.236] <TB1> INFO: Test took 3742ms.
[12:46:54.526] <TB1> INFO: Expecting 2560 events.
[12:46:55.414] <TB1> INFO: 2560 events read in total (296ms).
[12:46:55.414] <TB1> INFO: Test took 1164ms.
[12:46:55.722] <TB1> INFO: Expecting 2560 events.
[12:46:56.607] <TB1> INFO: 2560 events read in total (294ms).
[12:46:56.607] <TB1> INFO: Test took 1193ms.
[12:46:56.915] <TB1> INFO: Expecting 2560 events.
[12:46:57.801] <TB1> INFO: 2560 events read in total (295ms).
[12:46:57.801] <TB1> INFO: Test took 1193ms.
[12:46:58.109] <TB1> INFO: Expecting 2560 events.
[12:46:58.995] <TB1> INFO: 2560 events read in total (294ms).
[12:46:58.995] <TB1> INFO: Test took 1193ms.
[12:46:59.303] <TB1> INFO: Expecting 2560 events.
[12:47:00.182] <TB1> INFO: 2560 events read in total (287ms).
[12:47:00.182] <TB1> INFO: Test took 1186ms.
[12:47:00.490] <TB1> INFO: Expecting 2560 events.
[12:47:01.370] <TB1> INFO: 2560 events read in total (288ms).
[12:47:01.371] <TB1> INFO: Test took 1189ms.
[12:47:01.679] <TB1> INFO: Expecting 2560 events.
[12:47:02.560] <TB1> INFO: 2560 events read in total (289ms).
[12:47:02.560] <TB1> INFO: Test took 1189ms.
[12:47:02.868] <TB1> INFO: Expecting 2560 events.
[12:47:03.749] <TB1> INFO: 2560 events read in total (289ms).
[12:47:03.749] <TB1> INFO: Test took 1189ms.
[12:47:04.057] <TB1> INFO: Expecting 2560 events.
[12:47:04.939] <TB1> INFO: 2560 events read in total (290ms).
[12:47:04.939] <TB1> INFO: Test took 1189ms.
[12:47:05.247] <TB1> INFO: Expecting 2560 events.
[12:47:06.129] <TB1> INFO: 2560 events read in total (290ms).
[12:47:06.129] <TB1> INFO: Test took 1189ms.
[12:47:06.437] <TB1> INFO: Expecting 2560 events.
[12:47:07.319] <TB1> INFO: 2560 events read in total (290ms).
[12:47:07.319] <TB1> INFO: Test took 1189ms.
[12:47:07.627] <TB1> INFO: Expecting 2560 events.
[12:47:08.508] <TB1> INFO: 2560 events read in total (290ms).
[12:47:08.508] <TB1> INFO: Test took 1188ms.
[12:47:08.816] <TB1> INFO: Expecting 2560 events.
[12:47:09.699] <TB1> INFO: 2560 events read in total (292ms).
[12:47:09.699] <TB1> INFO: Test took 1190ms.
[12:47:10.007] <TB1> INFO: Expecting 2560 events.
[12:47:10.891] <TB1> INFO: 2560 events read in total (292ms).
[12:47:10.892] <TB1> INFO: Test took 1192ms.
[12:47:11.199] <TB1> INFO: Expecting 2560 events.
[12:47:12.087] <TB1> INFO: 2560 events read in total (296ms).
[12:47:12.088] <TB1> INFO: Test took 1195ms.
[12:47:12.395] <TB1> INFO: Expecting 2560 events.
[12:47:13.278] <TB1> INFO: 2560 events read in total (291ms).
[12:47:13.279] <TB1> INFO: Test took 1191ms.
[12:47:13.284] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:47:13.591] <TB1> INFO: Expecting 655360 events.
[12:47:28.075] <TB1> INFO: 655360 events read in total (13893ms).
[12:47:28.088] <TB1> INFO: Expecting 655360 events.
[12:47:42.376] <TB1> INFO: 655360 events read in total (13885ms).
[12:47:42.393] <TB1> INFO: Expecting 655360 events.
[12:47:56.690] <TB1> INFO: 655360 events read in total (13894ms).
[12:47:56.712] <TB1> INFO: Expecting 655360 events.
[12:48:11.193] <TB1> INFO: 655360 events read in total (14078ms).
[12:48:11.226] <TB1> INFO: Expecting 655360 events.
[12:48:25.609] <TB1> INFO: 655360 events read in total (13980ms).
[12:48:25.640] <TB1> INFO: Expecting 655360 events.
[12:48:40.055] <TB1> INFO: 655360 events read in total (14012ms).
[12:48:40.092] <TB1> INFO: Expecting 655360 events.
[12:48:54.411] <TB1> INFO: 655360 events read in total (13916ms).
[12:48:54.460] <TB1> INFO: Expecting 655360 events.
[12:49:08.721] <TB1> INFO: 655360 events read in total (13857ms).
[12:49:08.765] <TB1> INFO: Expecting 655360 events.
[12:49:23.193] <TB1> INFO: 655360 events read in total (14025ms).
[12:49:23.247] <TB1> INFO: Expecting 655360 events.
[12:49:37.566] <TB1> INFO: 655360 events read in total (13916ms).
[12:49:37.619] <TB1> INFO: Expecting 655360 events.
[12:49:51.831] <TB1> INFO: 655360 events read in total (13809ms).
[12:49:51.904] <TB1> INFO: Expecting 655360 events.
[12:50:06.152] <TB1> INFO: 655360 events read in total (13845ms).
[12:50:06.227] <TB1> INFO: Expecting 655360 events.
[12:50:20.632] <TB1> INFO: 655360 events read in total (14002ms).
[12:50:20.716] <TB1> INFO: Expecting 655360 events.
[12:50:35.012] <TB1> INFO: 655360 events read in total (13893ms).
[12:50:35.155] <TB1> INFO: Expecting 655360 events.
[12:50:49.506] <TB1> INFO: 655360 events read in total (13948ms).
[12:50:49.624] <TB1> INFO: Expecting 655360 events.
[12:51:04.130] <TB1> INFO: 655360 events read in total (14103ms).
[12:51:04.296] <TB1> INFO: Test took 231012ms.
[12:51:04.434] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:51:04.684] <TB1> INFO: Expecting 655360 events.
[12:51:19.057] <TB1> INFO: 655360 events read in total (13781ms).
[12:51:19.070] <TB1> INFO: Expecting 655360 events.
[12:51:32.920] <TB1> INFO: 655360 events read in total (13447ms).
[12:51:32.937] <TB1> INFO: Expecting 655360 events.
[12:51:47.238] <TB1> INFO: 655360 events read in total (13898ms).
[12:51:47.264] <TB1> INFO: Expecting 655360 events.
[12:52:01.481] <TB1> INFO: 655360 events read in total (13814ms).
[12:52:01.507] <TB1> INFO: Expecting 655360 events.
[12:52:15.873] <TB1> INFO: 655360 events read in total (13963ms).
[12:52:15.914] <TB1> INFO: Expecting 655360 events.
[12:52:30.133] <TB1> INFO: 655360 events read in total (13816ms).
[12:52:30.168] <TB1> INFO: Expecting 655360 events.
[12:52:44.425] <TB1> INFO: 655360 events read in total (13854ms).
[12:52:44.475] <TB1> INFO: Expecting 655360 events.
[12:52:58.639] <TB1> INFO: 655360 events read in total (13761ms).
[12:52:58.691] <TB1> INFO: Expecting 655360 events.
[12:53:12.934] <TB1> INFO: 655360 events read in total (13840ms).
[12:53:12.998] <TB1> INFO: Expecting 655360 events.
[12:53:27.145] <TB1> INFO: 655360 events read in total (13744ms).
[12:53:27.200] <TB1> INFO: Expecting 655360 events.
[12:53:41.386] <TB1> INFO: 655360 events read in total (13782ms).
[12:53:41.472] <TB1> INFO: Expecting 655360 events.
[12:53:55.360] <TB1> INFO: 655360 events read in total (13484ms).
[12:53:55.427] <TB1> INFO: Expecting 655360 events.
[12:54:09.376] <TB1> INFO: 655360 events read in total (13546ms).
[12:54:09.462] <TB1> INFO: Expecting 655360 events.
[12:54:23.708] <TB1> INFO: 655360 events read in total (13840ms).
[12:54:23.879] <TB1> INFO: Expecting 655360 events.
[12:54:38.149] <TB1> INFO: 655360 events read in total (13867ms).
[12:54:38.277] <TB1> INFO: Expecting 655360 events.
[12:54:52.554] <TB1> INFO: 655360 events read in total (13874ms).
[12:54:52.693] <TB1> INFO: Test took 228259ms.
[12:54:52.890] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:52.897] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:52.903] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:52.909] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:52.915] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:52.922] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:52.928] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:54:52.934] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:54:52.940] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[12:54:52.946] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[12:54:52.953] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[12:54:52.959] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[12:54:52.965] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[12:54:52.972] <TB1> INFO: safety margin for low PH: adding 9, margin is now 29
[12:54:52.978] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:52.985] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:52.991] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:52.997] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:53.004] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:54:53.011] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:54:53.017] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[12:54:53.023] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[12:54:53.030] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[12:54:53.037] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[12:54:53.043] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.051] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:53.060] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:54:53.067] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:54:53.076] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[12:54:53.082] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[12:54:53.088] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.097] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:53.105] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[12:54:53.113] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[12:54:53.121] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.130] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.138] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.146] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[12:54:53.154] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.162] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.170] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.179] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.187] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C0.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C1.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C2.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C3.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C4.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C5.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C6.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C7.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C8.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C9.dat
[12:54:53.225] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C10.dat
[12:54:53.226] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C11.dat
[12:54:53.226] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C12.dat
[12:54:53.226] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C13.dat
[12:54:53.226] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C14.dat
[12:54:53.226] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters35_C15.dat
[12:54:53.480] <TB1> INFO: Expecting 41600 events.
[12:54:56.624] <TB1> INFO: 41600 events read in total (2553ms).
[12:54:56.625] <TB1> INFO: Test took 3397ms.
[12:54:57.076] <TB1> INFO: Expecting 41600 events.
[12:55:00.083] <TB1> INFO: 41600 events read in total (2415ms).
[12:55:00.084] <TB1> INFO: Test took 3247ms.
[12:55:00.533] <TB1> INFO: Expecting 41600 events.
[12:55:03.630] <TB1> INFO: 41600 events read in total (2505ms).
[12:55:03.630] <TB1> INFO: Test took 3335ms.
[12:55:03.847] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:03.936] <TB1> INFO: Expecting 2560 events.
[12:55:04.819] <TB1> INFO: 2560 events read in total (291ms).
[12:55:04.819] <TB1> INFO: Test took 972ms.
[12:55:04.821] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:05.130] <TB1> INFO: Expecting 2560 events.
[12:55:06.014] <TB1> INFO: 2560 events read in total (292ms).
[12:55:06.014] <TB1> INFO: Test took 1193ms.
[12:55:06.017] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:06.328] <TB1> INFO: Expecting 2560 events.
[12:55:07.214] <TB1> INFO: 2560 events read in total (295ms).
[12:55:07.215] <TB1> INFO: Test took 1198ms.
[12:55:07.217] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:07.523] <TB1> INFO: Expecting 2560 events.
[12:55:08.408] <TB1> INFO: 2560 events read in total (294ms).
[12:55:08.409] <TB1> INFO: Test took 1192ms.
[12:55:08.412] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:08.717] <TB1> INFO: Expecting 2560 events.
[12:55:09.600] <TB1> INFO: 2560 events read in total (291ms).
[12:55:09.600] <TB1> INFO: Test took 1188ms.
[12:55:09.603] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:09.909] <TB1> INFO: Expecting 2560 events.
[12:55:10.793] <TB1> INFO: 2560 events read in total (292ms).
[12:55:10.793] <TB1> INFO: Test took 1190ms.
[12:55:10.796] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:11.102] <TB1> INFO: Expecting 2560 events.
[12:55:11.988] <TB1> INFO: 2560 events read in total (294ms).
[12:55:11.988] <TB1> INFO: Test took 1192ms.
[12:55:11.990] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:12.298] <TB1> INFO: Expecting 2560 events.
[12:55:13.189] <TB1> INFO: 2560 events read in total (299ms).
[12:55:13.190] <TB1> INFO: Test took 1200ms.
[12:55:13.191] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:13.498] <TB1> INFO: Expecting 2560 events.
[12:55:14.380] <TB1> INFO: 2560 events read in total (290ms).
[12:55:14.381] <TB1> INFO: Test took 1190ms.
[12:55:14.383] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:14.690] <TB1> INFO: Expecting 2560 events.
[12:55:15.569] <TB1> INFO: 2560 events read in total (288ms).
[12:55:15.569] <TB1> INFO: Test took 1187ms.
[12:55:15.573] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:15.877] <TB1> INFO: Expecting 2560 events.
[12:55:16.759] <TB1> INFO: 2560 events read in total (290ms).
[12:55:16.760] <TB1> INFO: Test took 1187ms.
[12:55:16.762] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:17.068] <TB1> INFO: Expecting 2560 events.
[12:55:17.953] <TB1> INFO: 2560 events read in total (293ms).
[12:55:17.954] <TB1> INFO: Test took 1192ms.
[12:55:17.956] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:18.262] <TB1> INFO: Expecting 2560 events.
[12:55:19.141] <TB1> INFO: 2560 events read in total (288ms).
[12:55:19.141] <TB1> INFO: Test took 1185ms.
[12:55:19.143] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:19.450] <TB1> INFO: Expecting 2560 events.
[12:55:20.330] <TB1> INFO: 2560 events read in total (289ms).
[12:55:20.330] <TB1> INFO: Test took 1187ms.
[12:55:20.332] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:20.638] <TB1> INFO: Expecting 2560 events.
[12:55:21.521] <TB1> INFO: 2560 events read in total (291ms).
[12:55:21.521] <TB1> INFO: Test took 1189ms.
[12:55:21.523] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:21.830] <TB1> INFO: Expecting 2560 events.
[12:55:22.708] <TB1> INFO: 2560 events read in total (287ms).
[12:55:22.708] <TB1> INFO: Test took 1185ms.
[12:55:22.711] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:23.017] <TB1> INFO: Expecting 2560 events.
[12:55:23.898] <TB1> INFO: 2560 events read in total (289ms).
[12:55:23.899] <TB1> INFO: Test took 1189ms.
[12:55:23.901] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:24.207] <TB1> INFO: Expecting 2560 events.
[12:55:25.091] <TB1> INFO: 2560 events read in total (292ms).
[12:55:25.091] <TB1> INFO: Test took 1191ms.
[12:55:25.093] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:25.399] <TB1> INFO: Expecting 2560 events.
[12:55:26.279] <TB1> INFO: 2560 events read in total (288ms).
[12:55:26.279] <TB1> INFO: Test took 1186ms.
[12:55:26.281] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:26.587] <TB1> INFO: Expecting 2560 events.
[12:55:27.467] <TB1> INFO: 2560 events read in total (288ms).
[12:55:27.467] <TB1> INFO: Test took 1186ms.
[12:55:27.470] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:27.776] <TB1> INFO: Expecting 2560 events.
[12:55:28.655] <TB1> INFO: 2560 events read in total (287ms).
[12:55:28.655] <TB1> INFO: Test took 1186ms.
[12:55:28.658] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:28.964] <TB1> INFO: Expecting 2560 events.
[12:55:29.844] <TB1> INFO: 2560 events read in total (289ms).
[12:55:29.844] <TB1> INFO: Test took 1186ms.
[12:55:29.848] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:30.153] <TB1> INFO: Expecting 2560 events.
[12:55:31.032] <TB1> INFO: 2560 events read in total (287ms).
[12:55:31.032] <TB1> INFO: Test took 1185ms.
[12:55:31.035] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:31.341] <TB1> INFO: Expecting 2560 events.
[12:55:32.225] <TB1> INFO: 2560 events read in total (293ms).
[12:55:32.226] <TB1> INFO: Test took 1191ms.
[12:55:32.229] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:32.534] <TB1> INFO: Expecting 2560 events.
[12:55:33.422] <TB1> INFO: 2560 events read in total (296ms).
[12:55:33.422] <TB1> INFO: Test took 1193ms.
[12:55:33.425] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:33.731] <TB1> INFO: Expecting 2560 events.
[12:55:34.618] <TB1> INFO: 2560 events read in total (295ms).
[12:55:34.619] <TB1> INFO: Test took 1194ms.
[12:55:34.621] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:34.927] <TB1> INFO: Expecting 2560 events.
[12:55:35.812] <TB1> INFO: 2560 events read in total (294ms).
[12:55:35.813] <TB1> INFO: Test took 1192ms.
[12:55:35.815] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:36.121] <TB1> INFO: Expecting 2560 events.
[12:55:37.009] <TB1> INFO: 2560 events read in total (296ms).
[12:55:37.009] <TB1> INFO: Test took 1194ms.
[12:55:37.011] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:37.317] <TB1> INFO: Expecting 2560 events.
[12:55:38.200] <TB1> INFO: 2560 events read in total (291ms).
[12:55:38.200] <TB1> INFO: Test took 1189ms.
[12:55:38.203] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:38.509] <TB1> INFO: Expecting 2560 events.
[12:55:39.394] <TB1> INFO: 2560 events read in total (294ms).
[12:55:39.395] <TB1> INFO: Test took 1193ms.
[12:55:39.397] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:39.703] <TB1> INFO: Expecting 2560 events.
[12:55:40.590] <TB1> INFO: 2560 events read in total (295ms).
[12:55:40.590] <TB1> INFO: Test took 1193ms.
[12:55:40.592] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[12:55:40.899] <TB1> INFO: Expecting 2560 events.
[12:55:41.786] <TB1> INFO: 2560 events read in total (295ms).
[12:55:41.786] <TB1> INFO: Test took 1194ms.
[12:55:42.251] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 645 seconds
[12:55:42.251] <TB1> INFO: PH scale (per ROC): 35 48 47 47 46 31 46 48 51 42 50 34 43 54 47 45
[12:55:42.251] <TB1> INFO: PH offset (per ROC): 95 88 109 112 107 100 102 116 114 108 126 91 96 127 102 110
[12:55:42.260] <TB1> INFO: Decoding statistics:
[12:55:42.260] <TB1> INFO: General information:
[12:55:42.260] <TB1> INFO: 16bit words read: 127880
[12:55:42.260] <TB1> INFO: valid events total: 20480
[12:55:42.260] <TB1> INFO: empty events: 17980
[12:55:42.260] <TB1> INFO: valid events with pixels: 2500
[12:55:42.260] <TB1> INFO: valid pixel hits: 2500
[12:55:42.260] <TB1> INFO: Event errors: 0
[12:55:42.260] <TB1> INFO: start marker: 0
[12:55:42.260] <TB1> INFO: stop marker: 0
[12:55:42.260] <TB1> INFO: overflow: 0
[12:55:42.260] <TB1> INFO: invalid 5bit words: 0
[12:55:42.260] <TB1> INFO: invalid XOR eye diagram: 0
[12:55:42.260] <TB1> INFO: frame (failed synchr.): 0
[12:55:42.260] <TB1> INFO: idle data (no TBM trl): 0
[12:55:42.260] <TB1> INFO: no data (only TBM hdr): 0
[12:55:42.260] <TB1> INFO: TBM errors: 0
[12:55:42.260] <TB1> INFO: flawed TBM headers: 0
[12:55:42.260] <TB1> INFO: flawed TBM trailers: 0
[12:55:42.260] <TB1> INFO: event ID mismatches: 0
[12:55:42.260] <TB1> INFO: ROC errors: 0
[12:55:42.260] <TB1> INFO: missing ROC header(s): 0
[12:55:42.260] <TB1> INFO: misplaced readback start: 0
[12:55:42.260] <TB1> INFO: Pixel decoding errors: 0
[12:55:42.260] <TB1> INFO: pixel data incomplete: 0
[12:55:42.260] <TB1> INFO: pixel address: 0
[12:55:42.260] <TB1> INFO: pulse height fill bit: 0
[12:55:42.260] <TB1> INFO: buffer corruption: 0
[12:55:42.602] <TB1> INFO: ######################################################################
[12:55:42.602] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[12:55:42.602] <TB1> INFO: ######################################################################
[12:55:42.619] <TB1> INFO: scanning low vcal = 10
[12:55:42.864] <TB1> INFO: Expecting 41600 events.
[12:55:46.436] <TB1> INFO: 41600 events read in total (2981ms).
[12:55:46.437] <TB1> INFO: Test took 3817ms.
[12:55:46.440] <TB1> INFO: scanning low vcal = 20
[12:55:46.752] <TB1> INFO: Expecting 41600 events.
[12:55:50.324] <TB1> INFO: 41600 events read in total (2981ms).
[12:55:50.324] <TB1> INFO: Test took 3884ms.
[12:55:50.328] <TB1> INFO: scanning low vcal = 30
[12:55:50.621] <TB1> INFO: Expecting 41600 events.
[12:55:54.272] <TB1> INFO: 41600 events read in total (3060ms).
[12:55:54.273] <TB1> INFO: Test took 3945ms.
[12:55:54.276] <TB1> INFO: scanning low vcal = 40
[12:55:54.553] <TB1> INFO: Expecting 41600 events.
[12:55:58.515] <TB1> INFO: 41600 events read in total (3370ms).
[12:55:58.517] <TB1> INFO: Test took 4241ms.
[12:55:58.521] <TB1> INFO: scanning low vcal = 50
[12:55:58.798] <TB1> INFO: Expecting 41600 events.
[12:56:02.726] <TB1> INFO: 41600 events read in total (3337ms).
[12:56:02.727] <TB1> INFO: Test took 4206ms.
[12:56:02.732] <TB1> INFO: scanning low vcal = 60
[12:56:03.007] <TB1> INFO: Expecting 41600 events.
[12:56:07.012] <TB1> INFO: 41600 events read in total (3414ms).
[12:56:07.013] <TB1> INFO: Test took 4281ms.
[12:56:07.017] <TB1> INFO: scanning low vcal = 70
[12:56:07.294] <TB1> INFO: Expecting 41600 events.
[12:56:11.283] <TB1> INFO: 41600 events read in total (3398ms).
[12:56:11.284] <TB1> INFO: Test took 4267ms.
[12:56:11.288] <TB1> INFO: scanning low vcal = 80
[12:56:11.564] <TB1> INFO: Expecting 41600 events.
[12:56:15.528] <TB1> INFO: 41600 events read in total (3372ms).
[12:56:15.529] <TB1> INFO: Test took 4242ms.
[12:56:15.533] <TB1> INFO: scanning low vcal = 90
[12:56:15.820] <TB1> INFO: Expecting 41600 events.
[12:56:19.808] <TB1> INFO: 41600 events read in total (3396ms).
[12:56:19.809] <TB1> INFO: Test took 4274ms.
[12:56:19.812] <TB1> INFO: scanning low vcal = 100
[12:56:20.088] <TB1> INFO: Expecting 41600 events.
[12:56:24.112] <TB1> INFO: 41600 events read in total (3432ms).
[12:56:24.113] <TB1> INFO: Test took 4300ms.
[12:56:24.117] <TB1> INFO: scanning low vcal = 110
[12:56:24.395] <TB1> INFO: Expecting 41600 events.
[12:56:28.520] <TB1> INFO: 41600 events read in total (3533ms).
[12:56:28.522] <TB1> INFO: Test took 4405ms.
[12:56:28.525] <TB1> INFO: scanning low vcal = 120
[12:56:28.819] <TB1> INFO: Expecting 41600 events.
[12:56:32.855] <TB1> INFO: 41600 events read in total (3444ms).
[12:56:32.857] <TB1> INFO: Test took 4332ms.
[12:56:32.860] <TB1> INFO: scanning low vcal = 130
[12:56:33.139] <TB1> INFO: Expecting 41600 events.
[12:56:37.099] <TB1> INFO: 41600 events read in total (3366ms).
[12:56:37.100] <TB1> INFO: Test took 4239ms.
[12:56:37.103] <TB1> INFO: scanning low vcal = 140
[12:56:37.379] <TB1> INFO: Expecting 41600 events.
[12:56:41.342] <TB1> INFO: 41600 events read in total (3371ms).
[12:56:41.343] <TB1> INFO: Test took 4240ms.
[12:56:41.346] <TB1> INFO: scanning low vcal = 150
[12:56:41.704] <TB1> INFO: Expecting 41600 events.
[12:56:45.643] <TB1> INFO: 41600 events read in total (3347ms).
[12:56:45.645] <TB1> INFO: Test took 4299ms.
[12:56:45.648] <TB1> INFO: scanning low vcal = 160
[12:56:45.924] <TB1> INFO: Expecting 41600 events.
[12:56:49.862] <TB1> INFO: 41600 events read in total (3345ms).
[12:56:49.862] <TB1> INFO: Test took 4214ms.
[12:56:49.866] <TB1> INFO: scanning low vcal = 170
[12:56:50.142] <TB1> INFO: Expecting 41600 events.
[12:56:54.104] <TB1> INFO: 41600 events read in total (3370ms).
[12:56:54.105] <TB1> INFO: Test took 4239ms.
[12:56:54.110] <TB1> INFO: scanning low vcal = 180
[12:56:54.384] <TB1> INFO: Expecting 41600 events.
[12:56:58.353] <TB1> INFO: 41600 events read in total (3377ms).
[12:56:58.354] <TB1> INFO: Test took 4244ms.
[12:56:58.358] <TB1> INFO: scanning low vcal = 190
[12:56:58.634] <TB1> INFO: Expecting 41600 events.
[12:57:02.584] <TB1> INFO: 41600 events read in total (3358ms).
[12:57:02.585] <TB1> INFO: Test took 4227ms.
[12:57:02.588] <TB1> INFO: scanning low vcal = 200
[12:57:02.865] <TB1> INFO: Expecting 41600 events.
[12:57:06.849] <TB1> INFO: 41600 events read in total (3392ms).
[12:57:06.851] <TB1> INFO: Test took 4263ms.
[12:57:06.854] <TB1> INFO: scanning low vcal = 210
[12:57:07.130] <TB1> INFO: Expecting 41600 events.
[12:57:11.145] <TB1> INFO: 41600 events read in total (3423ms).
[12:57:11.146] <TB1> INFO: Test took 4292ms.
[12:57:11.149] <TB1> INFO: scanning low vcal = 220
[12:57:11.426] <TB1> INFO: Expecting 41600 events.
[12:57:15.369] <TB1> INFO: 41600 events read in total (3351ms).
[12:57:15.370] <TB1> INFO: Test took 4220ms.
[12:57:15.374] <TB1> INFO: scanning low vcal = 230
[12:57:15.651] <TB1> INFO: Expecting 41600 events.
[12:57:19.588] <TB1> INFO: 41600 events read in total (3346ms).
[12:57:19.589] <TB1> INFO: Test took 4215ms.
[12:57:19.593] <TB1> INFO: scanning low vcal = 240
[12:57:19.869] <TB1> INFO: Expecting 41600 events.
[12:57:23.806] <TB1> INFO: 41600 events read in total (3345ms).
[12:57:23.807] <TB1> INFO: Test took 4214ms.
[12:57:23.810] <TB1> INFO: scanning low vcal = 250
[12:57:24.087] <TB1> INFO: Expecting 41600 events.
[12:57:28.031] <TB1> INFO: 41600 events read in total (3352ms).
[12:57:28.032] <TB1> INFO: Test took 4221ms.
[12:57:28.036] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[12:57:28.312] <TB1> INFO: Expecting 41600 events.
[12:57:32.267] <TB1> INFO: 41600 events read in total (3364ms).
[12:57:32.268] <TB1> INFO: Test took 4232ms.
[12:57:32.271] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[12:57:32.550] <TB1> INFO: Expecting 41600 events.
[12:57:36.499] <TB1> INFO: 41600 events read in total (3358ms).
[12:57:36.500] <TB1> INFO: Test took 4228ms.
[12:57:36.503] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[12:57:36.780] <TB1> INFO: Expecting 41600 events.
[12:57:40.719] <TB1> INFO: 41600 events read in total (3348ms).
[12:57:40.719] <TB1> INFO: Test took 4215ms.
[12:57:40.723] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[12:57:40.000] <TB1> INFO: Expecting 41600 events.
[12:57:44.974] <TB1> INFO: 41600 events read in total (3383ms).
[12:57:44.975] <TB1> INFO: Test took 4252ms.
[12:57:44.981] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[12:57:45.255] <TB1> INFO: Expecting 41600 events.
[12:57:49.239] <TB1> INFO: 41600 events read in total (3392ms).
[12:57:49.240] <TB1> INFO: Test took 4258ms.
[12:57:49.836] <TB1> INFO: PixTestGainPedestal::measure() done
[12:58:39.566] <TB1> INFO: PixTestGainPedestal::fit() done
[12:58:39.566] <TB1> INFO: non-linearity mean: 0.933 0.940 0.953 0.944 0.922 0.936 0.970 0.930 0.980 0.945 0.981 0.919 0.925 0.981 0.960 0.969
[12:58:39.566] <TB1> INFO: non-linearity RMS: 0.069 0.075 0.044 0.055 0.073 0.147 0.011 0.065 0.005 0.068 0.004 0.212 0.110 0.004 0.056 0.017
[12:58:39.566] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C0.dat
[12:58:39.579] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C1.dat
[12:58:39.593] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C2.dat
[12:58:39.607] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C3.dat
[12:58:39.620] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C4.dat
[12:58:39.634] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C5.dat
[12:58:39.647] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C6.dat
[12:58:39.660] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C7.dat
[12:58:39.673] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C8.dat
[12:58:39.686] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C9.dat
[12:58:39.699] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C10.dat
[12:58:39.712] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C11.dat
[12:58:39.725] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C12.dat
[12:58:39.738] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C13.dat
[12:58:39.752] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C14.dat
[12:58:39.765] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//phCalibrationFitErr35_C15.dat
[12:58:39.779] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 177 seconds
[12:58:39.779] <TB1> INFO: Decoding statistics:
[12:58:39.779] <TB1> INFO: General information:
[12:58:39.779] <TB1> INFO: 16bit words read: 3230274
[12:58:39.779] <TB1> INFO: valid events total: 332800
[12:58:39.779] <TB1> INFO: empty events: 3970
[12:58:39.779] <TB1> INFO: valid events with pixels: 328830
[12:58:39.779] <TB1> INFO: valid pixel hits: 616737
[12:58:39.779] <TB1> INFO: Event errors: 0
[12:58:39.779] <TB1> INFO: start marker: 0
[12:58:39.779] <TB1> INFO: stop marker: 0
[12:58:39.779] <TB1> INFO: overflow: 0
[12:58:39.779] <TB1> INFO: invalid 5bit words: 0
[12:58:39.779] <TB1> INFO: invalid XOR eye diagram: 0
[12:58:39.779] <TB1> INFO: frame (failed synchr.): 0
[12:58:39.779] <TB1> INFO: idle data (no TBM trl): 0
[12:58:39.779] <TB1> INFO: no data (only TBM hdr): 0
[12:58:39.779] <TB1> INFO: TBM errors: 0
[12:58:39.779] <TB1> INFO: flawed TBM headers: 0
[12:58:39.779] <TB1> INFO: flawed TBM trailers: 0
[12:58:39.779] <TB1> INFO: event ID mismatches: 0
[12:58:39.779] <TB1> INFO: ROC errors: 0
[12:58:39.779] <TB1> INFO: missing ROC header(s): 0
[12:58:39.779] <TB1> INFO: misplaced readback start: 0
[12:58:39.779] <TB1> INFO: Pixel decoding errors: 0
[12:58:39.779] <TB1> INFO: pixel data incomplete: 0
[12:58:39.779] <TB1> INFO: pixel address: 0
[12:58:39.779] <TB1> INFO: pulse height fill bit: 0
[12:58:39.779] <TB1> INFO: buffer corruption: 0
[12:58:39.798] <TB1> INFO: Decoding statistics:
[12:58:39.798] <TB1> INFO: General information:
[12:58:39.798] <TB1> INFO: 16bit words read: 3359690
[12:58:39.798] <TB1> INFO: valid events total: 353536
[12:58:39.798] <TB1> INFO: empty events: 22206
[12:58:39.798] <TB1> INFO: valid events with pixels: 331330
[12:58:39.798] <TB1> INFO: valid pixel hits: 619237
[12:58:39.798] <TB1> INFO: Event errors: 0
[12:58:39.798] <TB1> INFO: start marker: 0
[12:58:39.798] <TB1> INFO: stop marker: 0
[12:58:39.798] <TB1> INFO: overflow: 0
[12:58:39.798] <TB1> INFO: invalid 5bit words: 0
[12:58:39.798] <TB1> INFO: invalid XOR eye diagram: 0
[12:58:39.798] <TB1> INFO: frame (failed synchr.): 0
[12:58:39.798] <TB1> INFO: idle data (no TBM trl): 0
[12:58:39.798] <TB1> INFO: no data (only TBM hdr): 0
[12:58:39.798] <TB1> INFO: TBM errors: 0
[12:58:39.798] <TB1> INFO: flawed TBM headers: 0
[12:58:39.798] <TB1> INFO: flawed TBM trailers: 0
[12:58:39.798] <TB1> INFO: event ID mismatches: 0
[12:58:39.798] <TB1> INFO: ROC errors: 0
[12:58:39.798] <TB1> INFO: missing ROC header(s): 0
[12:58:39.798] <TB1> INFO: misplaced readback start: 0
[12:58:39.798] <TB1> INFO: Pixel decoding errors: 0
[12:58:39.798] <TB1> INFO: pixel data incomplete: 0
[12:58:39.798] <TB1> INFO: pixel address: 0
[12:58:39.798] <TB1> INFO: pulse height fill bit: 0
[12:58:39.798] <TB1> INFO: buffer corruption: 0
[12:58:39.798] <TB1> INFO: enter test to run
[12:58:39.798] <TB1> INFO: test: trim80 no parameter change
[12:58:39.798] <TB1> INFO: running: trim80
[12:58:39.799] <TB1> INFO: ######################################################################
[12:58:39.799] <TB1> INFO: PixTestTrim80::doTest()
[12:58:39.799] <TB1> INFO: ######################################################################
[12:58:39.801] <TB1> INFO: ----------------------------------------------------------------------
[12:58:39.801] <TB1> INFO: PixTestTrim80::trimTest() ntrig = 8, vcal = 80
[12:58:39.801] <TB1> INFO: ----------------------------------------------------------------------
[12:58:39.841] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[12:58:39.841] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[12:58:39.855] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[12:58:39.855] <TB1> INFO: run 1 of 1
[12:58:40.092] <TB1> INFO: Expecting 5025280 events.
[12:59:08.168] <TB1> INFO: 680872 events read in total (27485ms).
[12:59:35.863] <TB1> INFO: 1358760 events read in total (55180ms).
[13:00:03.827] <TB1> INFO: 2034912 events read in total (83145ms).
[13:00:31.984] <TB1> INFO: 2710608 events read in total (111301ms).
[13:00:59.881] <TB1> INFO: 3386104 events read in total (139198ms).
[13:01:27.569] <TB1> INFO: 4060928 events read in total (166886ms).
[13:01:55.998] <TB1> INFO: 4734432 events read in total (195315ms).
[13:02:08.204] <TB1> INFO: 5025280 events read in total (207521ms).
[13:02:08.338] <TB1> INFO: Test took 208483ms.
[13:02:37.170] <TB1> INFO: ROC 0 VthrComp = 94
[13:02:37.170] <TB1> INFO: ROC 1 VthrComp = 88
[13:02:37.170] <TB1> INFO: ROC 2 VthrComp = 71
[13:02:37.171] <TB1> INFO: ROC 3 VthrComp = 85
[13:02:37.171] <TB1> INFO: ROC 4 VthrComp = 74
[13:02:37.172] <TB1> INFO: ROC 5 VthrComp = 73
[13:02:37.173] <TB1> INFO: ROC 6 VthrComp = 83
[13:02:37.173] <TB1> INFO: ROC 7 VthrComp = 88
[13:02:37.173] <TB1> INFO: ROC 8 VthrComp = 80
[13:02:37.173] <TB1> INFO: ROC 9 VthrComp = 77
[13:02:37.173] <TB1> INFO: ROC 10 VthrComp = 72
[13:02:37.174] <TB1> INFO: ROC 11 VthrComp = 85
[13:02:37.174] <TB1> INFO: ROC 12 VthrComp = 74
[13:02:37.174] <TB1> INFO: ROC 13 VthrComp = 70
[13:02:37.175] <TB1> INFO: ROC 14 VthrComp = 77
[13:02:37.175] <TB1> INFO: ROC 15 VthrComp = 83
[13:02:37.413] <TB1> INFO: Expecting 41600 events.
[13:02:41.037] <TB1> INFO: 41600 events read in total (3032ms).
[13:02:41.038] <TB1> INFO: Test took 3861ms.
[13:02:41.050] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[13:02:41.050] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[13:02:41.062] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:02:41.062] <TB1> INFO: run 1 of 1
[13:02:41.340] <TB1> INFO: Expecting 5025280 events.
[13:03:09.658] <TB1> INFO: 685032 events read in total (27726ms).
[13:03:37.680] <TB1> INFO: 1366424 events read in total (55748ms).
[13:04:06.202] <TB1> INFO: 2045632 events read in total (84270ms).
[13:04:34.593] <TB1> INFO: 2721640 events read in total (112661ms).
[13:05:02.996] <TB1> INFO: 3393488 events read in total (141064ms).
[13:05:31.618] <TB1> INFO: 4065240 events read in total (169686ms).
[13:05:59.859] <TB1> INFO: 4736296 events read in total (197927ms).
[13:06:12.407] <TB1> INFO: 5025280 events read in total (210475ms).
[13:06:12.520] <TB1> INFO: Test took 211458ms.
[13:06:44.261] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 109.093 for pixel 0/76 mean/min/max = 92.1958/75.1746/109.217
[13:06:44.261] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 110.944 for pixel 1/76 mean/min/max = 94.0195/76.4994/111.54
[13:06:44.262] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 107.408 for pixel 10/70 mean/min/max = 90.1109/72.8131/107.409
[13:06:44.262] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 105.647 for pixel 34/79 mean/min/max = 90.0149/74.232/105.798
[13:06:44.262] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 107.138 for pixel 0/1 mean/min/max = 91.67/76.1624/107.178
[13:06:44.263] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 109.264 for pixel 0/42 mean/min/max = 93.0705/76.8465/109.295
[13:06:44.263] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 107.935 for pixel 51/77 mean/min/max = 91.2533/74.4388/108.068
[13:06:44.264] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 109.146 for pixel 14/79 mean/min/max = 92.7351/76.1115/109.359
[13:06:44.264] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 108.712 for pixel 51/74 mean/min/max = 91.711/74.6093/108.813
[13:06:44.265] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 108.438 for pixel 0/34 mean/min/max = 93.0886/77.7272/108.45
[13:06:44.265] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 109.704 for pixel 0/72 mean/min/max = 92.9608/76.1763/109.745
[13:06:44.266] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 107.065 for pixel 45/79 mean/min/max = 90.6386/74.1525/107.125
[13:06:44.266] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 110.609 for pixel 14/69 mean/min/max = 94.3482/78.0365/110.66
[13:06:44.266] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 105.988 for pixel 0/52 mean/min/max = 89.8429/73.6914/105.994
[13:06:44.267] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 112.721 for pixel 0/58 mean/min/max = 94.7423/76.739/112.746
[13:06:44.267] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 108.07 for pixel 0/45 mean/min/max = 91.5491/74.774/108.324
[13:06:44.268] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:06:44.356] <TB1> INFO: Expecting 411648 events.
[13:06:53.878] <TB1> INFO: 411648 events read in total (8930ms).
[13:06:53.890] <TB1> INFO: Expecting 411648 events.
[13:07:03.067] <TB1> INFO: 411648 events read in total (8774ms).
[13:07:03.078] <TB1> INFO: Expecting 411648 events.
[13:07:12.356] <TB1> INFO: 411648 events read in total (8875ms).
[13:07:12.370] <TB1> INFO: Expecting 411648 events.
[13:07:21.689] <TB1> INFO: 411648 events read in total (8916ms).
[13:07:21.707] <TB1> INFO: Expecting 411648 events.
[13:07:30.922] <TB1> INFO: 411648 events read in total (8813ms).
[13:07:30.946] <TB1> INFO: Expecting 411648 events.
[13:07:40.281] <TB1> INFO: 411648 events read in total (8932ms).
[13:07:40.304] <TB1> INFO: Expecting 411648 events.
[13:07:49.631] <TB1> INFO: 411648 events read in total (8924ms).
[13:07:49.657] <TB1> INFO: Expecting 411648 events.
[13:07:59.008] <TB1> INFO: 411648 events read in total (8948ms).
[13:07:59.037] <TB1> INFO: Expecting 411648 events.
[13:08:08.203] <TB1> INFO: 411648 events read in total (8763ms).
[13:08:08.260] <TB1> INFO: Expecting 411648 events.
[13:08:17.501] <TB1> INFO: 411648 events read in total (8838ms).
[13:08:17.544] <TB1> INFO: Expecting 411648 events.
[13:08:26.744] <TB1> INFO: 411648 events read in total (8797ms).
[13:08:26.805] <TB1> INFO: Expecting 411648 events.
[13:08:36.012] <TB1> INFO: 411648 events read in total (8804ms).
[13:08:36.063] <TB1> INFO: Expecting 411648 events.
[13:08:45.260] <TB1> INFO: 411648 events read in total (8794ms).
[13:08:45.315] <TB1> INFO: Expecting 411648 events.
[13:08:54.646] <TB1> INFO: 411648 events read in total (8928ms).
[13:08:54.704] <TB1> INFO: Expecting 411648 events.
[13:09:03.930] <TB1> INFO: 411648 events read in total (8812ms).
[13:09:03.997] <TB1> INFO: Expecting 411648 events.
[13:09:13.275] <TB1> INFO: 411648 events read in total (8875ms).
[13:09:13.397] <TB1> INFO: Test took 149129ms.
[13:09:14.989] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[13:09:15.003] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:09:15.003] <TB1> INFO: run 1 of 1
[13:09:15.242] <TB1> INFO: Expecting 5025280 events.
[13:09:43.716] <TB1> INFO: 669320 events read in total (27882ms).
[13:10:11.072] <TB1> INFO: 1336344 events read in total (55238ms).
[13:10:38.572] <TB1> INFO: 2001720 events read in total (82738ms).
[13:11:06.610] <TB1> INFO: 2664928 events read in total (110776ms).
[13:11:34.201] <TB1> INFO: 3324040 events read in total (138367ms).
[13:12:01.720] <TB1> INFO: 3983128 events read in total (165886ms).
[13:12:29.738] <TB1> INFO: 4640720 events read in total (193904ms).
[13:12:45.991] <TB1> INFO: 5025280 events read in total (210157ms).
[13:12:46.126] <TB1> INFO: Test took 211123ms.
[13:13:16.457] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 52.599023 .. 101.455429
[13:13:16.695] <TB1> INFO: Expecting 208000 events.
[13:13:26.975] <TB1> INFO: 208000 events read in total (9688ms).
[13:13:26.976] <TB1> INFO: Test took 10518ms.
[13:13:27.032] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 42 .. 111 (-1/-1) hits flags = 528 (plus default)
[13:13:27.046] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:13:27.046] <TB1> INFO: run 1 of 1
[13:13:27.325] <TB1> INFO: Expecting 2329600 events.
[13:13:56.142] <TB1> INFO: 688936 events read in total (28226ms).
[13:14:24.666] <TB1> INFO: 1373392 events read in total (56750ms).
[13:14:53.326] <TB1> INFO: 2051592 events read in total (85410ms).
[13:15:06.033] <TB1> INFO: 2329600 events read in total (98117ms).
[13:15:06.093] <TB1> INFO: Test took 99046ms.
[13:15:29.217] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 60.443568 .. 93.604391
[13:15:29.493] <TB1> INFO: Expecting 208000 events.
[13:15:39.691] <TB1> INFO: 208000 events read in total (9607ms).
[13:15:39.693] <TB1> INFO: Test took 10475ms.
[13:15:39.740] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 50 .. 103 (-1/-1) hits flags = 528 (plus default)
[13:15:39.754] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:15:39.754] <TB1> INFO: run 1 of 1
[13:15:40.032] <TB1> INFO: Expecting 1797120 events.
[13:16:10.127] <TB1> INFO: 691016 events read in total (29503ms).
[13:16:40.034] <TB1> INFO: 1381072 events read in total (59411ms).
[13:16:58.225] <TB1> INFO: 1797120 events read in total (77601ms).
[13:16:58.265] <TB1> INFO: Test took 78511ms.
[13:17:19.030] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 65.980228 .. 89.358218
[13:17:19.275] <TB1> INFO: Expecting 208000 events.
[13:17:29.457] <TB1> INFO: 208000 events read in total (9590ms).
[13:17:29.459] <TB1> INFO: Test took 10427ms.
[13:17:29.543] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 55 .. 99 (-1/-1) hits flags = 528 (plus default)
[13:17:29.557] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:17:29.557] <TB1> INFO: run 1 of 1
[13:17:29.846] <TB1> INFO: Expecting 1497600 events.
[13:17:59.696] <TB1> INFO: 691776 events read in total (29258ms).
[13:18:30.683] <TB1> INFO: 1382544 events read in total (60245ms).
[13:18:36.090] <TB1> INFO: 1497600 events read in total (65652ms).
[13:18:36.119] <TB1> INFO: Test took 66562ms.
[13:18:54.534] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 69.373837 .. 88.545102
[13:18:54.772] <TB1> INFO: Expecting 208000 events.
[13:19:04.771] <TB1> INFO: 208000 events read in total (9407ms).
[13:19:04.772] <TB1> INFO: Test took 10236ms.
[13:19:04.821] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 59 .. 98 (-1/-1) hits flags = 528 (plus default)
[13:19:04.834] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:19:04.834] <TB1> INFO: run 1 of 1
[13:19:05.113] <TB1> INFO: Expecting 1331200 events.
[13:19:34.386] <TB1> INFO: 683320 events read in total (28682ms).
[13:20:04.100] <TB1> INFO: 1331200 events read in total (58396ms).
[13:20:04.140] <TB1> INFO: Test took 59306ms.
[13:20:22.906] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 60 .. 100
[13:20:22.907] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 60 .. 100 (-1/-1) hits flags = 528 (plus default)
[13:20:22.921] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:20:22.921] <TB1> INFO: run 1 of 1
[13:20:23.161] <TB1> INFO: Expecting 1364480 events.
[13:20:52.399] <TB1> INFO: 668288 events read in total (28646ms).
[13:21:22.067] <TB1> INFO: 1335824 events read in total (58314ms).
[13:21:23.934] <TB1> INFO: 1364480 events read in total (60181ms).
[13:21:23.974] <TB1> INFO: Test took 61054ms.
[13:21:44.299] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C0.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C1.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C2.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C3.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C4.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C5.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C6.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C7.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C8.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C9.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C10.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C11.dat
[13:21:44.300] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C12.dat
[13:21:44.301] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C13.dat
[13:21:44.301] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C14.dat
[13:21:44.301] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//dacParameters80_C15.dat
[13:21:44.301] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C0.dat
[13:21:44.309] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C1.dat
[13:21:44.318] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C2.dat
[13:21:44.326] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C3.dat
[13:21:44.334] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C4.dat
[13:21:44.343] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C5.dat
[13:21:44.351] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C6.dat
[13:21:44.359] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C7.dat
[13:21:44.367] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C8.dat
[13:21:44.375] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C9.dat
[13:21:44.380] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C10.dat
[13:21:44.386] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C11.dat
[13:21:44.391] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C12.dat
[13:21:44.396] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C13.dat
[13:21:44.401] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C14.dat
[13:21:44.405] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1118_FullQualification_2016-11-03_09h01m_1478160071//003_FulltestTrim80_p17//trimParameters80_C15.dat
[13:21:44.410] <TB1> INFO: PixTestTrim80::trimTest() done
[13:21:44.410] <TB1> INFO: vtrim: 112 116 99 105 88 94 93 109 109 104 90 102 109 92 107 95
[13:21:44.410] <TB1> INFO: vthrcomp: 94 88 71 85 74 73 83 88 80 77 72 85 74 70 77 83
[13:21:44.410] <TB1> INFO: vcal mean: 79.92 79.96 79.92 79.92 79.90 79.97 79.93 79.96 79.89 79.95 79.93 79.97 79.95 79.91 79.93 79.98
[13:21:44.410] <TB1> INFO: vcal RMS: 0.75 0.75 0.74 0.70 1.42 0.74 0.79 0.76 0.74 0.73 0.72 0.77 0.75 0.72 0.79 0.75
[13:21:44.410] <TB1> INFO: bits mean: 9.48 9.55 10.59 10.31 9.26 9.17 9.86 9.79 9.95 9.34 8.99 10.38 9.71 9.99 9.60 9.68
[13:21:44.410] <TB1> INFO: bits RMS: 2.59 2.39 2.46 2.46 2.56 2.51 2.54 2.34 2.49 2.32 2.63 2.42 2.11 2.71 2.25 2.65
[13:21:44.417] <TB1> INFO: ----------------------------------------------------------------------
[13:21:44.417] <TB1> INFO: PixTestTrim80::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[13:21:44.417] <TB1> INFO: ----------------------------------------------------------------------
[13:21:44.430] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[13:21:44.444] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:21:44.444] <TB1> INFO: run 1 of 1
[13:21:44.682] <TB1> INFO: Expecting 4160000 events.
[13:22:17.860] <TB1> INFO: 773395 events read in total (32586ms).
[13:22:50.999] <TB1> INFO: 1541810 events read in total (65725ms).
[13:23:23.317] <TB1> INFO: 2303235 events read in total (98043ms).
[13:23:55.710] <TB1> INFO: 3060025 events read in total (130436ms).
[13:24:28.383] <TB1> INFO: 3814695 events read in total (163109ms).
[13:24:43.467] <TB1> INFO: 4160000 events read in total (178193ms).
[13:24:43.558] <TB1> INFO: Test took 179115ms.
[13:25:12.727] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 224 (-1/-1) hits flags = 528 (plus default)
[13:25:12.740] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:25:12.740] <TB1> INFO: run 1 of 1
[13:25:12.977] <TB1> INFO: Expecting 4680000 events.
[13:25:44.738] <TB1> INFO: 715455 events read in total (31169ms).
[13:26:16.467] <TB1> INFO: 1427600 events read in total (62898ms).
[13:26:47.913] <TB1> INFO: 2137050 events read in total (94344ms).
[13:27:18.916] <TB1> INFO: 2842035 events read in total (125347ms).
[13:27:50.271] <TB1> INFO: 3545170 events read in total (156702ms).
[13:28:23.233] <TB1> INFO: 4246755 events read in total (189664ms).
[13:28:43.057] <TB1> INFO: 4680000 events read in total (209488ms).
[13:28:43.200] <TB1> INFO: Test took 210459ms.
[13:29:15.982] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 208 (-1/-1) hits flags = 528 (plus default)
[13:29:15.997] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:29:15.997] <TB1> INFO: run 1 of 1
[13:29:16.234] <TB1> INFO: Expecting 4347200 events.
[13:29:49.200] <TB1> INFO: 734780 events read in total (32374ms).
[13:30:20.785] <TB1> INFO: 1465895 events read in total (63959ms).
[13:30:52.184] <TB1> INFO: 2192850 events read in total (95358ms).
[13:31:23.916] <TB1> INFO: 2914920 events read in total (127090ms).
[13:31:56.939] <TB1> INFO: 3635480 events read in total (160113ms).
[13:32:27.865] <TB1> INFO: 4347200 events read in total (191039ms).
[13:32:27.953] <TB1> INFO: Test took 191956ms.
[13:32:58.630] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 208 (-1/-1) hits flags = 528 (plus default)
[13:32:58.645] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:32:58.645] <TB1> INFO: run 1 of 1
[13:32:58.921] <TB1> INFO: Expecting 4347200 events.
[13:33:31.906] <TB1> INFO: 735370 events read in total (32393ms).
[13:34:03.778] <TB1> INFO: 1466650 events read in total (64265ms).
[13:34:35.015] <TB1> INFO: 2193820 events read in total (95502ms).
[13:35:06.260] <TB1> INFO: 2916125 events read in total (126747ms).
[13:35:39.585] <TB1> INFO: 3636690 events read in total (160072ms).
[13:36:10.546] <TB1> INFO: 4347200 events read in total (191033ms).
[13:36:10.672] <TB1> INFO: Test took 192027ms.
[13:36:42.552] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 206 (-1/-1) hits flags = 528 (plus default)
[13:36:42.566] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:36:42.566] <TB1> INFO: run 1 of 1
[13:36:42.854] <TB1> INFO: Expecting 4305600 events.
[13:37:15.727] <TB1> INFO: 738085 events read in total (32281ms).
[13:37:47.727] <TB1> INFO: 1471910 events read in total (64281ms).
[13:38:19.951] <TB1> INFO: 2201440 events read in total (96505ms).
[13:38:51.733] <TB1> INFO: 2926415 events read in total (128287ms).
[13:39:24.236] <TB1> INFO: 3649555 events read in total (160790ms).
[13:39:54.514] <TB1> INFO: 4305600 events read in total (191068ms).
[13:39:54.675] <TB1> INFO: Test took 192109ms.
[13:40:18.426] <TB1> INFO: PixTestTrim80::trimBitTest() done
[13:40:18.427] <TB1> INFO: PixTestTrim80::doTest() done, duration: 2498 seconds
[13:40:19.565] <TB1> INFO: enter test to run
[13:40:19.565] <TB1> INFO: test: exit no parameter change
[13:40:19.966] <TB1> QUIET: Connection to board 154 closed.
[13:40:19.967] <TB1> INFO: pXar: this is the end, my friend