Test Date: 2016-11-04 10:05
Analysis date: 2016-11-07 10:51
Logfile
LogfileView
[18:30:16.827] <TB3> INFO: *** Welcome to pxar ***
[18:30:16.827] <TB3> INFO: *** Today: 2016/11/04
[18:30:16.835] <TB3> INFO: *** Version: c8ba-dirty
[18:30:16.835] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C15.dat
[18:30:16.836] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[18:30:16.836] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//defaultMaskFile.dat
[18:30:16.836] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters_C15.dat
[18:30:16.890] <TB3> INFO: clk: 4
[18:30:16.890] <TB3> INFO: ctr: 4
[18:30:16.890] <TB3> INFO: sda: 19
[18:30:16.890] <TB3> INFO: tin: 9
[18:30:16.890] <TB3> INFO: level: 15
[18:30:16.890] <TB3> INFO: triggerdelay: 0
[18:30:16.890] <TB3> QUIET: Instanciating API for pxar v2.1.0+867~g2c7f7f2
[18:30:16.890] <TB3> INFO: Log level: INFO
[18:30:16.899] <TB3> INFO: Found DTB DTB_WZ4I6J
[18:30:16.907] <TB3> QUIET: Connection to board DTB_WZ4I6J opened.
[18:30:16.909] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 170
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WZ4I6J
MAC address: 40D8551180AA
Hostname: pixelDTB170
Comment:
------------------------------------------------------
[18:30:16.911] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[18:30:18.433] <TB3> INFO: DUT info:
[18:30:18.433] <TB3> INFO: The DUT currently contains the following objects:
[18:30:18.433] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[18:30:18.433] <TB3> INFO: TBM Core alpha (0): 7 registers set
[18:30:18.433] <TB3> INFO: TBM Core beta (1): 7 registers set
[18:30:18.433] <TB3> INFO: TBM Core alpha (2): 7 registers set
[18:30:18.433] <TB3> INFO: TBM Core beta (3): 7 registers set
[18:30:18.433] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[18:30:18.433] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.434] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:30:18.834] <TB3> INFO: enter 'restricted' command line mode
[18:30:18.834] <TB3> INFO: enter test to run
[18:30:18.835] <TB3> INFO: test: pretest no parameter change
[18:30:18.835] <TB3> INFO: running: pretest
[18:30:19.366] <TB3> INFO: ######################################################################
[18:30:19.366] <TB3> INFO: PixTestPretest::doTest()
[18:30:19.366] <TB3> INFO: ######################################################################
[18:30:19.368] <TB3> INFO: ----------------------------------------------------------------------
[18:30:19.368] <TB3> INFO: PixTestPretest::programROC()
[18:30:19.368] <TB3> INFO: ----------------------------------------------------------------------
[18:30:37.381] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[18:30:37.381] <TB3> INFO: IA differences per ROC: 17.7 17.7 18.5 18.5 19.3 17.7 19.3 15.3 20.1 20.1 19.3 19.3 20.1 17.7 18.5 17.7
[18:30:37.418] <TB3> INFO: ----------------------------------------------------------------------
[18:30:37.418] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[18:30:37.418] <TB3> INFO: ----------------------------------------------------------------------
[18:30:58.662] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 386.7 mA = 24.1687 mA/ROC
[18:30:58.662] <TB3> INFO: i(loss) [mA/ROC]: 19.3 19.3 20.1 20.1 20.1 20.9 19.3 19.3 19.3 20.1 19.3 20.1 18.5 20.1 19.3 20.1
[18:30:58.691] <TB3> INFO: ----------------------------------------------------------------------
[18:30:58.691] <TB3> INFO: PixTestPretest::findTiming()
[18:30:58.691] <TB3> INFO: ----------------------------------------------------------------------
[18:30:58.691] <TB3> INFO: PixTestCmd::init()
[18:30:59.251] <TB3> WARNING: Not unmasking DUT, not setting Calibrate bits!

[18:31:29.964] <TB3> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[18:31:29.964] <TB3> INFO: (success/tries = 100/100), width = 4
[18:31:31.471] <TB3> INFO: ----------------------------------------------------------------------
[18:31:31.471] <TB3> INFO: PixTestPretest::findWorkingPixel()
[18:31:31.471] <TB3> INFO: ----------------------------------------------------------------------
[18:31:31.562] <TB3> INFO: Expecting 231680 events.
[18:31:41.219] <TB3> INFO: 231680 events read in total (9065ms).
[18:31:41.226] <TB3> INFO: Test took 9753ms.
[18:31:41.471] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[18:31:41.500] <TB3> INFO: ----------------------------------------------------------------------
[18:31:41.500] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[18:31:41.500] <TB3> INFO: ----------------------------------------------------------------------
[18:31:41.592] <TB3> INFO: Expecting 231680 events.
[18:31:51.299] <TB3> INFO: 231680 events read in total (9116ms).
[18:31:51.307] <TB3> INFO: Test took 9804ms.
[18:31:51.567] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[18:31:51.567] <TB3> INFO: CalDel: 84 95 83 96 98 77 121 85 104 88 91 93 87 82 82 88
[18:31:51.567] <TB3> INFO: VthrComp: 51 51 52 54 51 53 51 51 51 51 51 51 51 51 51 51
[18:31:51.569] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C0.dat
[18:31:51.569] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C1.dat
[18:31:51.569] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C2.dat
[18:31:51.569] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C3.dat
[18:31:51.569] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C4.dat
[18:31:51.569] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C5.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C6.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C7.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C8.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C9.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C10.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C11.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C12.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C13.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C14.dat
[18:31:51.570] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters_C15.dat
[18:31:51.570] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C0a.dat
[18:31:51.570] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C0b.dat
[18:31:51.571] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C1a.dat
[18:31:51.571] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[18:31:51.571] <TB3> INFO: PixTestPretest::doTest() done, duration: 92 seconds
[18:31:51.666] <TB3> INFO: enter test to run
[18:31:51.666] <TB3> INFO: test: fulltest no parameter change
[18:31:51.666] <TB3> INFO: running: fulltest
[18:31:51.666] <TB3> INFO: ######################################################################
[18:31:51.666] <TB3> INFO: PixTestFullTest::doTest()
[18:31:51.666] <TB3> INFO: ######################################################################
[18:31:51.668] <TB3> INFO: ######################################################################
[18:31:51.668] <TB3> INFO: PixTestAlive::doTest()
[18:31:51.668] <TB3> INFO: ######################################################################
[18:31:51.669] <TB3> INFO: ----------------------------------------------------------------------
[18:31:51.669] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:31:51.669] <TB3> INFO: ----------------------------------------------------------------------
[18:31:51.903] <TB3> INFO: Expecting 41600 events.
[18:31:55.398] <TB3> INFO: 41600 events read in total (2904ms).
[18:31:55.399] <TB3> INFO: Test took 3729ms.
[18:31:55.625] <TB3> INFO: PixTestAlive::aliveTest() done
[18:31:55.625] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 1 0 0 0 0 0 0 0 0
[18:31:55.626] <TB3> INFO: ----------------------------------------------------------------------
[18:31:55.626] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:31:55.626] <TB3> INFO: ----------------------------------------------------------------------
[18:31:55.859] <TB3> INFO: Expecting 41600 events.
[18:31:58.806] <TB3> INFO: 41600 events read in total (2355ms).
[18:31:58.807] <TB3> INFO: Test took 3180ms.
[18:31:58.807] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[18:31:59.047] <TB3> INFO: PixTestAlive::maskTest() done
[18:31:59.047] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[18:31:59.048] <TB3> INFO: ----------------------------------------------------------------------
[18:31:59.048] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:31:59.048] <TB3> INFO: ----------------------------------------------------------------------
[18:31:59.280] <TB3> INFO: Expecting 41600 events.
[18:32:02.798] <TB3> INFO: 41600 events read in total (2927ms).
[18:32:02.799] <TB3> INFO: Test took 3750ms.
[18:32:03.029] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[18:32:03.029] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[18:32:03.029] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[18:32:03.029] <TB3> INFO: Decoding statistics:
[18:32:03.029] <TB3> INFO: General information:
[18:32:03.029] <TB3> INFO: 16bit words read: 0
[18:32:03.029] <TB3> INFO: valid events total: 0
[18:32:03.029] <TB3> INFO: empty events: 0
[18:32:03.029] <TB3> INFO: valid events with pixels: 0
[18:32:03.029] <TB3> INFO: valid pixel hits: 0
[18:32:03.029] <TB3> INFO: Event errors: 0
[18:32:03.029] <TB3> INFO: start marker: 0
[18:32:03.029] <TB3> INFO: stop marker: 0
[18:32:03.029] <TB3> INFO: overflow: 0
[18:32:03.029] <TB3> INFO: invalid 5bit words: 0
[18:32:03.029] <TB3> INFO: invalid XOR eye diagram: 0
[18:32:03.029] <TB3> INFO: frame (failed synchr.): 0
[18:32:03.029] <TB3> INFO: idle data (no TBM trl): 0
[18:32:03.029] <TB3> INFO: no data (only TBM hdr): 0
[18:32:03.029] <TB3> INFO: TBM errors: 0
[18:32:03.029] <TB3> INFO: flawed TBM headers: 0
[18:32:03.029] <TB3> INFO: flawed TBM trailers: 0
[18:32:03.029] <TB3> INFO: event ID mismatches: 0
[18:32:03.029] <TB3> INFO: ROC errors: 0
[18:32:03.029] <TB3> INFO: missing ROC header(s): 0
[18:32:03.029] <TB3> INFO: misplaced readback start: 0
[18:32:03.029] <TB3> INFO: Pixel decoding errors: 0
[18:32:03.029] <TB3> INFO: pixel data incomplete: 0
[18:32:03.029] <TB3> INFO: pixel address: 0
[18:32:03.029] <TB3> INFO: pulse height fill bit: 0
[18:32:03.029] <TB3> INFO: buffer corruption: 0
[18:32:03.036] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C15.dat
[18:32:03.036] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr_C15.dat
[18:32:03.036] <TB3> ERROR: <ConfigParameters.cc/readGainPedestalParameters:L1005> cannot open /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat for reading PH calibration constants

[18:32:03.036] <TB3> INFO: ######################################################################
[18:32:03.036] <TB3> INFO: PixTestReadback::doTest()
[18:32:03.036] <TB3> INFO: ######################################################################
[18:32:03.036] <TB3> INFO: ----------------------------------------------------------------------
[18:32:03.036] <TB3> INFO: PixTestReadback::CalibrateVd()
[18:32:03.036] <TB3> INFO: ----------------------------------------------------------------------
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C0.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C1.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C2.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C3.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C4.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C5.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C6.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C7.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C8.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C9.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C10.dat
[18:32:12.993] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C11.dat
[18:32:12.994] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C12.dat
[18:32:12.994] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C13.dat
[18:32:12.994] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C14.dat
[18:32:12.994] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C15.dat
[18:32:13.021] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[18:32:13.021] <TB3> INFO: ----------------------------------------------------------------------
[18:32:13.021] <TB3> INFO: PixTestReadback::CalibrateVa()
[18:32:13.021] <TB3> INFO: ----------------------------------------------------------------------
[18:32:22.910] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C0.dat
[18:32:22.910] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C1.dat
[18:32:22.910] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C2.dat
[18:32:22.910] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C3.dat
[18:32:22.910] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C4.dat
[18:32:22.910] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C5.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C6.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C7.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C8.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C9.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C10.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C11.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C12.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C13.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C14.dat
[18:32:22.911] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C15.dat
[18:32:22.940] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[18:32:22.940] <TB3> INFO: ----------------------------------------------------------------------
[18:32:22.940] <TB3> INFO: PixTestReadback::readbackVbg()
[18:32:22.940] <TB3> INFO: ----------------------------------------------------------------------
[18:32:30.581] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[18:32:30.581] <TB3> INFO: ----------------------------------------------------------------------
[18:32:30.581] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[18:32:30.581] <TB3> INFO: ----------------------------------------------------------------------
[18:32:30.581] <TB3> INFO: Vbg will be calibrated using Vd calibration
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 152.2calibrated Vbg = 1.18337 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 147.6calibrated Vbg = 1.17567 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 154.2calibrated Vbg = 1.17616 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 156calibrated Vbg = 1.17007 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 154.9calibrated Vbg = 1.18109 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 154.9calibrated Vbg = 1.17237 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 157.4calibrated Vbg = 1.18437 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 150.2calibrated Vbg = 1.1743 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 150.8calibrated Vbg = 1.17244 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 152.2calibrated Vbg = 1.17556 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 155.7calibrated Vbg = 1.16776 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 157.6calibrated Vbg = 1.16654 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 158.5calibrated Vbg = 1.17301 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 160calibrated Vbg = 1.17496 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 156calibrated Vbg = 1.17979 :::*/*/*/*/
[18:32:30.581] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 151.7calibrated Vbg = 1.17203 :::*/*/*/*/
[18:32:30.583] <TB3> INFO: ----------------------------------------------------------------------
[18:32:30.583] <TB3> INFO: PixTestReadback::CalibrateIa()
[18:32:30.583] <TB3> INFO: ----------------------------------------------------------------------
[18:35:10.860] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C0.dat
[18:35:10.860] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C1.dat
[18:35:10.860] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C2.dat
[18:35:10.860] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C3.dat
[18:35:10.860] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C4.dat
[18:35:10.860] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C5.dat
[18:35:10.860] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C6.dat
[18:35:10.860] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C7.dat
[18:35:10.860] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C8.dat
[18:35:10.861] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C9.dat
[18:35:10.861] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C10.dat
[18:35:10.861] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C11.dat
[18:35:10.861] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C12.dat
[18:35:10.861] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C13.dat
[18:35:10.861] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C14.dat
[18:35:10.861] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//readbackCal_C15.dat
[18:35:10.889] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[18:35:10.891] <TB3> INFO: PixTestReadback::doTest() done
[18:35:10.891] <TB3> INFO: Decoding statistics:
[18:35:10.891] <TB3> INFO: General information:
[18:35:10.891] <TB3> INFO: 16bit words read: 1536
[18:35:10.891] <TB3> INFO: valid events total: 256
[18:35:10.891] <TB3> INFO: empty events: 256
[18:35:10.891] <TB3> INFO: valid events with pixels: 0
[18:35:10.891] <TB3> INFO: valid pixel hits: 0
[18:35:10.891] <TB3> INFO: Event errors: 0
[18:35:10.891] <TB3> INFO: start marker: 0
[18:35:10.891] <TB3> INFO: stop marker: 0
[18:35:10.891] <TB3> INFO: overflow: 0
[18:35:10.891] <TB3> INFO: invalid 5bit words: 0
[18:35:10.891] <TB3> INFO: invalid XOR eye diagram: 0
[18:35:10.891] <TB3> INFO: frame (failed synchr.): 0
[18:35:10.891] <TB3> INFO: idle data (no TBM trl): 0
[18:35:10.891] <TB3> INFO: no data (only TBM hdr): 0
[18:35:10.891] <TB3> INFO: TBM errors: 0
[18:35:10.891] <TB3> INFO: flawed TBM headers: 0
[18:35:10.891] <TB3> INFO: flawed TBM trailers: 0
[18:35:10.891] <TB3> INFO: event ID mismatches: 0
[18:35:10.891] <TB3> INFO: ROC errors: 0
[18:35:10.891] <TB3> INFO: missing ROC header(s): 0
[18:35:10.891] <TB3> INFO: misplaced readback start: 0
[18:35:10.891] <TB3> INFO: Pixel decoding errors: 0
[18:35:10.891] <TB3> INFO: pixel data incomplete: 0
[18:35:10.891] <TB3> INFO: pixel address: 0
[18:35:10.891] <TB3> INFO: pulse height fill bit: 0
[18:35:10.891] <TB3> INFO: buffer corruption: 0
[18:35:10.928] <TB3> INFO: ######################################################################
[18:35:10.928] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[18:35:10.928] <TB3> INFO: ######################################################################
[18:35:10.930] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[18:35:10.942] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[18:35:10.942] <TB3> INFO: run 1 of 1
[18:35:11.173] <TB3> INFO: Expecting 3120000 events.
[18:35:42.208] <TB3> INFO: 683025 events read in total (30443ms).
[18:35:54.642] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (146) != TBM ID (129)

[18:35:54.777] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 146 146 129 146 146 146 146 146

[18:35:54.777] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (147)

[18:35:54.777] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:35:54.777] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a096 8000 40c0 266 2def 40c0 266 2def e022 c000

[18:35:54.777] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a090 80b1 4040 266 2def 40c0 266 2def e022 c000

[18:35:54.778] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a091 80c0 40c1 266 2def 40c1 266 2def e022 c000

[18:35:54.778] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 40c1 40c1 2def 40c0 266 2def e022 c000

[18:35:54.778] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a093 8040 40c0 266 2def 40c1 266 2def e022 c000

[18:35:54.778] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a094 80b1 40c0 266 2def 40c0 266 2def e022 c000

[18:35:54.778] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a095 80c0 4060 266 2def 40e0 266 2def e022 c000

[18:36:12.387] <TB3> INFO: 1360360 events read in total (60622ms).
[18:36:24.781] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (105) != TBM ID (129)

[18:36:24.917] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 105 105 129 105 105 105 105 105

[18:36:24.917] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (106)

[18:36:24.917] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:36:24.917] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06d 80c0 40c1 4cc 2bef 40c1 4cc 2bef e022 c000

[18:36:24.917] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a067 8040 40e0 4cc 2bef 40c0 4cc 2bef e022 c000

[18:36:24.918] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a068 80b1 40c0 4cc 2bef 40c0 4cc 2bef e022 c000

[18:36:24.918] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 40c1 40c1 2bef 40c1 4cc 2bef e022 c000

[18:36:24.918] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06a 8000 40c1 4cc 2bef 40c1 4cc 2bef e022 c000

[18:36:24.918] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06b 8040 40c1 4cc 2bef 40c1 4cc 2bef e022 c000

[18:36:24.918] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a06c 80b1 40c0 4cc 2bef 40c0 4cc 2bef e022 c000

[18:36:42.431] <TB3> INFO: 2035455 events read in total (90666ms).
[18:36:54.839] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (128) != TBM ID (129)

[18:36:54.976] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 128 128 129 128 128 128 128 128

[18:36:54.976] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (129)

[18:36:54.976] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:36:54.976] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a084 80b1 40e0 832 23ef 40c0 832 23ef e022 c000

[18:36:54.976] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07e 8000 40c0 832 23ef 40c0 832 23ef e022 c000

[18:36:54.976] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a07f 8040 40c3 832 23ef 40c3 832 23ef e022 c000

[18:36:54.976] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 40c1 40c1 23ef 40c0 832 23ef e022 c000

[18:36:54.976] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 40c1 832 23ef 40c1 832 23ef e022 c000

[18:36:54.976] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a082 8000 40c0 832 23ef 40c0 832 23ef e022 c000

[18:36:54.976] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a083 8040 4060 832 23ef 40c1 832 23ef e022 c000

[18:37:12.904] <TB3> INFO: 2710910 events read in total (121139ms).
[18:37:20.538] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (255) != TBM ID (129)

[18:37:20.680] <TB3> ERROR: <hal.cc/daqAllEvents:L1697> Channels report mismatching event numbers: 255 255 129 255 255 255 255 255

[18:37:20.680] <TB3> ERROR: <datapipe.cc/CheckEventID:L485> Channel 0 Event ID mismatch: local ID (130) != TBM ID (0)

[18:37:20.680] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:37:20.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a003 8040 4060 4061 e022 c000

[18:37:20.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fd 80c0 40c1 40c1 e022 c000

[18:37:20.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a0fe 8000 4061 4061 e022 c000

[18:37:20.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a081 80c0 40c1 40c1 e022 c000

[18:37:20.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a000 80b1 4060 40c0 e022 c000

[18:37:20.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a001 80c0 40c1 40c1 e022 c000

[18:37:20.680] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a002 8000 40c0 40c0 e022 c000

[18:37:20.682] <TB3> WARNING: Channel 0 ROC 0: Readback start marker after 32 readouts!

[18:37:20.682] <TB3> WARNING: Channel 0 ROC 1: Readback start marker after 32 readouts!

[18:37:20.682] <TB3> ERROR: <datapipe.cc/Read:L170> Dumping the flawed event +- 3 events:

[18:37:20.682] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a012 8000 40c0 40c0 e022 c000

[18:37:20.682] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00c 80b1 40c0 aa2 2def 40c0 e022 c000

[18:37:20.682] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00d 80c0 4040 aa2 2def 40c0 aa2 2def e022 c000

[18:37:20.682] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00e 8000 40c1 aa2 2def 40c1 e022 c000

[18:37:20.682] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a00f 8040 40c2 40c2 e022 c000

[18:37:20.682] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a010 80b1 40c0 40c0 e022 c000

[18:37:20.682] <TB3> ERROR: <datapipe.cc/Read:L172> ====== 0 ====== a011 80c0 40c1 aa2 2def 40c1 e022 c000

[18:37:32.308] <TB3> INFO: 3120000 events read in total (140543ms).
[18:37:32.375] <TB3> INFO: Test took 141434ms.
[18:37:58.567] <TB3> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 167 seconds
[18:37:58.567] <TB3> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0
[18:37:58.567] <TB3> INFO: separation cut (per ROC): 109 106 117 108 110 124 105 108 110 125 123 119 121 123 111 127
[18:37:58.568] <TB3> INFO: Decoding statistics:
[18:37:58.568] <TB3> INFO: General information:
[18:37:58.568] <TB3> INFO: 16bit words read: 0
[18:37:58.568] <TB3> INFO: valid events total: 0
[18:37:58.568] <TB3> INFO: empty events: 0
[18:37:58.568] <TB3> INFO: valid events with pixels: 0
[18:37:58.568] <TB3> INFO: valid pixel hits: 0
[18:37:58.568] <TB3> INFO: Event errors: 0
[18:37:58.568] <TB3> INFO: start marker: 0
[18:37:58.568] <TB3> INFO: stop marker: 0
[18:37:58.568] <TB3> INFO: overflow: 0
[18:37:58.568] <TB3> INFO: invalid 5bit words: 0
[18:37:58.568] <TB3> INFO: invalid XOR eye diagram: 0
[18:37:58.568] <TB3> INFO: frame (failed synchr.): 0
[18:37:58.568] <TB3> INFO: idle data (no TBM trl): 0
[18:37:58.568] <TB3> INFO: no data (only TBM hdr): 0
[18:37:58.568] <TB3> INFO: TBM errors: 0
[18:37:58.568] <TB3> INFO: flawed TBM headers: 0
[18:37:58.568] <TB3> INFO: flawed TBM trailers: 0
[18:37:58.568] <TB3> INFO: event ID mismatches: 0
[18:37:58.568] <TB3> INFO: ROC errors: 0
[18:37:58.568] <TB3> INFO: missing ROC header(s): 0
[18:37:58.568] <TB3> INFO: misplaced readback start: 0
[18:37:58.568] <TB3> INFO: Pixel decoding errors: 0
[18:37:58.568] <TB3> INFO: pixel data incomplete: 0
[18:37:58.568] <TB3> INFO: pixel address: 0
[18:37:58.568] <TB3> INFO: pulse height fill bit: 0
[18:37:58.568] <TB3> INFO: buffer corruption: 0
[18:37:58.614] <TB3> INFO: ######################################################################
[18:37:58.614] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[18:37:58.614] <TB3> INFO: ######################################################################
[18:37:58.614] <TB3> INFO: ----------------------------------------------------------------------
[18:37:58.614] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[18:37:58.614] <TB3> INFO: ----------------------------------------------------------------------
[18:37:58.614] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[18:37:58.625] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[18:37:58.625] <TB3> INFO: run 1 of 1
[18:37:58.893] <TB3> INFO: Expecting 36608000 events.
[18:38:22.738] <TB3> INFO: 701200 events read in total (23253ms).
[18:38:45.908] <TB3> INFO: 1383150 events read in total (46423ms).
[18:39:09.025] <TB3> INFO: 2065700 events read in total (69541ms).
[18:39:32.006] <TB3> INFO: 2745000 events read in total (92521ms).
[18:39:54.849] <TB3> INFO: 3428650 events read in total (115364ms).
[18:40:17.709] <TB3> INFO: 4108850 events read in total (138224ms).
[18:40:40.895] <TB3> INFO: 4791400 events read in total (161410ms).
[18:41:04.021] <TB3> INFO: 5472150 events read in total (184536ms).
[18:41:26.937] <TB3> INFO: 6153700 events read in total (207452ms).
[18:41:50.096] <TB3> INFO: 6834100 events read in total (230611ms).
[18:42:12.929] <TB3> INFO: 7514250 events read in total (253444ms).
[18:42:35.895] <TB3> INFO: 8195300 events read in total (276410ms).
[18:42:58.726] <TB3> INFO: 8876750 events read in total (299241ms).
[18:43:21.386] <TB3> INFO: 9557200 events read in total (321901ms).
[18:43:43.921] <TB3> INFO: 10238650 events read in total (344436ms).
[18:44:06.682] <TB3> INFO: 10918900 events read in total (367197ms).
[18:44:29.290] <TB3> INFO: 11598700 events read in total (389805ms).
[18:44:52.255] <TB3> INFO: 12280550 events read in total (412770ms).
[18:45:14.929] <TB3> INFO: 12961450 events read in total (435444ms).
[18:45:37.879] <TB3> INFO: 13642550 events read in total (458394ms).
[18:46:00.769] <TB3> INFO: 14321000 events read in total (481284ms).
[18:46:23.417] <TB3> INFO: 15000450 events read in total (503932ms).
[18:46:45.930] <TB3> INFO: 15676950 events read in total (526445ms).
[18:47:08.877] <TB3> INFO: 16355500 events read in total (549392ms).
[18:47:31.703] <TB3> INFO: 17033500 events read in total (572218ms).
[18:47:54.669] <TB3> INFO: 17711250 events read in total (595184ms).
[18:48:17.391] <TB3> INFO: 18386250 events read in total (617906ms).
[18:48:40.339] <TB3> INFO: 19063650 events read in total (640854ms).
[18:49:03.271] <TB3> INFO: 19737050 events read in total (663786ms).
[18:49:26.163] <TB3> INFO: 20412550 events read in total (686678ms).
[18:49:49.196] <TB3> INFO: 21085200 events read in total (709711ms).
[18:50:12.177] <TB3> INFO: 21759700 events read in total (732692ms).
[18:50:35.309] <TB3> INFO: 22432950 events read in total (755824ms).
[18:50:58.421] <TB3> INFO: 23106450 events read in total (778936ms).
[18:51:21.058] <TB3> INFO: 23779100 events read in total (801573ms).
[18:51:43.972] <TB3> INFO: 24452650 events read in total (824487ms).
[18:52:06.406] <TB3> INFO: 25125500 events read in total (846921ms).
[18:52:29.425] <TB3> INFO: 25800400 events read in total (869940ms).
[18:52:52.304] <TB3> INFO: 26475150 events read in total (892819ms).
[18:53:14.999] <TB3> INFO: 27147250 events read in total (915514ms).
[18:53:37.704] <TB3> INFO: 27820950 events read in total (938219ms).
[18:54:00.505] <TB3> INFO: 28493250 events read in total (961020ms).
[18:54:23.659] <TB3> INFO: 29166500 events read in total (984174ms).
[18:54:46.227] <TB3> INFO: 29838350 events read in total (1006742ms).
[18:55:09.063] <TB3> INFO: 30509850 events read in total (1029578ms).
[18:55:32.232] <TB3> INFO: 31181850 events read in total (1052747ms).
[18:55:55.167] <TB3> INFO: 31854550 events read in total (1075682ms).
[18:56:18.163] <TB3> INFO: 32525350 events read in total (1098678ms).
[18:56:41.195] <TB3> INFO: 33198850 events read in total (1121710ms).
[18:57:04.075] <TB3> INFO: 33870700 events read in total (1144590ms).
[18:57:27.040] <TB3> INFO: 34546650 events read in total (1167555ms).
[18:57:50.326] <TB3> INFO: 35220650 events read in total (1190841ms).
[18:58:13.199] <TB3> INFO: 35895050 events read in total (1213714ms).
[18:58:35.762] <TB3> INFO: 36583550 events read in total (1236277ms).
[18:58:36.941] <TB3> INFO: 36608000 events read in total (1237456ms).
[18:58:36.993] <TB3> INFO: Test took 1238368ms.
[18:58:37.352] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:39.200] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:41.068] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:43.088] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:45.135] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:47.055] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:49.076] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:51.074] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:52.485] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:53.870] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:55.244] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:56.652] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:58.042] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:58:59.430] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:59:00.802] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:59:02.187] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[18:59:03.703] <TB3> INFO: PixTestScurves::scurves() done
[18:59:03.703] <TB3> INFO: Vcal mean: 118.42 119.69 126.73 126.02 119.43 124.19 123.99 121.71 122.44 122.70 128.01 120.19 128.48 126.88 117.24 123.37
[18:59:03.703] <TB3> INFO: Vcal RMS: 5.55 5.42 7.03 7.17 5.32 6.15 5.98 6.36 6.15 5.82 6.77 6.29 6.37 6.13 5.71 6.12
[18:59:03.703] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1265 seconds
[18:59:03.703] <TB3> INFO: Decoding statistics:
[18:59:03.703] <TB3> INFO: General information:
[18:59:03.703] <TB3> INFO: 16bit words read: 0
[18:59:03.703] <TB3> INFO: valid events total: 0
[18:59:03.703] <TB3> INFO: empty events: 0
[18:59:03.703] <TB3> INFO: valid events with pixels: 0
[18:59:03.703] <TB3> INFO: valid pixel hits: 0
[18:59:03.703] <TB3> INFO: Event errors: 0
[18:59:03.703] <TB3> INFO: start marker: 0
[18:59:03.703] <TB3> INFO: stop marker: 0
[18:59:03.703] <TB3> INFO: overflow: 0
[18:59:03.703] <TB3> INFO: invalid 5bit words: 0
[18:59:03.703] <TB3> INFO: invalid XOR eye diagram: 0
[18:59:03.703] <TB3> INFO: frame (failed synchr.): 0
[18:59:03.703] <TB3> INFO: idle data (no TBM trl): 0
[18:59:03.703] <TB3> INFO: no data (only TBM hdr): 0
[18:59:03.703] <TB3> INFO: TBM errors: 0
[18:59:03.703] <TB3> INFO: flawed TBM headers: 0
[18:59:03.703] <TB3> INFO: flawed TBM trailers: 0
[18:59:03.703] <TB3> INFO: event ID mismatches: 0
[18:59:03.703] <TB3> INFO: ROC errors: 0
[18:59:03.703] <TB3> INFO: missing ROC header(s): 0
[18:59:03.703] <TB3> INFO: misplaced readback start: 0
[18:59:03.703] <TB3> INFO: Pixel decoding errors: 0
[18:59:03.703] <TB3> INFO: pixel data incomplete: 0
[18:59:03.703] <TB3> INFO: pixel address: 0
[18:59:03.703] <TB3> INFO: pulse height fill bit: 0
[18:59:03.703] <TB3> INFO: buffer corruption: 0
[18:59:03.767] <TB3> INFO: ######################################################################
[18:59:03.767] <TB3> INFO: PixTestTrim::doTest()
[18:59:03.767] <TB3> INFO: ######################################################################
[18:59:03.769] <TB3> INFO: ----------------------------------------------------------------------
[18:59:03.769] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[18:59:03.769] <TB3> INFO: ----------------------------------------------------------------------
[18:59:03.817] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[18:59:03.817] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[18:59:03.829] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[18:59:03.829] <TB3> INFO: run 1 of 1
[18:59:04.092] <TB3> INFO: Expecting 5025280 events.
[18:59:35.176] <TB3> INFO: 829920 events read in total (30490ms).
[19:00:05.121] <TB3> INFO: 1658912 events read in total (60435ms).
[19:00:35.438] <TB3> INFO: 2484832 events read in total (90753ms).
[19:01:05.284] <TB3> INFO: 3305224 events read in total (120598ms).
[19:01:35.468] <TB3> INFO: 4122336 events read in total (150782ms).
[19:02:05.716] <TB3> INFO: 4938336 events read in total (181030ms).
[19:02:09.440] <TB3> INFO: 5025280 events read in total (184754ms).
[19:02:09.475] <TB3> INFO: Test took 185646ms.
[19:02:26.332] <TB3> INFO: ROC 0 VthrComp = 122
[19:02:26.332] <TB3> INFO: ROC 1 VthrComp = 120
[19:02:26.332] <TB3> INFO: ROC 2 VthrComp = 131
[19:02:26.333] <TB3> INFO: ROC 3 VthrComp = 125
[19:02:26.333] <TB3> INFO: ROC 4 VthrComp = 124
[19:02:26.333] <TB3> INFO: ROC 5 VthrComp = 133
[19:02:26.333] <TB3> INFO: ROC 6 VthrComp = 116
[19:02:26.333] <TB3> INFO: ROC 7 VthrComp = 117
[19:02:26.333] <TB3> INFO: ROC 8 VthrComp = 127
[19:02:26.333] <TB3> INFO: ROC 9 VthrComp = 128
[19:02:26.334] <TB3> INFO: ROC 10 VthrComp = 125
[19:02:26.334] <TB3> INFO: ROC 11 VthrComp = 121
[19:02:26.334] <TB3> INFO: ROC 12 VthrComp = 128
[19:02:26.334] <TB3> INFO: ROC 13 VthrComp = 131
[19:02:26.334] <TB3> INFO: ROC 14 VthrComp = 119
[19:02:26.334] <TB3> INFO: ROC 15 VthrComp = 126
[19:02:26.583] <TB3> INFO: Expecting 41600 events.
[19:02:30.093] <TB3> INFO: 41600 events read in total (2918ms).
[19:02:30.094] <TB3> INFO: Test took 3758ms.
[19:02:30.104] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[19:02:30.104] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[19:02:30.116] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[19:02:30.116] <TB3> INFO: run 1 of 1
[19:02:30.394] <TB3> INFO: Expecting 5025280 events.
[19:02:56.362] <TB3> INFO: 591552 events read in total (25377ms).
[19:03:21.974] <TB3> INFO: 1180928 events read in total (50989ms).
[19:03:47.682] <TB3> INFO: 1770328 events read in total (76697ms).
[19:04:13.141] <TB3> INFO: 2359344 events read in total (102156ms).
[19:04:38.558] <TB3> INFO: 2946288 events read in total (127573ms).
[19:05:03.938] <TB3> INFO: 3532040 events read in total (152953ms).
[19:05:29.839] <TB3> INFO: 4116960 events read in total (178854ms).
[19:05:55.265] <TB3> INFO: 4701944 events read in total (204280ms).
[19:06:09.447] <TB3> INFO: 5025280 events read in total (218462ms).
[19:06:09.504] <TB3> INFO: Test took 219388ms.
[19:06:33.949] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 59.5126 for pixel 18/3 mean/min/max = 45.8849/32.1457/59.6241
[19:06:33.950] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 61.2101 for pixel 21/3 mean/min/max = 46.9958/32.7065/61.285
[19:06:33.950] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 60.3363 for pixel 4/13 mean/min/max = 46.1016/31.7985/60.4047
[19:06:33.950] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 66.2492 for pixel 42/7 mean/min/max = 48.5621/30.7794/66.3448
[19:06:33.951] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 58.5732 for pixel 1/58 mean/min/max = 45.332/32.0415/58.6224
[19:06:33.951] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 59.3419 for pixel 51/10 mean/min/max = 45.9364/32.5163/59.3565
[19:06:33.951] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 64.2148 for pixel 24/2 mean/min/max = 48.2593/32.2292/64.2895
[19:06:33.952] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 61.6265 for pixel 44/13 mean/min/max = 46.6751/31.698/61.6522
[19:06:33.952] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 60.9838 for pixel 47/3 mean/min/max = 46.2069/31.0418/61.372
[19:06:33.952] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 60.9447 for pixel 8/17 mean/min/max = 47.2289/33.4644/60.9935
[19:06:33.953] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 62.7544 for pixel 0/5 mean/min/max = 47.2699/31.6187/62.9212
[19:06:33.953] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 61.3493 for pixel 24/37 mean/min/max = 46.4895/31.623/61.3559
[19:06:33.953] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 60.6244 for pixel 22/8 mean/min/max = 46.4198/31.7922/61.0473
[19:06:33.953] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 59.2644 for pixel 10/78 mean/min/max = 46.0681/32.7318/59.4044
[19:06:33.954] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 59.3945 for pixel 45/9 mean/min/max = 45.7494/31.9823/59.5165
[19:06:33.954] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 60.2151 for pixel 10/78 mean/min/max = 46.1001/31.902/60.2982
[19:06:33.954] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:06:34.043] <TB3> INFO: Expecting 411648 events.
[19:06:43.391] <TB3> INFO: 411648 events read in total (8757ms).
[19:06:43.398] <TB3> INFO: Expecting 411648 events.
[19:06:52.607] <TB3> INFO: 411648 events read in total (8806ms).
[19:06:52.617] <TB3> INFO: Expecting 411648 events.
[19:07:01.815] <TB3> INFO: 411648 events read in total (8795ms).
[19:07:01.828] <TB3> INFO: Expecting 411648 events.
[19:07:11.045] <TB3> INFO: 411648 events read in total (8814ms).
[19:07:11.061] <TB3> INFO: Expecting 411648 events.
[19:07:20.239] <TB3> INFO: 411648 events read in total (8775ms).
[19:07:20.256] <TB3> INFO: Expecting 411648 events.
[19:07:29.393] <TB3> INFO: 411648 events read in total (8734ms).
[19:07:29.413] <TB3> INFO: Expecting 411648 events.
[19:07:38.519] <TB3> INFO: 411648 events read in total (8703ms).
[19:07:38.549] <TB3> INFO: Expecting 411648 events.
[19:07:47.711] <TB3> INFO: 411648 events read in total (8759ms).
[19:07:47.736] <TB3> INFO: Expecting 411648 events.
[19:07:56.879] <TB3> INFO: 411648 events read in total (8740ms).
[19:07:56.916] <TB3> INFO: Expecting 411648 events.
[19:08:06.099] <TB3> INFO: 411648 events read in total (8780ms).
[19:08:06.132] <TB3> INFO: Expecting 411648 events.
[19:08:15.222] <TB3> INFO: 411648 events read in total (8687ms).
[19:08:15.268] <TB3> INFO: Expecting 411648 events.
[19:08:24.471] <TB3> INFO: 411648 events read in total (8800ms).
[19:08:24.520] <TB3> INFO: Expecting 411648 events.
[19:08:33.679] <TB3> INFO: 411648 events read in total (8756ms).
[19:08:33.724] <TB3> INFO: Expecting 411648 events.
[19:08:42.906] <TB3> INFO: 411648 events read in total (8779ms).
[19:08:42.968] <TB3> INFO: Expecting 411648 events.
[19:08:52.127] <TB3> INFO: 411648 events read in total (8756ms).
[19:08:52.172] <TB3> INFO: Expecting 411648 events.
[19:09:01.357] <TB3> INFO: 411648 events read in total (8782ms).
[19:09:01.413] <TB3> INFO: Test took 147459ms.
[19:09:02.160] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[19:09:02.171] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[19:09:02.171] <TB3> INFO: run 1 of 1
[19:09:02.405] <TB3> INFO: Expecting 5025280 events.
[19:09:28.436] <TB3> INFO: 588680 events read in total (25440ms).
[19:09:54.113] <TB3> INFO: 1177120 events read in total (51118ms).
[19:10:19.907] <TB3> INFO: 1763568 events read in total (76911ms).
[19:10:45.567] <TB3> INFO: 2351000 events read in total (102571ms).
[19:11:11.053] <TB3> INFO: 2940208 events read in total (128057ms).
[19:11:36.853] <TB3> INFO: 3532648 events read in total (153857ms).
[19:12:03.103] <TB3> INFO: 4121624 events read in total (180107ms).
[19:12:28.612] <TB3> INFO: 4709688 events read in total (205616ms).
[19:12:42.584] <TB3> INFO: 5025280 events read in total (219588ms).
[19:12:42.690] <TB3> INFO: Test took 220520ms.
[19:13:04.435] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 6.988637 .. 146.967727
[19:13:04.676] <TB3> INFO: Expecting 208000 events.
[19:13:14.041] <TB3> INFO: 208000 events read in total (8773ms).
[19:13:14.042] <TB3> INFO: Test took 9606ms.
[19:13:14.087] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 6 .. 156 (-1/-1) hits flags = 528 (plus default)
[19:13:14.097] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[19:13:14.097] <TB3> INFO: run 1 of 1
[19:13:14.375] <TB3> INFO: Expecting 5025280 events.
[19:13:40.661] <TB3> INFO: 578256 events read in total (25694ms).
[19:14:06.157] <TB3> INFO: 1156392 events read in total (51191ms).
[19:14:31.318] <TB3> INFO: 1734392 events read in total (76351ms).
[19:14:56.520] <TB3> INFO: 2312264 events read in total (101553ms).
[19:15:21.955] <TB3> INFO: 2889496 events read in total (126989ms).
[19:15:47.164] <TB3> INFO: 3466456 events read in total (152197ms).
[19:16:12.198] <TB3> INFO: 4043008 events read in total (177231ms).
[19:16:37.761] <TB3> INFO: 4619488 events read in total (202794ms).
[19:16:55.515] <TB3> INFO: 5025280 events read in total (220548ms).
[19:16:55.593] <TB3> INFO: Test took 221496ms.
[19:17:20.686] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 26.985175 .. 43.850572
[19:17:20.919] <TB3> INFO: Expecting 208000 events.
[19:17:30.783] <TB3> INFO: 208000 events read in total (9273ms).
[19:17:30.784] <TB3> INFO: Test took 10097ms.
[19:17:30.861] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 16 .. 53 (-1/-1) hits flags = 528 (plus default)
[19:17:30.874] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[19:17:30.874] <TB3> INFO: run 1 of 1
[19:17:31.176] <TB3> INFO: Expecting 1264640 events.
[19:17:59.768] <TB3> INFO: 673856 events read in total (28001ms).
[19:18:24.159] <TB3> INFO: 1264640 events read in total (52393ms).
[19:18:24.189] <TB3> INFO: Test took 53316ms.
[19:18:38.779] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 26.976418 .. 48.890200
[19:18:39.016] <TB3> INFO: Expecting 208000 events.
[19:18:48.921] <TB3> INFO: 208000 events read in total (9314ms).
[19:18:48.922] <TB3> INFO: Test took 10142ms.
[19:18:48.968] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 58 (-1/-1) hits flags = 528 (plus default)
[19:18:48.978] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[19:18:48.978] <TB3> INFO: run 1 of 1
[19:18:49.256] <TB3> INFO: Expecting 1431040 events.
[19:19:17.197] <TB3> INFO: 653128 events read in total (27349ms).
[19:19:45.014] <TB3> INFO: 1305480 events read in total (55166ms).
[19:19:50.676] <TB3> INFO: 1431040 events read in total (60828ms).
[19:19:50.707] <TB3> INFO: Test took 61729ms.
[19:20:05.007] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 25.269753 .. 50.242718
[19:20:05.245] <TB3> INFO: Expecting 208000 events.
[19:20:14.986] <TB3> INFO: 208000 events read in total (9150ms).
[19:20:14.987] <TB3> INFO: Test took 9979ms.
[19:20:15.046] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 15 .. 60 (-1/-1) hits flags = 528 (plus default)
[19:20:15.058] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[19:20:15.058] <TB3> INFO: run 1 of 1
[19:20:15.335] <TB3> INFO: Expecting 1530880 events.
[19:20:42.936] <TB3> INFO: 649608 events read in total (27009ms).
[19:21:10.523] <TB3> INFO: 1299456 events read in total (54596ms).
[19:21:20.367] <TB3> INFO: 1530880 events read in total (64440ms).
[19:21:20.401] <TB3> INFO: Test took 65344ms.
[19:21:34.591] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[19:21:34.591] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[19:21:34.601] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[19:21:34.602] <TB3> INFO: run 1 of 1
[19:21:34.835] <TB3> INFO: Expecting 1364480 events.
[19:22:03.404] <TB3> INFO: 667464 events read in total (27978ms).
[19:22:31.251] <TB3> INFO: 1334600 events read in total (55826ms).
[19:22:32.978] <TB3> INFO: 1364480 events read in total (57552ms).
[19:22:32.002] <TB3> INFO: Test took 58401ms.
[19:22:47.181] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C0.dat
[19:22:47.182] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C1.dat
[19:22:47.182] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C2.dat
[19:22:47.182] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C3.dat
[19:22:47.182] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C4.dat
[19:22:47.182] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C5.dat
[19:22:47.182] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C6.dat
[19:22:47.182] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C7.dat
[19:22:47.182] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C8.dat
[19:22:47.183] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C9.dat
[19:22:47.183] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C10.dat
[19:22:47.183] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C11.dat
[19:22:47.183] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C12.dat
[19:22:47.183] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C13.dat
[19:22:47.183] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C14.dat
[19:22:47.183] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C15.dat
[19:22:47.183] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C0.dat
[19:22:47.191] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C1.dat
[19:22:47.199] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C2.dat
[19:22:47.207] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C3.dat
[19:22:47.216] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C4.dat
[19:22:47.224] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C5.dat
[19:22:47.231] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C6.dat
[19:22:47.238] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C7.dat
[19:22:47.245] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C8.dat
[19:22:47.252] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C9.dat
[19:22:47.259] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C10.dat
[19:22:47.266] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C11.dat
[19:22:47.275] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C12.dat
[19:22:47.283] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C13.dat
[19:22:47.292] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C14.dat
[19:22:47.300] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters35_C15.dat
[19:22:47.308] <TB3> INFO: PixTestTrim::trimTest() done
[19:22:47.308] <TB3> INFO: vtrim: 145 140 150 169 121 144 140 143 164 150 129 187 128 132 139 126
[19:22:47.308] <TB3> INFO: vthrcomp: 122 120 131 125 124 133 116 117 127 128 125 121 128 131 119 126
[19:22:47.308] <TB3> INFO: vcal mean: 34.93 34.97 35.00 35.33 34.92 34.90 35.24 35.17 35.03 34.99 35.15 35.25 34.98 34.96 34.93 35.05
[19:22:47.308] <TB3> INFO: vcal RMS: 1.05 1.07 1.16 1.47 1.04 1.18 1.38 1.41 1.26 0.94 1.17 1.55 1.09 1.02 1.03 1.20
[19:22:47.308] <TB3> INFO: bits mean: 10.21 9.34 10.06 10.04 9.85 10.08 9.69 10.21 10.35 9.31 9.30 11.13 9.71 9.46 9.93 9.48
[19:22:47.308] <TB3> INFO: bits RMS: 2.38 2.64 2.43 2.48 2.60 2.37 2.55 2.41 2.45 2.52 2.82 1.93 2.64 2.61 2.51 2.72
[19:22:47.315] <TB3> INFO: ----------------------------------------------------------------------
[19:22:47.315] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[19:22:47.315] <TB3> INFO: ----------------------------------------------------------------------
[19:22:47.318] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[19:22:47.329] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[19:22:47.329] <TB3> INFO: run 1 of 1
[19:22:47.561] <TB3> INFO: Expecting 4160000 events.
[19:23:20.662] <TB3> INFO: 770240 events read in total (32509ms).
[19:23:53.294] <TB3> INFO: 1536855 events read in total (65141ms).
[19:24:25.289] <TB3> INFO: 2297940 events read in total (97136ms).
[19:24:57.532] <TB3> INFO: 3055955 events read in total (129379ms).
[19:25:29.281] <TB3> INFO: 3811995 events read in total (161128ms).
[19:25:43.981] <TB3> INFO: 4160000 events read in total (175828ms).
[19:25:44.026] <TB3> INFO: Test took 176697ms.
[19:26:10.638] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 203 (-1/-1) hits flags = 528 (plus default)
[19:26:10.649] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[19:26:10.649] <TB3> INFO: run 1 of 1
[19:26:10.880] <TB3> INFO: Expecting 4243200 events.
[19:26:43.327] <TB3> INFO: 740255 events read in total (31855ms).
[19:27:14.929] <TB3> INFO: 1477025 events read in total (63457ms).
[19:27:46.383] <TB3> INFO: 2211205 events read in total (94911ms).
[19:28:17.926] <TB3> INFO: 2940520 events read in total (126454ms).
[19:28:49.669] <TB3> INFO: 3668960 events read in total (158197ms).
[19:29:14.370] <TB3> INFO: 4243200 events read in total (182898ms).
[19:29:14.426] <TB3> INFO: Test took 183777ms.
[19:29:44.004] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[19:29:44.015] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[19:29:44.015] <TB3> INFO: run 1 of 1
[19:29:44.247] <TB3> INFO: Expecting 4139200 events.
[19:30:16.928] <TB3> INFO: 747960 events read in total (32089ms).
[19:30:48.702] <TB3> INFO: 1492385 events read in total (63863ms).
[19:31:20.828] <TB3> INFO: 2233520 events read in total (95989ms).
[19:31:52.383] <TB3> INFO: 2970150 events read in total (127544ms).
[19:32:23.841] <TB3> INFO: 3705935 events read in total (159002ms).
[19:32:42.873] <TB3> INFO: 4139200 events read in total (178034ms).
[19:32:42.931] <TB3> INFO: Test took 178916ms.
[19:33:11.021] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[19:33:11.031] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[19:33:11.031] <TB3> INFO: run 1 of 1
[19:33:11.263] <TB3> INFO: Expecting 4139200 events.
[19:33:44.023] <TB3> INFO: 747950 events read in total (32168ms).
[19:34:16.237] <TB3> INFO: 1492500 events read in total (64382ms).
[19:34:48.067] <TB3> INFO: 2233915 events read in total (96212ms).
[19:35:19.642] <TB3> INFO: 2971060 events read in total (127787ms).
[19:35:51.090] <TB3> INFO: 3707270 events read in total (159235ms).
[19:36:09.714] <TB3> INFO: 4139200 events read in total (177859ms).
[19:36:09.761] <TB3> INFO: Test took 178730ms.
[19:36:37.796] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[19:36:37.806] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[19:36:37.806] <TB3> INFO: run 1 of 1
[19:36:38.040] <TB3> INFO: Expecting 4160000 events.
[19:37:10.193] <TB3> INFO: 746845 events read in total (31562ms).
[19:37:41.626] <TB3> INFO: 1490325 events read in total (62995ms).
[19:38:12.910] <TB3> INFO: 2230015 events read in total (94279ms).
[19:38:44.221] <TB3> INFO: 2966100 events read in total (125590ms).
[19:39:15.633] <TB3> INFO: 3701500 events read in total (157002ms).
[19:39:35.239] <TB3> INFO: 4160000 events read in total (176608ms).
[19:39:35.298] <TB3> INFO: Test took 177492ms.
[19:40:03.638] <TB3> INFO: PixTestTrim::trimBitTest() done
[19:40:03.640] <TB3> INFO: PixTestTrim::doTest() done, duration: 2459 seconds
[19:40:03.640] <TB3> INFO: Decoding statistics:
[19:40:03.640] <TB3> INFO: General information:
[19:40:03.640] <TB3> INFO: 16bit words read: 0
[19:40:03.640] <TB3> INFO: valid events total: 0
[19:40:03.640] <TB3> INFO: empty events: 0
[19:40:03.640] <TB3> INFO: valid events with pixels: 0
[19:40:03.640] <TB3> INFO: valid pixel hits: 0
[19:40:03.640] <TB3> INFO: Event errors: 0
[19:40:03.640] <TB3> INFO: start marker: 0
[19:40:03.640] <TB3> INFO: stop marker: 0
[19:40:03.640] <TB3> INFO: overflow: 0
[19:40:03.640] <TB3> INFO: invalid 5bit words: 0
[19:40:03.640] <TB3> INFO: invalid XOR eye diagram: 0
[19:40:03.640] <TB3> INFO: frame (failed synchr.): 0
[19:40:03.640] <TB3> INFO: idle data (no TBM trl): 0
[19:40:03.640] <TB3> INFO: no data (only TBM hdr): 0
[19:40:03.640] <TB3> INFO: TBM errors: 0
[19:40:03.640] <TB3> INFO: flawed TBM headers: 0
[19:40:03.640] <TB3> INFO: flawed TBM trailers: 0
[19:40:03.640] <TB3> INFO: event ID mismatches: 0
[19:40:03.640] <TB3> INFO: ROC errors: 0
[19:40:03.640] <TB3> INFO: missing ROC header(s): 0
[19:40:03.640] <TB3> INFO: misplaced readback start: 0
[19:40:03.640] <TB3> INFO: Pixel decoding errors: 0
[19:40:03.640] <TB3> INFO: pixel data incomplete: 0
[19:40:03.640] <TB3> INFO: pixel address: 0
[19:40:03.640] <TB3> INFO: pulse height fill bit: 0
[19:40:03.640] <TB3> INFO: buffer corruption: 0
[19:40:04.324] <TB3> INFO: ######################################################################
[19:40:04.324] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[19:40:04.324] <TB3> INFO: ######################################################################
[19:40:04.602] <TB3> INFO: Expecting 41600 events.
[19:40:08.159] <TB3> INFO: 41600 events read in total (2966ms).
[19:40:08.160] <TB3> INFO: Test took 3835ms.
[19:40:08.621] <TB3> INFO: Expecting 41600 events.
[19:40:12.259] <TB3> INFO: 41600 events read in total (3047ms).
[19:40:12.259] <TB3> INFO: Test took 3895ms.
[19:40:12.547] <TB3> INFO: Expecting 41600 events.
[19:40:16.109] <TB3> INFO: 41600 events read in total (2970ms).
[19:40:16.110] <TB3> INFO: Test took 3827ms.
[19:40:16.441] <TB3> INFO: Expecting 41600 events.
[19:40:19.996] <TB3> INFO: 41600 events read in total (2963ms).
[19:40:19.997] <TB3> INFO: Test took 3859ms.
[19:40:20.285] <TB3> INFO: Expecting 41600 events.
[19:40:23.864] <TB3> INFO: 41600 events read in total (2987ms).
[19:40:23.866] <TB3> INFO: Test took 3845ms.
[19:40:24.159] <TB3> INFO: Expecting 41600 events.
[19:40:27.801] <TB3> INFO: 41600 events read in total (3050ms).
[19:40:27.802] <TB3> INFO: Test took 3908ms.
[19:40:28.095] <TB3> INFO: Expecting 41600 events.
[19:40:31.627] <TB3> INFO: 41600 events read in total (2940ms).
[19:40:31.628] <TB3> INFO: Test took 3798ms.
[19:40:31.917] <TB3> INFO: Expecting 41600 events.
[19:40:35.375] <TB3> INFO: 41600 events read in total (2866ms).
[19:40:35.376] <TB3> INFO: Test took 3724ms.
[19:40:35.666] <TB3> INFO: Expecting 41600 events.
[19:40:39.179] <TB3> INFO: 41600 events read in total (2921ms).
[19:40:39.180] <TB3> INFO: Test took 3778ms.
[19:40:39.468] <TB3> INFO: Expecting 41600 events.
[19:40:42.916] <TB3> INFO: 41600 events read in total (2857ms).
[19:40:42.917] <TB3> INFO: Test took 3714ms.
[19:40:43.215] <TB3> INFO: Expecting 41600 events.
[19:40:46.758] <TB3> INFO: 41600 events read in total (2951ms).
[19:40:46.759] <TB3> INFO: Test took 3819ms.
[19:40:47.047] <TB3> INFO: Expecting 41600 events.
[19:40:50.610] <TB3> INFO: 41600 events read in total (2971ms).
[19:40:50.611] <TB3> INFO: Test took 3829ms.
[19:40:50.906] <TB3> INFO: Expecting 41600 events.
[19:40:54.356] <TB3> INFO: 41600 events read in total (2859ms).
[19:40:54.356] <TB3> INFO: Test took 3722ms.
[19:40:54.645] <TB3> INFO: Expecting 41600 events.
[19:40:58.175] <TB3> INFO: 41600 events read in total (2940ms).
[19:40:58.176] <TB3> INFO: Test took 3796ms.
[19:40:58.464] <TB3> INFO: Expecting 41600 events.
[19:41:01.980] <TB3> INFO: 41600 events read in total (2922ms).
[19:41:01.981] <TB3> INFO: Test took 3781ms.
[19:41:02.269] <TB3> INFO: Expecting 41600 events.
[19:41:05.871] <TB3> INFO: 41600 events read in total (3011ms).
[19:41:05.872] <TB3> INFO: Test took 3868ms.
[19:41:06.162] <TB3> INFO: Expecting 41600 events.
[19:41:09.618] <TB3> INFO: 41600 events read in total (2864ms).
[19:41:09.619] <TB3> INFO: Test took 3721ms.
[19:41:09.907] <TB3> INFO: Expecting 41600 events.
[19:41:13.415] <TB3> INFO: 41600 events read in total (2916ms).
[19:41:13.416] <TB3> INFO: Test took 3774ms.
[19:41:13.705] <TB3> INFO: Expecting 41600 events.
[19:41:17.156] <TB3> INFO: 41600 events read in total (2860ms).
[19:41:17.156] <TB3> INFO: Test took 3716ms.
[19:41:17.445] <TB3> INFO: Expecting 41600 events.
[19:41:20.951] <TB3> INFO: 41600 events read in total (2915ms).
[19:41:20.952] <TB3> INFO: Test took 3772ms.
[19:41:21.242] <TB3> INFO: Expecting 41600 events.
[19:41:24.890] <TB3> INFO: 41600 events read in total (3056ms).
[19:41:24.891] <TB3> INFO: Test took 3914ms.
[19:41:25.179] <TB3> INFO: Expecting 41600 events.
[19:41:28.682] <TB3> INFO: 41600 events read in total (2911ms).
[19:41:28.683] <TB3> INFO: Test took 3769ms.
[19:41:28.982] <TB3> INFO: Expecting 41600 events.
[19:41:32.553] <TB3> INFO: 41600 events read in total (2979ms).
[19:41:32.554] <TB3> INFO: Test took 3846ms.
[19:41:32.842] <TB3> INFO: Expecting 41600 events.
[19:41:36.335] <TB3> INFO: 41600 events read in total (2901ms).
[19:41:36.336] <TB3> INFO: Test took 3759ms.
[19:41:36.625] <TB3> INFO: Expecting 41600 events.
[19:41:40.120] <TB3> INFO: 41600 events read in total (2904ms).
[19:41:40.120] <TB3> INFO: Test took 3760ms.
[19:41:40.417] <TB3> INFO: Expecting 41600 events.
[19:41:43.882] <TB3> INFO: 41600 events read in total (2873ms).
[19:41:43.883] <TB3> INFO: Test took 3738ms.
[19:41:44.175] <TB3> INFO: Expecting 2560 events.
[19:41:45.059] <TB3> INFO: 2560 events read in total (292ms).
[19:41:45.059] <TB3> INFO: Test took 1161ms.
[19:41:45.368] <TB3> INFO: Expecting 2560 events.
[19:41:46.250] <TB3> INFO: 2560 events read in total (291ms).
[19:41:46.251] <TB3> INFO: Test took 1191ms.
[19:41:46.559] <TB3> INFO: Expecting 2560 events.
[19:41:47.442] <TB3> INFO: 2560 events read in total (292ms).
[19:41:47.443] <TB3> INFO: Test took 1192ms.
[19:41:47.750] <TB3> INFO: Expecting 2560 events.
[19:41:48.634] <TB3> INFO: 2560 events read in total (292ms).
[19:41:48.634] <TB3> INFO: Test took 1191ms.
[19:41:48.942] <TB3> INFO: Expecting 2560 events.
[19:41:49.820] <TB3> INFO: 2560 events read in total (286ms).
[19:41:49.820] <TB3> INFO: Test took 1185ms.
[19:41:50.129] <TB3> INFO: Expecting 2560 events.
[19:41:51.010] <TB3> INFO: 2560 events read in total (290ms).
[19:41:51.010] <TB3> INFO: Test took 1189ms.
[19:41:51.318] <TB3> INFO: Expecting 2560 events.
[19:41:52.199] <TB3> INFO: 2560 events read in total (290ms).
[19:41:52.199] <TB3> INFO: Test took 1188ms.
[19:41:52.507] <TB3> INFO: Expecting 2560 events.
[19:41:53.386] <TB3> INFO: 2560 events read in total (288ms).
[19:41:53.386] <TB3> INFO: Test took 1186ms.
[19:41:53.694] <TB3> INFO: Expecting 2560 events.
[19:41:54.573] <TB3> INFO: 2560 events read in total (287ms).
[19:41:54.574] <TB3> INFO: Test took 1187ms.
[19:41:54.882] <TB3> INFO: Expecting 2560 events.
[19:41:55.761] <TB3> INFO: 2560 events read in total (288ms).
[19:41:55.761] <TB3> INFO: Test took 1187ms.
[19:41:56.068] <TB3> INFO: Expecting 2560 events.
[19:41:56.951] <TB3> INFO: 2560 events read in total (291ms).
[19:41:56.951] <TB3> INFO: Test took 1189ms.
[19:41:57.259] <TB3> INFO: Expecting 2560 events.
[19:41:58.140] <TB3> INFO: 2560 events read in total (289ms).
[19:41:58.140] <TB3> INFO: Test took 1189ms.
[19:41:58.448] <TB3> INFO: Expecting 2560 events.
[19:41:59.333] <TB3> INFO: 2560 events read in total (294ms).
[19:41:59.333] <TB3> INFO: Test took 1193ms.
[19:41:59.641] <TB3> INFO: Expecting 2560 events.
[19:42:00.524] <TB3> INFO: 2560 events read in total (291ms).
[19:42:00.525] <TB3> INFO: Test took 1191ms.
[19:42:00.832] <TB3> INFO: Expecting 2560 events.
[19:42:01.719] <TB3> INFO: 2560 events read in total (295ms).
[19:42:01.719] <TB3> INFO: Test took 1194ms.
[19:42:02.027] <TB3> INFO: Expecting 2560 events.
[19:42:02.912] <TB3> INFO: 2560 events read in total (293ms).
[19:42:02.913] <TB3> INFO: Test took 1193ms.
[19:42:02.915] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:42:03.222] <TB3> INFO: Expecting 655360 events.
[19:42:17.659] <TB3> INFO: 655360 events read in total (13846ms).
[19:42:17.673] <TB3> INFO: Expecting 655360 events.
[19:42:31.866] <TB3> INFO: 655360 events read in total (13790ms).
[19:42:31.880] <TB3> INFO: Expecting 655360 events.
[19:42:46.102] <TB3> INFO: 655360 events read in total (13819ms).
[19:42:46.121] <TB3> INFO: Expecting 655360 events.
[19:43:00.304] <TB3> INFO: 655360 events read in total (13780ms).
[19:43:00.327] <TB3> INFO: Expecting 655360 events.
[19:43:14.641] <TB3> INFO: 655360 events read in total (13911ms).
[19:43:14.668] <TB3> INFO: Expecting 655360 events.
[19:43:28.000] <TB3> INFO: 655360 events read in total (13929ms).
[19:43:29.040] <TB3> INFO: Expecting 655360 events.
[19:43:43.299] <TB3> INFO: 655360 events read in total (13856ms).
[19:43:43.336] <TB3> INFO: Expecting 655360 events.
[19:43:57.532] <TB3> INFO: 655360 events read in total (13793ms).
[19:43:57.573] <TB3> INFO: Expecting 655360 events.
[19:44:11.916] <TB3> INFO: 655360 events read in total (13940ms).
[19:44:11.961] <TB3> INFO: Expecting 655360 events.
[19:44:26.317] <TB3> INFO: 655360 events read in total (13953ms).
[19:44:26.366] <TB3> INFO: Expecting 655360 events.
[19:44:40.622] <TB3> INFO: 655360 events read in total (13854ms).
[19:44:40.676] <TB3> INFO: Expecting 655360 events.
[19:44:54.943] <TB3> INFO: 655360 events read in total (13864ms).
[19:44:54.002] <TB3> INFO: Expecting 655360 events.
[19:45:09.171] <TB3> INFO: 655360 events read in total (13766ms).
[19:45:09.232] <TB3> INFO: Expecting 655360 events.
[19:45:23.432] <TB3> INFO: 655360 events read in total (13797ms).
[19:45:23.498] <TB3> INFO: Expecting 655360 events.
[19:45:37.811] <TB3> INFO: 655360 events read in total (13910ms).
[19:45:37.881] <TB3> INFO: Expecting 655360 events.
[19:45:52.095] <TB3> INFO: 655360 events read in total (13811ms).
[19:45:52.169] <TB3> INFO: Test took 229254ms.
[19:45:52.247] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:45:52.512] <TB3> INFO: Expecting 655360 events.
[19:46:06.946] <TB3> INFO: 655360 events read in total (13842ms).
[19:46:06.957] <TB3> INFO: Expecting 655360 events.
[19:46:21.137] <TB3> INFO: 655360 events read in total (13777ms).
[19:46:21.152] <TB3> INFO: Expecting 655360 events.
[19:46:35.242] <TB3> INFO: 655360 events read in total (13687ms).
[19:46:35.260] <TB3> INFO: Expecting 655360 events.
[19:46:49.121] <TB3> INFO: 655360 events read in total (13458ms).
[19:46:49.143] <TB3> INFO: Expecting 655360 events.
[19:47:03.128] <TB3> INFO: 655360 events read in total (13583ms).
[19:47:03.156] <TB3> INFO: Expecting 655360 events.
[19:47:17.241] <TB3> INFO: 655360 events read in total (13683ms).
[19:47:17.271] <TB3> INFO: Expecting 655360 events.
[19:47:31.224] <TB3> INFO: 655360 events read in total (13550ms).
[19:47:31.262] <TB3> INFO: Expecting 655360 events.
[19:47:45.354] <TB3> INFO: 655360 events read in total (13689ms).
[19:47:45.393] <TB3> INFO: Expecting 655360 events.
[19:47:59.474] <TB3> INFO: 655360 events read in total (13678ms).
[19:47:59.520] <TB3> INFO: Expecting 655360 events.
[19:48:13.588] <TB3> INFO: 655360 events read in total (13665ms).
[19:48:13.637] <TB3> INFO: Expecting 655360 events.
[19:48:27.656] <TB3> INFO: 655360 events read in total (13616ms).
[19:48:27.709] <TB3> INFO: Expecting 655360 events.
[19:48:41.796] <TB3> INFO: 655360 events read in total (13684ms).
[19:48:41.854] <TB3> INFO: Expecting 655360 events.
[19:48:55.973] <TB3> INFO: 655360 events read in total (13716ms).
[19:48:56.055] <TB3> INFO: Expecting 655360 events.
[19:49:10.119] <TB3> INFO: 655360 events read in total (13661ms).
[19:49:10.186] <TB3> INFO: Expecting 655360 events.
[19:49:24.282] <TB3> INFO: 655360 events read in total (13693ms).
[19:49:24.376] <TB3> INFO: Expecting 655360 events.
[19:49:38.420] <TB3> INFO: 655360 events read in total (13641ms).
[19:49:38.493] <TB3> INFO: Test took 226246ms.
[19:49:38.650] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.655] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.662] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.669] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:49:38.676] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.682] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:49:38.689] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[19:49:38.696] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[19:49:38.702] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[19:49:38.708] <TB3> INFO: safety margin for low PH: adding 5, margin is now 25
[19:49:38.715] <TB3> INFO: safety margin for low PH: adding 6, margin is now 26
[19:49:38.721] <TB3> INFO: safety margin for low PH: adding 7, margin is now 27
[19:49:38.728] <TB3> INFO: safety margin for low PH: adding 8, margin is now 28
[19:49:38.735] <TB3> INFO: safety margin for low PH: adding 9, margin is now 29
[19:49:38.741] <TB3> INFO: safety margin for low PH: adding 10, margin is now 30
[19:49:38.748] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.755] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:49:38.761] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.768] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:49:38.775] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[19:49:38.782] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.789] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.797] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:49:38.804] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[19:49:38.810] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[19:49:38.817] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.825] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.831] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.838] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.846] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.854] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.862] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.868] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[19:49:38.875] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[19:49:38.881] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[19:49:38.915] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C0.dat
[19:49:38.915] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C1.dat
[19:49:38.915] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C2.dat
[19:49:38.915] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C3.dat
[19:49:38.915] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C4.dat
[19:49:38.915] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C5.dat
[19:49:38.916] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C6.dat
[19:49:38.916] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C7.dat
[19:49:38.916] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C8.dat
[19:49:38.916] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C9.dat
[19:49:38.916] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C10.dat
[19:49:38.916] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C11.dat
[19:49:38.916] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C12.dat
[19:49:38.916] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C13.dat
[19:49:38.916] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C14.dat
[19:49:38.917] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters35_C15.dat
[19:49:39.174] <TB3> INFO: Expecting 41600 events.
[19:49:42.274] <TB3> INFO: 41600 events read in total (2508ms).
[19:49:42.275] <TB3> INFO: Test took 3356ms.
[19:49:42.716] <TB3> INFO: Expecting 41600 events.
[19:49:45.745] <TB3> INFO: 41600 events read in total (2438ms).
[19:49:45.745] <TB3> INFO: Test took 3260ms.
[19:49:46.188] <TB3> INFO: Expecting 41600 events.
[19:49:49.304] <TB3> INFO: 41600 events read in total (2524ms).
[19:49:49.305] <TB3> INFO: Test took 3349ms.
[19:49:49.520] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:49:49.608] <TB3> INFO: Expecting 2560 events.
[19:49:50.490] <TB3> INFO: 2560 events read in total (290ms).
[19:49:50.491] <TB3> INFO: Test took 971ms.
[19:49:50.492] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:49:50.799] <TB3> INFO: Expecting 2560 events.
[19:49:51.682] <TB3> INFO: 2560 events read in total (291ms).
[19:49:51.682] <TB3> INFO: Test took 1190ms.
[19:49:51.684] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:49:51.991] <TB3> INFO: Expecting 2560 events.
[19:49:52.878] <TB3> INFO: 2560 events read in total (296ms).
[19:49:52.878] <TB3> INFO: Test took 1194ms.
[19:49:52.880] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:49:53.186] <TB3> INFO: Expecting 2560 events.
[19:49:54.070] <TB3> INFO: 2560 events read in total (292ms).
[19:49:54.070] <TB3> INFO: Test took 1190ms.
[19:49:54.072] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:49:54.378] <TB3> INFO: Expecting 2560 events.
[19:49:55.262] <TB3> INFO: 2560 events read in total (292ms).
[19:49:55.262] <TB3> INFO: Test took 1190ms.
[19:49:55.265] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:49:55.571] <TB3> INFO: Expecting 2560 events.
[19:49:56.456] <TB3> INFO: 2560 events read in total (294ms).
[19:49:56.456] <TB3> INFO: Test took 1191ms.
[19:49:56.458] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:49:56.765] <TB3> INFO: Expecting 2560 events.
[19:49:57.647] <TB3> INFO: 2560 events read in total (291ms).
[19:49:57.647] <TB3> INFO: Test took 1189ms.
[19:49:57.649] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:49:57.956] <TB3> INFO: Expecting 2560 events.
[19:49:58.839] <TB3> INFO: 2560 events read in total (292ms).
[19:49:58.839] <TB3> INFO: Test took 1190ms.
[19:49:58.841] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:49:59.147] <TB3> INFO: Expecting 2560 events.
[19:50:00.026] <TB3> INFO: 2560 events read in total (287ms).
[19:50:00.026] <TB3> INFO: Test took 1185ms.
[19:50:00.028] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:00.334] <TB3> INFO: Expecting 2560 events.
[19:50:01.212] <TB3> INFO: 2560 events read in total (286ms).
[19:50:01.212] <TB3> INFO: Test took 1184ms.
[19:50:01.214] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:01.521] <TB3> INFO: Expecting 2560 events.
[19:50:02.400] <TB3> INFO: 2560 events read in total (288ms).
[19:50:02.401] <TB3> INFO: Test took 1187ms.
[19:50:02.403] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:02.709] <TB3> INFO: Expecting 2560 events.
[19:50:03.589] <TB3> INFO: 2560 events read in total (289ms).
[19:50:03.589] <TB3> INFO: Test took 1186ms.
[19:50:03.591] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:03.897] <TB3> INFO: Expecting 2560 events.
[19:50:04.775] <TB3> INFO: 2560 events read in total (286ms).
[19:50:04.775] <TB3> INFO: Test took 1184ms.
[19:50:04.776] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:05.084] <TB3> INFO: Expecting 2560 events.
[19:50:05.962] <TB3> INFO: 2560 events read in total (287ms).
[19:50:05.963] <TB3> INFO: Test took 1187ms.
[19:50:05.965] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:06.271] <TB3> INFO: Expecting 2560 events.
[19:50:07.153] <TB3> INFO: 2560 events read in total (291ms).
[19:50:07.153] <TB3> INFO: Test took 1188ms.
[19:50:07.155] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:07.461] <TB3> INFO: Expecting 2560 events.
[19:50:08.340] <TB3> INFO: 2560 events read in total (287ms).
[19:50:08.341] <TB3> INFO: Test took 1186ms.
[19:50:08.343] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:08.649] <TB3> INFO: Expecting 2560 events.
[19:50:09.529] <TB3> INFO: 2560 events read in total (288ms).
[19:50:09.530] <TB3> INFO: Test took 1187ms.
[19:50:09.531] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:09.838] <TB3> INFO: Expecting 2560 events.
[19:50:10.718] <TB3> INFO: 2560 events read in total (288ms).
[19:50:10.718] <TB3> INFO: Test took 1187ms.
[19:50:10.721] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:11.026] <TB3> INFO: Expecting 2560 events.
[19:50:11.905] <TB3> INFO: 2560 events read in total (287ms).
[19:50:11.905] <TB3> INFO: Test took 1184ms.
[19:50:11.907] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:12.214] <TB3> INFO: Expecting 2560 events.
[19:50:13.092] <TB3> INFO: 2560 events read in total (287ms).
[19:50:13.092] <TB3> INFO: Test took 1185ms.
[19:50:13.094] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:13.401] <TB3> INFO: Expecting 2560 events.
[19:50:14.280] <TB3> INFO: 2560 events read in total (288ms).
[19:50:14.280] <TB3> INFO: Test took 1186ms.
[19:50:14.282] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:14.588] <TB3> INFO: Expecting 2560 events.
[19:50:15.469] <TB3> INFO: 2560 events read in total (289ms).
[19:50:15.469] <TB3> INFO: Test took 1187ms.
[19:50:15.471] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:15.778] <TB3> INFO: Expecting 2560 events.
[19:50:16.657] <TB3> INFO: 2560 events read in total (288ms).
[19:50:16.658] <TB3> INFO: Test took 1187ms.
[19:50:16.660] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:16.966] <TB3> INFO: Expecting 2560 events.
[19:50:17.849] <TB3> INFO: 2560 events read in total (292ms).
[19:50:17.849] <TB3> INFO: Test took 1189ms.
[19:50:17.851] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:18.158] <TB3> INFO: Expecting 2560 events.
[19:50:19.041] <TB3> INFO: 2560 events read in total (292ms).
[19:50:19.041] <TB3> INFO: Test took 1190ms.
[19:50:19.043] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:19.350] <TB3> INFO: Expecting 2560 events.
[19:50:20.234] <TB3> INFO: 2560 events read in total (292ms).
[19:50:20.234] <TB3> INFO: Test took 1191ms.
[19:50:20.236] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:20.543] <TB3> INFO: Expecting 2560 events.
[19:50:21.427] <TB3> INFO: 2560 events read in total (293ms).
[19:50:21.427] <TB3> INFO: Test took 1191ms.
[19:50:21.429] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:21.736] <TB3> INFO: Expecting 2560 events.
[19:50:22.621] <TB3> INFO: 2560 events read in total (294ms).
[19:50:22.622] <TB3> INFO: Test took 1193ms.
[19:50:22.623] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:22.930] <TB3> INFO: Expecting 2560 events.
[19:50:23.814] <TB3> INFO: 2560 events read in total (292ms).
[19:50:23.814] <TB3> INFO: Test took 1191ms.
[19:50:23.816] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:24.123] <TB3> INFO: Expecting 2560 events.
[19:50:25.007] <TB3> INFO: 2560 events read in total (293ms).
[19:50:25.007] <TB3> INFO: Test took 1191ms.
[19:50:25.009] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:25.315] <TB3> INFO: Expecting 2560 events.
[19:50:26.201] <TB3> INFO: 2560 events read in total (294ms).
[19:50:26.201] <TB3> INFO: Test took 1192ms.
[19:50:26.203] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[19:50:26.509] <TB3> INFO: Expecting 2560 events.
[19:50:27.395] <TB3> INFO: 2560 events read in total (294ms).
[19:50:27.395] <TB3> INFO: Test took 1193ms.
[19:50:27.857] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 623 seconds
[19:50:27.857] <TB3> INFO: PH scale (per ROC): 42 58 40 38 46 34 31 46 35 37 47 54 34 56 55 48
[19:50:27.857] <TB3> INFO: PH offset (per ROC): 104 125 109 110 94 91 99 125 105 110 135 126 101 126 117 123
[19:50:27.862] <TB3> INFO: Decoding statistics:
[19:50:27.862] <TB3> INFO: General information:
[19:50:27.862] <TB3> INFO: 16bit words read: 127896
[19:50:27.862] <TB3> INFO: valid events total: 20480
[19:50:27.862] <TB3> INFO: empty events: 17972
[19:50:27.862] <TB3> INFO: valid events with pixels: 2508
[19:50:27.862] <TB3> INFO: valid pixel hits: 2508
[19:50:27.862] <TB3> INFO: Event errors: 0
[19:50:27.862] <TB3> INFO: start marker: 0
[19:50:27.862] <TB3> INFO: stop marker: 0
[19:50:27.862] <TB3> INFO: overflow: 0
[19:50:27.862] <TB3> INFO: invalid 5bit words: 0
[19:50:27.862] <TB3> INFO: invalid XOR eye diagram: 0
[19:50:27.862] <TB3> INFO: frame (failed synchr.): 0
[19:50:27.862] <TB3> INFO: idle data (no TBM trl): 0
[19:50:27.862] <TB3> INFO: no data (only TBM hdr): 0
[19:50:27.862] <TB3> INFO: TBM errors: 0
[19:50:27.862] <TB3> INFO: flawed TBM headers: 0
[19:50:27.862] <TB3> INFO: flawed TBM trailers: 0
[19:50:27.862] <TB3> INFO: event ID mismatches: 0
[19:50:27.862] <TB3> INFO: ROC errors: 0
[19:50:27.862] <TB3> INFO: missing ROC header(s): 0
[19:50:27.862] <TB3> INFO: misplaced readback start: 0
[19:50:27.862] <TB3> INFO: Pixel decoding errors: 0
[19:50:27.862] <TB3> INFO: pixel data incomplete: 0
[19:50:27.862] <TB3> INFO: pixel address: 0
[19:50:27.862] <TB3> INFO: pulse height fill bit: 0
[19:50:27.862] <TB3> INFO: buffer corruption: 0
[19:50:28.126] <TB3> INFO: ######################################################################
[19:50:28.126] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[19:50:28.126] <TB3> INFO: ######################################################################
[19:50:28.138] <TB3> INFO: scanning low vcal = 10
[19:50:28.371] <TB3> INFO: Expecting 41600 events.
[19:50:31.923] <TB3> INFO: 41600 events read in total (2961ms).
[19:50:31.924] <TB3> INFO: Test took 3786ms.
[19:50:31.925] <TB3> INFO: scanning low vcal = 20
[19:50:32.225] <TB3> INFO: Expecting 41600 events.
[19:50:35.816] <TB3> INFO: 41600 events read in total (3000ms).
[19:50:35.816] <TB3> INFO: Test took 3891ms.
[19:50:35.817] <TB3> INFO: scanning low vcal = 30
[19:50:36.114] <TB3> INFO: Expecting 41600 events.
[19:50:39.747] <TB3> INFO: 41600 events read in total (3041ms).
[19:50:39.748] <TB3> INFO: Test took 3930ms.
[19:50:39.751] <TB3> INFO: scanning low vcal = 40
[19:50:40.031] <TB3> INFO: Expecting 41600 events.
[19:50:43.936] <TB3> INFO: 41600 events read in total (3314ms).
[19:50:43.937] <TB3> INFO: Test took 4186ms.
[19:50:43.939] <TB3> INFO: scanning low vcal = 50
[19:50:44.216] <TB3> INFO: Expecting 41600 events.
[19:50:48.165] <TB3> INFO: 41600 events read in total (3358ms).
[19:50:48.166] <TB3> INFO: Test took 4227ms.
[19:50:48.168] <TB3> INFO: scanning low vcal = 60
[19:50:48.445] <TB3> INFO: Expecting 41600 events.
[19:50:52.408] <TB3> INFO: 41600 events read in total (3371ms).
[19:50:52.409] <TB3> INFO: Test took 4240ms.
[19:50:52.411] <TB3> INFO: scanning low vcal = 70
[19:50:52.688] <TB3> INFO: Expecting 41600 events.
[19:50:56.661] <TB3> INFO: 41600 events read in total (3382ms).
[19:50:56.662] <TB3> INFO: Test took 4251ms.
[19:50:56.664] <TB3> INFO: scanning low vcal = 80
[19:50:56.941] <TB3> INFO: Expecting 41600 events.
[19:51:00.883] <TB3> INFO: 41600 events read in total (3350ms).
[19:51:00.884] <TB3> INFO: Test took 4219ms.
[19:51:00.887] <TB3> INFO: scanning low vcal = 90
[19:51:01.163] <TB3> INFO: Expecting 41600 events.
[19:51:05.101] <TB3> INFO: 41600 events read in total (3346ms).
[19:51:05.102] <TB3> INFO: Test took 4215ms.
[19:51:05.104] <TB3> INFO: scanning low vcal = 100
[19:51:05.381] <TB3> INFO: Expecting 41600 events.
[19:51:09.332] <TB3> INFO: 41600 events read in total (3360ms).
[19:51:09.333] <TB3> INFO: Test took 4229ms.
[19:51:09.335] <TB3> INFO: scanning low vcal = 110
[19:51:09.612] <TB3> INFO: Expecting 41600 events.
[19:51:13.536] <TB3> INFO: 41600 events read in total (3333ms).
[19:51:13.537] <TB3> INFO: Test took 4202ms.
[19:51:13.539] <TB3> INFO: scanning low vcal = 120
[19:51:13.816] <TB3> INFO: Expecting 41600 events.
[19:51:17.827] <TB3> INFO: 41600 events read in total (3420ms).
[19:51:17.828] <TB3> INFO: Test took 4289ms.
[19:51:17.830] <TB3> INFO: scanning low vcal = 130
[19:51:18.107] <TB3> INFO: Expecting 41600 events.
[19:51:22.100] <TB3> INFO: 41600 events read in total (3401ms).
[19:51:22.101] <TB3> INFO: Test took 4270ms.
[19:51:22.104] <TB3> INFO: scanning low vcal = 140
[19:51:22.380] <TB3> INFO: Expecting 41600 events.
[19:51:26.355] <TB3> INFO: 41600 events read in total (3383ms).
[19:51:26.356] <TB3> INFO: Test took 4252ms.
[19:51:26.358] <TB3> INFO: scanning low vcal = 150
[19:51:26.635] <TB3> INFO: Expecting 41600 events.
[19:51:30.625] <TB3> INFO: 41600 events read in total (3398ms).
[19:51:30.626] <TB3> INFO: Test took 4268ms.
[19:51:30.629] <TB3> INFO: scanning low vcal = 160
[19:51:30.905] <TB3> INFO: Expecting 41600 events.
[19:51:34.863] <TB3> INFO: 41600 events read in total (3366ms).
[19:51:34.863] <TB3> INFO: Test took 4234ms.
[19:51:34.866] <TB3> INFO: scanning low vcal = 170
[19:51:35.142] <TB3> INFO: Expecting 41600 events.
[19:51:39.096] <TB3> INFO: 41600 events read in total (3362ms).
[19:51:39.097] <TB3> INFO: Test took 4231ms.
[19:51:39.099] <TB3> INFO: scanning low vcal = 180
[19:51:39.376] <TB3> INFO: Expecting 41600 events.
[19:51:43.299] <TB3> INFO: 41600 events read in total (3331ms).
[19:51:43.300] <TB3> INFO: Test took 4201ms.
[19:51:43.302] <TB3> INFO: scanning low vcal = 190
[19:51:43.579] <TB3> INFO: Expecting 41600 events.
[19:51:47.520] <TB3> INFO: 41600 events read in total (3349ms).
[19:51:47.521] <TB3> INFO: Test took 4219ms.
[19:51:47.523] <TB3> INFO: scanning low vcal = 200
[19:51:47.800] <TB3> INFO: Expecting 41600 events.
[19:51:51.742] <TB3> INFO: 41600 events read in total (3351ms).
[19:51:51.742] <TB3> INFO: Test took 4220ms.
[19:51:51.745] <TB3> INFO: scanning low vcal = 210
[19:51:52.022] <TB3> INFO: Expecting 41600 events.
[19:51:55.985] <TB3> INFO: 41600 events read in total (3372ms).
[19:51:55.985] <TB3> INFO: Test took 4240ms.
[19:51:55.988] <TB3> INFO: scanning low vcal = 220
[19:51:56.265] <TB3> INFO: Expecting 41600 events.
[19:52:00.272] <TB3> INFO: 41600 events read in total (3416ms).
[19:52:00.273] <TB3> INFO: Test took 4285ms.
[19:52:00.275] <TB3> INFO: scanning low vcal = 230
[19:52:00.552] <TB3> INFO: Expecting 41600 events.
[19:52:04.532] <TB3> INFO: 41600 events read in total (3388ms).
[19:52:04.532] <TB3> INFO: Test took 4257ms.
[19:52:04.535] <TB3> INFO: scanning low vcal = 240
[19:52:04.812] <TB3> INFO: Expecting 41600 events.
[19:52:08.777] <TB3> INFO: 41600 events read in total (3373ms).
[19:52:08.778] <TB3> INFO: Test took 4242ms.
[19:52:08.780] <TB3> INFO: scanning low vcal = 250
[19:52:09.057] <TB3> INFO: Expecting 41600 events.
[19:52:13.012] <TB3> INFO: 41600 events read in total (3363ms).
[19:52:13.013] <TB3> INFO: Test took 4232ms.
[19:52:13.017] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[19:52:13.292] <TB3> INFO: Expecting 41600 events.
[19:52:17.273] <TB3> INFO: 41600 events read in total (3389ms).
[19:52:17.274] <TB3> INFO: Test took 4257ms.
[19:52:17.276] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[19:52:17.553] <TB3> INFO: Expecting 41600 events.
[19:52:21.473] <TB3> INFO: 41600 events read in total (3329ms).
[19:52:21.474] <TB3> INFO: Test took 4198ms.
[19:52:21.477] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[19:52:21.753] <TB3> INFO: Expecting 41600 events.
[19:52:25.677] <TB3> INFO: 41600 events read in total (3332ms).
[19:52:25.678] <TB3> INFO: Test took 4201ms.
[19:52:25.681] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[19:52:25.957] <TB3> INFO: Expecting 41600 events.
[19:52:29.924] <TB3> INFO: 41600 events read in total (3375ms).
[19:52:29.925] <TB3> INFO: Test took 4244ms.
[19:52:29.928] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[19:52:30.204] <TB3> INFO: Expecting 41600 events.
[19:52:34.168] <TB3> INFO: 41600 events read in total (3372ms).
[19:52:34.169] <TB3> INFO: Test took 4241ms.
[19:52:34.630] <TB3> INFO: PixTestGainPedestal::measure() done
[19:53:15.271] <TB3> INFO: PixTestGainPedestal::fit() done
[19:53:15.271] <TB3> INFO: non-linearity mean: 0.929 0.985 0.927 0.926 0.972 1.005 0.993 0.982 0.941 0.911 0.980 0.982 0.977 0.981 0.981 0.981
[19:53:15.272] <TB3> INFO: non-linearity RMS: 0.072 0.003 0.083 0.137 0.011 0.179 0.192 0.003 0.158 0.092 0.005 0.003 0.163 0.003 0.004 0.004
[19:53:15.272] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C0.dat
[19:53:15.287] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C1.dat
[19:53:15.302] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C2.dat
[19:53:15.317] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C3.dat
[19:53:15.332] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C4.dat
[19:53:15.347] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C5.dat
[19:53:15.361] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C6.dat
[19:53:15.376] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C7.dat
[19:53:15.391] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C8.dat
[19:53:15.406] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C9.dat
[19:53:15.421] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C10.dat
[19:53:15.435] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C11.dat
[19:53:15.451] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C12.dat
[19:53:15.466] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C13.dat
[19:53:15.482] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C14.dat
[19:53:15.497] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//phCalibrationFitErr35_C15.dat
[19:53:15.512] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 167 seconds
[19:53:15.512] <TB3> INFO: Decoding statistics:
[19:53:15.512] <TB3> INFO: General information:
[19:53:15.512] <TB3> INFO: 16bit words read: 3297914
[19:53:15.512] <TB3> INFO: valid events total: 332800
[19:53:15.512] <TB3> INFO: empty events: 77
[19:53:15.512] <TB3> INFO: valid events with pixels: 332723
[19:53:15.512] <TB3> INFO: valid pixel hits: 650557
[19:53:15.512] <TB3> INFO: Event errors: 0
[19:53:15.512] <TB3> INFO: start marker: 0
[19:53:15.512] <TB3> INFO: stop marker: 0
[19:53:15.512] <TB3> INFO: overflow: 0
[19:53:15.512] <TB3> INFO: invalid 5bit words: 0
[19:53:15.512] <TB3> INFO: invalid XOR eye diagram: 0
[19:53:15.512] <TB3> INFO: frame (failed synchr.): 0
[19:53:15.512] <TB3> INFO: idle data (no TBM trl): 0
[19:53:15.512] <TB3> INFO: no data (only TBM hdr): 0
[19:53:15.512] <TB3> INFO: TBM errors: 0
[19:53:15.512] <TB3> INFO: flawed TBM headers: 0
[19:53:15.512] <TB3> INFO: flawed TBM trailers: 0
[19:53:15.512] <TB3> INFO: event ID mismatches: 0
[19:53:15.512] <TB3> INFO: ROC errors: 0
[19:53:15.512] <TB3> INFO: missing ROC header(s): 0
[19:53:15.512] <TB3> INFO: misplaced readback start: 0
[19:53:15.512] <TB3> INFO: Pixel decoding errors: 0
[19:53:15.512] <TB3> INFO: pixel data incomplete: 0
[19:53:15.512] <TB3> INFO: pixel address: 0
[19:53:15.512] <TB3> INFO: pulse height fill bit: 0
[19:53:15.512] <TB3> INFO: buffer corruption: 0
[19:53:15.527] <TB3> INFO: Decoding statistics:
[19:53:15.527] <TB3> INFO: General information:
[19:53:15.527] <TB3> INFO: 16bit words read: 3427346
[19:53:15.527] <TB3> INFO: valid events total: 353536
[19:53:15.527] <TB3> INFO: empty events: 18305
[19:53:15.527] <TB3> INFO: valid events with pixels: 335231
[19:53:15.527] <TB3> INFO: valid pixel hits: 653065
[19:53:15.527] <TB3> INFO: Event errors: 0
[19:53:15.527] <TB3> INFO: start marker: 0
[19:53:15.527] <TB3> INFO: stop marker: 0
[19:53:15.527] <TB3> INFO: overflow: 0
[19:53:15.527] <TB3> INFO: invalid 5bit words: 0
[19:53:15.527] <TB3> INFO: invalid XOR eye diagram: 0
[19:53:15.527] <TB3> INFO: frame (failed synchr.): 0
[19:53:15.527] <TB3> INFO: idle data (no TBM trl): 0
[19:53:15.527] <TB3> INFO: no data (only TBM hdr): 0
[19:53:15.527] <TB3> INFO: TBM errors: 0
[19:53:15.527] <TB3> INFO: flawed TBM headers: 0
[19:53:15.527] <TB3> INFO: flawed TBM trailers: 0
[19:53:15.527] <TB3> INFO: event ID mismatches: 0
[19:53:15.527] <TB3> INFO: ROC errors: 0
[19:53:15.527] <TB3> INFO: missing ROC header(s): 0
[19:53:15.527] <TB3> INFO: misplaced readback start: 0
[19:53:15.527] <TB3> INFO: Pixel decoding errors: 0
[19:53:15.527] <TB3> INFO: pixel data incomplete: 0
[19:53:15.527] <TB3> INFO: pixel address: 0
[19:53:15.527] <TB3> INFO: pulse height fill bit: 0
[19:53:15.527] <TB3> INFO: buffer corruption: 0
[19:53:15.527] <TB3> INFO: enter test to run
[19:53:15.527] <TB3> INFO: test: Trim80 no parameter change
[19:53:15.527] <TB3> INFO: running: trim80
[19:53:15.543] <TB3> INFO: ######################################################################
[19:53:15.543] <TB3> INFO: PixTestTrim80::doTest()
[19:53:15.543] <TB3> INFO: ######################################################################
[19:53:15.544] <TB3> INFO: ----------------------------------------------------------------------
[19:53:15.545] <TB3> INFO: PixTestTrim80::trimTest() ntrig = 8, vcal = 80
[19:53:15.545] <TB3> INFO: ----------------------------------------------------------------------
[19:53:15.585] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[19:53:15.585] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[19:53:15.595] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[19:53:15.596] <TB3> INFO: run 1 of 1
[19:53:15.831] <TB3> INFO: Expecting 5025280 events.
[19:53:43.444] <TB3> INFO: 680872 events read in total (27021ms).
[19:54:10.387] <TB3> INFO: 1358392 events read in total (53964ms).
[19:54:37.380] <TB3> INFO: 2033960 events read in total (80957ms).
[19:55:04.328] <TB3> INFO: 2707088 events read in total (107905ms).
[19:55:31.227] <TB3> INFO: 3379216 events read in total (134804ms).
[19:55:58.455] <TB3> INFO: 4049808 events read in total (162032ms).
[19:56:25.400] <TB3> INFO: 4719736 events read in total (188977ms).
[19:56:37.826] <TB3> INFO: 5025280 events read in total (201403ms).
[19:56:37.880] <TB3> INFO: Test took 202284ms.
[19:57:01.057] <TB3> INFO: ROC 0 VthrComp = 73
[19:57:01.057] <TB3> INFO: ROC 1 VthrComp = 73
[19:57:01.057] <TB3> INFO: ROC 2 VthrComp = 78
[19:57:01.057] <TB3> INFO: ROC 3 VthrComp = 77
[19:57:01.057] <TB3> INFO: ROC 4 VthrComp = 73
[19:57:01.057] <TB3> INFO: ROC 5 VthrComp = 80
[19:57:01.057] <TB3> INFO: ROC 6 VthrComp = 74
[19:57:01.057] <TB3> INFO: ROC 7 VthrComp = 73
[19:57:01.057] <TB3> INFO: ROC 8 VthrComp = 75
[19:57:01.057] <TB3> INFO: ROC 9 VthrComp = 76
[19:57:01.058] <TB3> INFO: ROC 10 VthrComp = 76
[19:57:01.058] <TB3> INFO: ROC 11 VthrComp = 73
[19:57:01.058] <TB3> INFO: ROC 12 VthrComp = 77
[19:57:01.058] <TB3> INFO: ROC 13 VthrComp = 78
[19:57:01.058] <TB3> INFO: ROC 14 VthrComp = 71
[19:57:01.058] <TB3> INFO: ROC 15 VthrComp = 76
[19:57:01.333] <TB3> INFO: Expecting 41600 events.
[19:57:04.863] <TB3> INFO: 41600 events read in total (2938ms).
[19:57:04.864] <TB3> INFO: Test took 3804ms.
[19:57:04.873] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[19:57:04.873] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[19:57:04.882] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[19:57:04.882] <TB3> INFO: run 1 of 1
[19:57:05.160] <TB3> INFO: Expecting 5025280 events.
[19:57:32.848] <TB3> INFO: 689536 events read in total (27096ms).
[19:57:59.981] <TB3> INFO: 1373816 events read in total (54229ms).
[19:58:27.324] <TB3> INFO: 2056912 events read in total (81572ms).
[19:58:54.471] <TB3> INFO: 2737432 events read in total (108719ms).
[19:59:21.721] <TB3> INFO: 3414232 events read in total (135969ms).
[19:59:48.855] <TB3> INFO: 4089928 events read in total (163103ms).
[20:00:15.951] <TB3> INFO: 4766640 events read in total (190199ms).
[20:00:26.411] <TB3> INFO: 5025280 events read in total (200659ms).
[20:00:26.464] <TB3> INFO: Test took 201582ms.
[20:00:51.562] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 108.106 for pixel 10/74 mean/min/max = 92.7594/77.3618/108.157
[20:00:51.563] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 107.918 for pixel 12/77 mean/min/max = 92.9367/77.7717/108.102
[20:00:51.563] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 112.288 for pixel 0/8 mean/min/max = 95.2672/77.5856/112.949
[20:00:51.564] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 116.428 for pixel 0/9 mean/min/max = 97.0159/77.599/116.433
[20:00:51.564] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 107.983 for pixel 0/24 mean/min/max = 92.9658/77.7374/108.194
[20:00:51.565] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 107.74 for pixel 6/1 mean/min/max = 91.4306/75.0584/107.803
[20:00:51.565] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 110.087 for pixel 15/1 mean/min/max = 94.4386/78.4357/110.442
[20:00:51.566] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 109.914 for pixel 8/66 mean/min/max = 93.7293/77.2398/110.219
[20:00:51.566] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 111.522 for pixel 0/0 mean/min/max = 94.5873/77.6127/111.562
[20:00:51.567] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 109.357 for pixel 1/6 mean/min/max = 93.8829/78.2174/109.548
[20:00:51.567] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 113.424 for pixel 0/5 mean/min/max = 96.3137/78.9756/113.652
[20:00:51.567] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 111.325 for pixel 6/2 mean/min/max = 94.0978/76.8256/111.37
[20:00:51.568] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 112.834 for pixel 0/54 mean/min/max = 95.286/77.5348/113.037
[20:00:51.568] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 110.367 for pixel 16/79 mean/min/max = 94.3719/78.3481/110.396
[20:00:51.569] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 106.932 for pixel 0/78 mean/min/max = 90.9349/74.9254/106.944
[20:00:51.569] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 110.952 for pixel 0/68 mean/min/max = 94.2363/77.4092/111.063
[20:00:51.569] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:00:51.658] <TB3> INFO: Expecting 411648 events.
[20:01:01.209] <TB3> INFO: 411648 events read in total (8959ms).
[20:01:01.217] <TB3> INFO: Expecting 411648 events.
[20:01:10.722] <TB3> INFO: 411648 events read in total (9102ms).
[20:01:10.732] <TB3> INFO: Expecting 411648 events.
[20:01:20.105] <TB3> INFO: 411648 events read in total (8970ms).
[20:01:20.122] <TB3> INFO: Expecting 411648 events.
[20:01:29.240] <TB3> INFO: 411648 events read in total (8715ms).
[20:01:29.254] <TB3> INFO: Expecting 411648 events.
[20:01:38.366] <TB3> INFO: 411648 events read in total (8709ms).
[20:01:38.384] <TB3> INFO: Expecting 411648 events.
[20:01:47.527] <TB3> INFO: 411648 events read in total (8740ms).
[20:01:47.554] <TB3> INFO: Expecting 411648 events.
[20:01:56.751] <TB3> INFO: 411648 events read in total (8794ms).
[20:01:56.776] <TB3> INFO: Expecting 411648 events.
[20:02:05.933] <TB3> INFO: 411648 events read in total (8754ms).
[20:02:05.966] <TB3> INFO: Expecting 411648 events.
[20:02:15.067] <TB3> INFO: 411648 events read in total (8698ms).
[20:02:15.098] <TB3> INFO: Expecting 411648 events.
[20:02:24.263] <TB3> INFO: 411648 events read in total (8762ms).
[20:02:24.296] <TB3> INFO: Expecting 411648 events.
[20:02:33.403] <TB3> INFO: 411648 events read in total (8704ms).
[20:02:33.436] <TB3> INFO: Expecting 411648 events.
[20:02:42.553] <TB3> INFO: 411648 events read in total (8714ms).
[20:02:42.601] <TB3> INFO: Expecting 411648 events.
[20:02:51.687] <TB3> INFO: 411648 events read in total (8683ms).
[20:02:51.726] <TB3> INFO: Expecting 411648 events.
[20:03:00.822] <TB3> INFO: 411648 events read in total (8693ms).
[20:03:00.877] <TB3> INFO: Expecting 411648 events.
[20:03:10.099] <TB3> INFO: 411648 events read in total (8819ms).
[20:03:10.152] <TB3> INFO: Expecting 411648 events.
[20:03:19.337] <TB3> INFO: 411648 events read in total (8782ms).
[20:03:19.387] <TB3> INFO: Test took 147818ms.
[20:03:20.985] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[20:03:20.995] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[20:03:20.995] <TB3> INFO: run 1 of 1
[20:03:21.240] <TB3> INFO: Expecting 5025280 events.
[20:03:48.841] <TB3> INFO: 666912 events read in total (27009ms).
[20:04:15.867] <TB3> INFO: 1332136 events read in total (54035ms).
[20:04:42.652] <TB3> INFO: 1997344 events read in total (80820ms).
[20:05:09.714] <TB3> INFO: 2659896 events read in total (107882ms).
[20:05:36.672] <TB3> INFO: 3319088 events read in total (134840ms).
[20:06:03.409] <TB3> INFO: 3977592 events read in total (161577ms).
[20:06:29.970] <TB3> INFO: 4633560 events read in total (188138ms).
[20:06:45.943] <TB3> INFO: 5025280 events read in total (204111ms).
[20:06:46.005] <TB3> INFO: Test took 205010ms.
[20:07:10.394] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 54.743412 .. 126.263513
[20:07:10.641] <TB3> INFO: Expecting 208000 events.
[20:07:20.586] <TB3> INFO: 208000 events read in total (9353ms).
[20:07:20.587] <TB3> INFO: Test took 10191ms.
[20:07:20.634] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 44 .. 136 (-1/-1) hits flags = 528 (plus default)
[20:07:20.647] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[20:07:20.647] <TB3> INFO: run 1 of 1
[20:07:20.924] <TB3> INFO: Expecting 3095040 events.
[20:07:48.183] <TB3> INFO: 637112 events read in total (26667ms).
[20:08:14.705] <TB3> INFO: 1273688 events read in total (53189ms).
[20:08:40.903] <TB3> INFO: 1908016 events read in total (79387ms).
[20:09:07.203] <TB3> INFO: 2539248 events read in total (105687ms).
[20:09:30.766] <TB3> INFO: 3095040 events read in total (129250ms).
[20:09:30.809] <TB3> INFO: Test took 130162ms.
[20:09:54.377] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 62.646728 .. 112.061482
[20:09:54.644] <TB3> INFO: Expecting 208000 events.
[20:10:04.417] <TB3> INFO: 208000 events read in total (9182ms).
[20:10:04.418] <TB3> INFO: Test took 10039ms.
[20:10:04.463] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 52 .. 122 (-1/-1) hits flags = 528 (plus default)
[20:10:04.473] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[20:10:04.473] <TB3> INFO: run 1 of 1
[20:10:04.751] <TB3> INFO: Expecting 2362880 events.
[20:10:32.098] <TB3> INFO: 636064 events read in total (26755ms).
[20:10:59.080] <TB3> INFO: 1272192 events read in total (53737ms).
[20:11:25.413] <TB3> INFO: 1907912 events read in total (80070ms).
[20:11:44.076] <TB3> INFO: 2362880 events read in total (98733ms).
[20:11:44.114] <TB3> INFO: Test took 99640ms.
[20:12:03.359] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 68.977493 .. 107.681104
[20:12:03.619] <TB3> INFO: Expecting 208000 events.
[20:12:13.194] <TB3> INFO: 208000 events read in total (8983ms).
[20:12:13.195] <TB3> INFO: Test took 9834ms.
[20:12:13.261] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 58 .. 117 (-1/-1) hits flags = 528 (plus default)
[20:12:13.272] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[20:12:13.272] <TB3> INFO: run 1 of 1
[20:12:13.550] <TB3> INFO: Expecting 1996800 events.
[20:12:40.677] <TB3> INFO: 628304 events read in total (26536ms).
[20:13:07.395] <TB3> INFO: 1256552 events read in total (53254ms).
[20:13:34.035] <TB3> INFO: 1884424 events read in total (79894ms).
[20:13:39.126] <TB3> INFO: 1996800 events read in total (84985ms).
[20:13:39.153] <TB3> INFO: Test took 85880ms.
[20:13:59.161] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 72.027846 .. 87.343973
[20:13:59.394] <TB3> INFO: Expecting 208000 events.
[20:14:09.532] <TB3> INFO: 208000 events read in total (9546ms).
[20:14:09.533] <TB3> INFO: Test took 10371ms.
[20:14:09.597] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 62 .. 97 (-1/-1) hits flags = 528 (plus default)
[20:14:09.609] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[20:14:09.609] <TB3> INFO: run 1 of 1
[20:14:09.887] <TB3> INFO: Expecting 1198080 events.
[20:14:38.696] <TB3> INFO: 676720 events read in total (28217ms).
[20:15:00.548] <TB3> INFO: 1198080 events read in total (50069ms).
[20:15:00.570] <TB3> INFO: Test took 50961ms.
[20:15:17.351] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 60 .. 100
[20:15:17.351] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 60 .. 100 (-1/-1) hits flags = 528 (plus default)
[20:15:17.362] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[20:15:17.363] <TB3> INFO: run 1 of 1
[20:15:17.600] <TB3> INFO: Expecting 1364480 events.
[20:15:46.022] <TB3> INFO: 668424 events read in total (27831ms).
[20:16:13.355] <TB3> INFO: 1336576 events read in total (55164ms).
[20:16:15.035] <TB3> INFO: 1364480 events read in total (56844ms).
[20:16:15.062] <TB3> INFO: Test took 57700ms.
[20:16:32.796] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C0.dat
[20:16:32.796] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C1.dat
[20:16:32.796] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C2.dat
[20:16:32.796] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C3.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C4.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C5.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C6.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C7.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C8.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C9.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C10.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C11.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C12.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C13.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C14.dat
[20:16:32.797] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//dacParameters80_C15.dat
[20:16:32.798] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C0.dat
[20:16:32.805] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C1.dat
[20:16:32.812] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C2.dat
[20:16:32.820] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C3.dat
[20:16:32.827] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C4.dat
[20:16:32.834] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C5.dat
[20:16:32.842] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C6.dat
[20:16:32.849] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C7.dat
[20:16:32.856] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C8.dat
[20:16:32.862] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C9.dat
[20:16:32.868] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C10.dat
[20:16:32.875] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C11.dat
[20:16:32.882] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C12.dat
[20:16:32.889] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C13.dat
[20:16:32.897] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C14.dat
[20:16:32.904] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1125_FullQualification_2016-11-04_10h05m_1478250315//003_FulltestTrim80_p17//trimParameters80_C15.dat
[20:16:32.911] <TB3> INFO: PixTestTrim80::trimTest() done
[20:16:32.911] <TB3> INFO: vtrim: 115 113 119 135 91 111 112 101 124 116 121 123 109 104 101 103
[20:16:32.912] <TB3> INFO: vthrcomp: 73 73 78 77 73 80 74 73 75 76 76 73 77 78 71 76
[20:16:32.912] <TB3> INFO: vcal mean: 79.99 80.01 80.01 79.96 80.00 79.95 79.97 80.01 79.99 80.02 79.98 80.00 80.00 80.02 79.99 80.01
[20:16:32.912] <TB3> INFO: vcal RMS: 0.75 0.76 0.74 0.85 0.67 1.44 0.80 1.45 0.70 0.72 0.77 0.75 0.72 0.72 0.73 0.72
[20:16:32.912] <TB3> INFO: bits mean: 10.35 9.94 9.39 9.52 9.51 10.51 9.96 9.55 9.67 9.61 9.40 9.94 9.45 9.00 10.44 9.08
[20:16:32.912] <TB3> INFO: bits RMS: 1.97 2.08 2.18 2.14 2.21 2.14 1.97 2.28 2.14 2.12 2.07 2.12 2.17 2.30 2.23 2.39
[20:16:32.921] <TB3> INFO: ----------------------------------------------------------------------
[20:16:32.921] <TB3> INFO: PixTestTrim80::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[20:16:32.921] <TB3> INFO: ----------------------------------------------------------------------
[20:16:32.924] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[20:16:32.934] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[20:16:32.934] <TB3> INFO: run 1 of 1
[20:16:33.165] <TB3> INFO: Expecting 4160000 events.
[20:17:06.004] <TB3> INFO: 770315 events read in total (32248ms).
[20:17:38.053] <TB3> INFO: 1537140 events read in total (64297ms).
[20:18:10.083] <TB3> INFO: 2298480 events read in total (96327ms).
[20:18:42.185] <TB3> INFO: 3055925 events read in total (128429ms).
[20:19:13.884] <TB3> INFO: 3812185 events read in total (160128ms).
[20:19:28.552] <TB3> INFO: 4160000 events read in total (174796ms).
[20:19:28.595] <TB3> INFO: Test took 175661ms.
[20:19:53.498] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 207 (-1/-1) hits flags = 528 (plus default)
[20:19:53.510] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[20:19:53.510] <TB3> INFO: run 1 of 1
[20:19:53.743] <TB3> INFO: Expecting 4326400 events.
[20:20:25.439] <TB3> INFO: 734575 events read in total (31104ms).
[20:20:56.746] <TB3> INFO: 1466115 events read in total (62411ms).
[20:21:28.319] <TB3> INFO: 2195250 events read in total (93984ms).
[20:21:59.764] <TB3> INFO: 2919995 events read in total (125429ms).
[20:22:30.877] <TB3> INFO: 3643290 events read in total (156542ms).
[20:23:00.196] <TB3> INFO: 4326400 events read in total (185861ms).
[20:23:00.249] <TB3> INFO: Test took 186739ms.
[20:23:28.305] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[20:23:28.316] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[20:23:28.316] <TB3> INFO: run 1 of 1
[20:23:28.548] <TB3> INFO: Expecting 4160000 events.
[20:24:00.724] <TB3> INFO: 746215 events read in total (31585ms).
[20:24:32.399] <TB3> INFO: 1489295 events read in total (63260ms).
[20:25:04.352] <TB3> INFO: 2228915 events read in total (95213ms).
[20:25:35.921] <TB3> INFO: 2964400 events read in total (126782ms).
[20:26:06.958] <TB3> INFO: 3699070 events read in total (157819ms).
[20:26:26.692] <TB3> INFO: 4160000 events read in total (177553ms).
[20:26:26.753] <TB3> INFO: Test took 178437ms.
[20:26:52.409] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[20:26:52.421] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[20:26:52.421] <TB3> INFO: run 1 of 1
[20:26:52.697] <TB3> INFO: Expecting 4160000 events.
[20:27:24.896] <TB3> INFO: 746900 events read in total (31608ms).
[20:27:56.555] <TB3> INFO: 1490535 events read in total (63267ms).
[20:28:28.185] <TB3> INFO: 2230410 events read in total (94897ms).
[20:28:59.338] <TB3> INFO: 2966345 events read in total (126050ms).
[20:29:31.201] <TB3> INFO: 3701090 events read in total (157913ms).
[20:29:50.766] <TB3> INFO: 4160000 events read in total (177478ms).
[20:29:50.828] <TB3> INFO: Test took 178407ms.
[20:30:18.065] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 200 (-1/-1) hits flags = 528 (plus default)
[20:30:18.076] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[20:30:18.076] <TB3> INFO: run 1 of 1
[20:30:18.309] <TB3> INFO: Expecting 4180800 events.
[20:30:50.323] <TB3> INFO: 745505 events read in total (31422ms).
[20:31:22.032] <TB3> INFO: 1487480 events read in total (63131ms).
[20:31:53.273] <TB3> INFO: 2226415 events read in total (94372ms).
[20:32:24.961] <TB3> INFO: 2960965 events read in total (126060ms).
[20:32:58.037] <TB3> INFO: 3694885 events read in total (159136ms).
[20:33:18.998] <TB3> INFO: 4180800 events read in total (180097ms).
[20:33:19.048] <TB3> INFO: Test took 180971ms.
[20:33:41.002] <TB3> INFO: PixTestTrim80::trimBitTest() done
[20:33:42.003] <TB3> INFO: PixTestTrim80::doTest() done, duration: 2426 seconds
[20:33:42.633] <TB3> INFO: enter test to run
[20:33:42.633] <TB3> INFO: test: exit no parameter change
[20:33:42.729] <TB3> QUIET: Connection to board 170 closed.
[20:33:42.730] <TB3> INFO: pXar: this is the end, my friend
MoReWeb-v1.0.5-10-g7383767 on branch 20161012_zhud