[12:50:41.195] <TB1> INFO: *** Welcome to pxar ***
[12:50:41.195] <TB1> INFO: *** Today: 2016/10/31
[12:50:41.200] <TB1> INFO: *** Version: c8ba-dirty
[12:50:41.200] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C15.dat
[12:50:41.201] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[12:50:41.201] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//defaultMaskFile.dat
[12:50:41.201] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters_C15.dat
[12:50:41.305] <TB1> INFO: clk: 4
[12:50:41.305] <TB1> INFO: ctr: 4
[12:50:41.305] <TB1> INFO: sda: 19
[12:50:41.305] <TB1> INFO: tin: 9
[12:50:41.305] <TB1> INFO: level: 15
[12:50:41.305] <TB1> INFO: triggerdelay: 0
[12:50:41.305] <TB1> QUIET: Instanciating API for pxar v2.7.6+61~g7f4a123
[12:50:41.305] <TB1> INFO: Log level: INFO
[12:50:41.315] <TB1> INFO: Found DTB DTB_WXC03A
[12:50:41.327] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[12:50:41.329] <TB1> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 154
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WXC03A
MAC address: 40D85511809A
Hostname: pixelDTB154
Comment:
------------------------------------------------------
[12:50:41.331] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[12:50:42.822] <TB1> INFO: DUT info:
[12:50:42.822] <TB1> INFO: The DUT currently contains the following objects:
[12:50:42.822] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[12:50:42.822] <TB1> INFO: TBM Core alpha (0): 7 registers set
[12:50:42.822] <TB1> INFO: TBM Core beta (1): 7 registers set
[12:50:42.822] <TB1> INFO: TBM Core alpha (2): 7 registers set
[12:50:42.822] <TB1> INFO: TBM Core beta (3): 7 registers set
[12:50:42.822] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[12:50:42.822] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.822] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.823] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.823] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.823] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:42.823] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:50:43.223] <TB1> INFO: enter 'restricted' command line mode
[12:50:43.223] <TB1> INFO: enter test to run
[12:50:43.223] <TB1> INFO: test: pretest no parameter change
[12:50:43.223] <TB1> INFO: running: pretest
[12:50:43.228] <TB1> INFO: ######################################################################
[12:50:43.228] <TB1> INFO: PixTestPretest::doTest()
[12:50:43.228] <TB1> INFO: ######################################################################
[12:50:43.230] <TB1> INFO: ----------------------------------------------------------------------
[12:50:43.230] <TB1> INFO: PixTestPretest::programROC()
[12:50:43.230] <TB1> INFO: ----------------------------------------------------------------------
[12:51:01.243] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[12:51:01.243] <TB1> INFO: IA differences per ROC: 20.1 17.7 20.9 17.7 19.3 17.7 16.9 19.3 19.3 18.5 17.7 18.5 16.9 18.5 18.5 18.5
[12:51:01.301] <TB1> INFO: ----------------------------------------------------------------------
[12:51:01.301] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[12:51:01.301] <TB1> INFO: ----------------------------------------------------------------------
[12:51:22.599] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 389.1 mA = 24.3188 mA/ROC
[12:51:22.600] <TB1> INFO: i(loss) [mA/ROC]: 20.1 19.3 20.1 19.3 20.1 19.3 20.1 20.1 20.1 19.3 20.1 20.1 19.3 20.1 19.3 20.1
[12:51:22.635] <TB1> INFO: ----------------------------------------------------------------------
[12:51:22.635] <TB1> INFO: PixTestPretest::findTiming()
[12:51:22.635] <TB1> INFO: ----------------------------------------------------------------------
[12:51:22.636] <TB1> INFO: PixTestCmd::init()

[12:51:55.038] <TB1> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[12:51:55.038] <TB1> INFO: (success/tries = 100/100), width = 4
[12:51:56.538] <TB1> INFO: ----------------------------------------------------------------------
[12:51:56.538] <TB1> INFO: PixTestPretest::findWorkingPixel()
[12:51:56.538] <TB1> INFO: ----------------------------------------------------------------------
[12:51:56.633] <TB1> INFO: Expecting 231680 events.
[12:52:06.509] <TB1> INFO: 231680 events read in total (9284ms).
[12:52:06.519] <TB1> INFO: Test took 9976ms.
[12:52:06.770] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[12:52:06.808] <TB1> INFO: ----------------------------------------------------------------------
[12:52:06.808] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[12:52:06.808] <TB1> INFO: ----------------------------------------------------------------------
[12:52:06.902] <TB1> INFO: Expecting 231680 events.
[12:52:17.251] <TB1> INFO: 231680 events read in total (9757ms).
[12:52:17.263] <TB1> INFO: Test took 10450ms.
[12:52:17.530] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[12:52:17.530] <TB1> INFO: CalDel: 92 94 98 76 80 79 90 83 82 80 71 111 80 78 80 72
[12:52:17.530] <TB1> INFO: VthrComp: 51 51 54 51 51 51 51 51 51 51 54 51 51 52 51 51
[12:52:17.534] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C0.dat
[12:52:17.534] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C1.dat
[12:52:17.534] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C2.dat
[12:52:17.534] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C3.dat
[12:52:17.534] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C4.dat
[12:52:17.535] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C5.dat
[12:52:17.535] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C6.dat
[12:52:17.535] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C7.dat
[12:52:17.535] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C8.dat
[12:52:17.535] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C9.dat
[12:52:17.535] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C10.dat
[12:52:17.535] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C11.dat
[12:52:17.536] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C12.dat
[12:52:17.536] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C13.dat
[12:52:17.536] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C14.dat
[12:52:17.536] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters_C15.dat
[12:52:17.536] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//tbmParameters_C0a.dat
[12:52:17.536] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//tbmParameters_C0b.dat
[12:52:17.536] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//tbmParameters_C1a.dat
[12:52:17.537] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[12:52:17.537] <TB1> INFO: PixTestPretest::doTest() done, duration: 94 seconds
[12:52:17.591] <TB1> INFO: enter test to run
[12:52:17.591] <TB1> INFO: test: fulltest no parameter change
[12:52:17.591] <TB1> INFO: running: fulltest
[12:52:17.591] <TB1> INFO: ######################################################################
[12:52:17.591] <TB1> INFO: PixTestFullTest::doTest()
[12:52:17.591] <TB1> INFO: ######################################################################
[12:52:17.592] <TB1> INFO: ######################################################################
[12:52:17.592] <TB1> INFO: PixTestAlive::doTest()
[12:52:17.592] <TB1> INFO: ######################################################################
[12:52:17.593] <TB1> INFO: ----------------------------------------------------------------------
[12:52:17.593] <TB1> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:52:17.593] <TB1> INFO: ----------------------------------------------------------------------
[12:52:17.831] <TB1> INFO: Expecting 41600 events.
[12:52:21.336] <TB1> INFO: 41600 events read in total (2913ms).
[12:52:21.337] <TB1> INFO: Test took 3742ms.
[12:52:21.572] <TB1> INFO: PixTestAlive::aliveTest() done
[12:52:21.572] <TB1> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0
[12:52:21.574] <TB1> INFO: ----------------------------------------------------------------------
[12:52:21.574] <TB1> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:52:21.574] <TB1> INFO: ----------------------------------------------------------------------
[12:52:21.817] <TB1> INFO: Expecting 41600 events.
[12:52:24.816] <TB1> INFO: 41600 events read in total (2407ms).
[12:52:24.816] <TB1> INFO: Test took 3239ms.
[12:52:24.817] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[12:52:25.053] <TB1> INFO: PixTestAlive::maskTest() done
[12:52:25.054] <TB1> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:52:25.057] <TB1> INFO: ----------------------------------------------------------------------
[12:52:25.057] <TB1> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:52:25.057] <TB1> INFO: ----------------------------------------------------------------------
[12:52:25.306] <TB1> INFO: Expecting 41600 events.
[12:52:28.843] <TB1> INFO: 41600 events read in total (2946ms).
[12:52:28.844] <TB1> INFO: Test took 3784ms.
[12:52:29.070] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[12:52:29.070] <TB1> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:52:29.071] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[12:52:29.071] <TB1> INFO: Decoding statistics:
[12:52:29.071] <TB1> INFO: General information:
[12:52:29.071] <TB1> INFO: 16bit words read: 0
[12:52:29.071] <TB1> INFO: valid events total: 0
[12:52:29.071] <TB1> INFO: empty events: 0
[12:52:29.071] <TB1> INFO: valid events with pixels: 0
[12:52:29.071] <TB1> INFO: valid pixel hits: 0
[12:52:29.071] <TB1> INFO: Event errors: 0
[12:52:29.071] <TB1> INFO: start marker: 0
[12:52:29.071] <TB1> INFO: stop marker: 0
[12:52:29.071] <TB1> INFO: overflow: 0
[12:52:29.071] <TB1> INFO: invalid 5bit words: 0
[12:52:29.071] <TB1> INFO: invalid XOR eye diagram: 0
[12:52:29.071] <TB1> INFO: frame (failed synchr.): 0
[12:52:29.071] <TB1> INFO: idle data (no TBM trl): 0
[12:52:29.071] <TB1> INFO: no data (only TBM hdr): 0
[12:52:29.071] <TB1> INFO: TBM errors: 0
[12:52:29.071] <TB1> INFO: flawed TBM headers: 0
[12:52:29.071] <TB1> INFO: flawed TBM trailers: 0
[12:52:29.071] <TB1> INFO: event ID mismatches: 0
[12:52:29.071] <TB1> INFO: ROC errors: 0
[12:52:29.071] <TB1> INFO: missing ROC header(s): 0
[12:52:29.071] <TB1> INFO: misplaced readback start: 0
[12:52:29.071] <TB1> INFO: Pixel decoding errors: 0
[12:52:29.071] <TB1> INFO: pixel data incomplete: 0
[12:52:29.071] <TB1> INFO: pixel address: 0
[12:52:29.071] <TB1> INFO: pulse height fill bit: 0
[12:52:29.071] <TB1> INFO: buffer corruption: 0
[12:52:29.075] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C15.dat
[12:52:29.076] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr_C15.dat

[12:52:29.076] <TB1> INFO: ######################################################################
[12:52:29.076] <TB1> INFO: PixTestReadback::doTest()
[12:52:29.076] <TB1> INFO: ######################################################################
[12:52:29.076] <TB1> INFO: ----------------------------------------------------------------------
[12:52:29.076] <TB1> INFO: PixTestReadback::CalibrateVd()
[12:52:29.076] <TB1> INFO: ----------------------------------------------------------------------
[12:52:39.058] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C0.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C1.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C2.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C3.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C4.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C5.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C6.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C7.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C8.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C9.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C10.dat
[12:52:39.059] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C11.dat
[12:52:39.060] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C12.dat
[12:52:39.060] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C13.dat
[12:52:39.060] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C14.dat
[12:52:39.060] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C15.dat
[12:52:39.092] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[12:52:39.092] <TB1> INFO: ----------------------------------------------------------------------
[12:52:39.092] <TB1> INFO: PixTestReadback::CalibrateVa()
[12:52:39.092] <TB1> INFO: ----------------------------------------------------------------------
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C0.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C1.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C2.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C3.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C4.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C5.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C6.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C7.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C8.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C9.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C10.dat
[12:52:49.035] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C11.dat
[12:52:49.036] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C12.dat
[12:52:49.036] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C13.dat
[12:52:49.036] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C14.dat
[12:52:49.036] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C15.dat
[12:52:49.064] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[12:52:49.064] <TB1> INFO: ----------------------------------------------------------------------
[12:52:49.064] <TB1> INFO: PixTestReadback::readbackVbg()
[12:52:49.064] <TB1> INFO: ----------------------------------------------------------------------
[12:52:56.736] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[12:52:56.736] <TB1> INFO: ----------------------------------------------------------------------
[12:52:56.736] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[12:52:56.736] <TB1> INFO: ----------------------------------------------------------------------
[12:52:56.736] <TB1> INFO: Vbg will be calibrated using Vd calibration
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 147.6calibrated Vbg = 1.19445 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 146.7calibrated Vbg = 1.19157 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 153.9calibrated Vbg = 1.19185 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 152.2calibrated Vbg = 1.18829 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 148.8calibrated Vbg = 1.19243 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 164.7calibrated Vbg = 1.19585 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 150.3calibrated Vbg = 1.19882 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 148.9calibrated Vbg = 1.19725 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 153calibrated Vbg = 1.19243 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 156.2calibrated Vbg = 1.18765 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 157.9calibrated Vbg = 1.1894 :::*/*/*/*/
[12:52:56.736] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 153.9calibrated Vbg = 1.18205 :::*/*/*/*/
[12:52:56.737] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 157.2calibrated Vbg = 1.19034 :::*/*/*/*/
[12:52:56.737] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 156.4calibrated Vbg = 1.19718 :::*/*/*/*/
[12:52:56.737] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 160.2calibrated Vbg = 1.19433 :::*/*/*/*/
[12:52:56.737] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 164calibrated Vbg = 1.1978 :::*/*/*/*/
[12:52:56.739] <TB1> INFO: ----------------------------------------------------------------------
[12:52:56.740] <TB1> INFO: PixTestReadback::CalibrateIa()
[12:52:56.740] <TB1> INFO: ----------------------------------------------------------------------
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C0.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C1.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C2.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C3.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C4.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C5.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C6.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C7.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C8.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C9.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C10.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C11.dat
[12:55:37.587] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C12.dat
[12:55:37.588] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C13.dat
[12:55:37.588] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C14.dat
[12:55:37.588] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//readbackCal_C15.dat
[12:55:37.615] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[12:55:37.618] <TB1> INFO: PixTestReadback::doTest() done
[12:55:37.618] <TB1> INFO: Decoding statistics:
[12:55:37.618] <TB1> INFO: General information:
[12:55:37.618] <TB1> INFO: 16bit words read: 1536
[12:55:37.618] <TB1> INFO: valid events total: 256
[12:55:37.618] <TB1> INFO: empty events: 256
[12:55:37.618] <TB1> INFO: valid events with pixels: 0
[12:55:37.618] <TB1> INFO: valid pixel hits: 0
[12:55:37.618] <TB1> INFO: Event errors: 0
[12:55:37.618] <TB1> INFO: start marker: 0
[12:55:37.618] <TB1> INFO: stop marker: 0
[12:55:37.618] <TB1> INFO: overflow: 0
[12:55:37.618] <TB1> INFO: invalid 5bit words: 0
[12:55:37.618] <TB1> INFO: invalid XOR eye diagram: 0
[12:55:37.618] <TB1> INFO: frame (failed synchr.): 0
[12:55:37.618] <TB1> INFO: idle data (no TBM trl): 0
[12:55:37.618] <TB1> INFO: no data (only TBM hdr): 0
[12:55:37.619] <TB1> INFO: TBM errors: 0
[12:55:37.619] <TB1> INFO: flawed TBM headers: 0
[12:55:37.619] <TB1> INFO: flawed TBM trailers: 0
[12:55:37.619] <TB1> INFO: event ID mismatches: 0
[12:55:37.619] <TB1> INFO: ROC errors: 0
[12:55:37.619] <TB1> INFO: missing ROC header(s): 0
[12:55:37.619] <TB1> INFO: misplaced readback start: 0
[12:55:37.619] <TB1> INFO: Pixel decoding errors: 0
[12:55:37.619] <TB1> INFO: pixel data incomplete: 0
[12:55:37.619] <TB1> INFO: pixel address: 0
[12:55:37.619] <TB1> INFO: pulse height fill bit: 0
[12:55:37.619] <TB1> INFO: buffer corruption: 0
[12:55:37.674] <TB1> INFO: ######################################################################
[12:55:37.674] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[12:55:37.674] <TB1> INFO: ######################################################################
[12:55:37.677] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[12:55:37.701] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[12:55:37.701] <TB1> INFO: run 1 of 1
[12:55:37.939] <TB1> INFO: Expecting 3120000 events.
[12:56:10.200] <TB1> INFO: 677120 events read in total (31669ms).
[12:56:40.770] <TB1> INFO: 1346055 events read in total (62239ms).
[12:57:11.203] <TB1> INFO: 2009835 events read in total (92672ms).











[12:57:41.788] <TB1> INFO: 2672485 events read in total (123257ms).











[12:58:02.213] <TB1> INFO: 3120000 events read in total (143682ms).
[12:58:02.368] <TB1> INFO: Test took 144668ms.
[12:58:26.970] <TB1> INFO: PixTestBBMap::doTest() done with 2 decoding errors: , duration: 169 seconds
[12:58:26.970] <TB1> INFO: number of dead bumps (per ROC): 11 94 29 158 111 55 33 13 7 35 61 158 153 104 16 0
[12:58:26.970] <TB1> INFO: separation cut (per ROC): 102 94 128 98 93 98 94 103 104 97 100 94 94 101 105 115
[12:58:26.970] <TB1> INFO: Decoding statistics:
[12:58:26.970] <TB1> INFO: General information:
[12:58:26.970] <TB1> INFO: 16bit words read: 0
[12:58:26.970] <TB1> INFO: valid events total: 0
[12:58:26.970] <TB1> INFO: empty events: 0
[12:58:26.970] <TB1> INFO: valid events with pixels: 0
[12:58:26.970] <TB1> INFO: valid pixel hits: 0
[12:58:26.970] <TB1> INFO: Event errors: 0
[12:58:26.970] <TB1> INFO: start marker: 0
[12:58:26.970] <TB1> INFO: stop marker: 0
[12:58:26.970] <TB1> INFO: overflow: 0
[12:58:26.970] <TB1> INFO: invalid 5bit words: 0
[12:58:26.970] <TB1> INFO: invalid XOR eye diagram: 0
[12:58:26.970] <TB1> INFO: frame (failed synchr.): 0
[12:58:26.970] <TB1> INFO: idle data (no TBM trl): 0
[12:58:26.970] <TB1> INFO: no data (only TBM hdr): 0
[12:58:26.970] <TB1> INFO: TBM errors: 0
[12:58:26.970] <TB1> INFO: flawed TBM headers: 0
[12:58:26.970] <TB1> INFO: flawed TBM trailers: 0
[12:58:26.970] <TB1> INFO: event ID mismatches: 0
[12:58:26.970] <TB1> INFO: ROC errors: 0
[12:58:26.970] <TB1> INFO: missing ROC header(s): 0
[12:58:26.970] <TB1> INFO: misplaced readback start: 0
[12:58:26.970] <TB1> INFO: Pixel decoding errors: 0
[12:58:26.971] <TB1> INFO: pixel data incomplete: 0
[12:58:26.971] <TB1> INFO: pixel address: 0
[12:58:26.971] <TB1> INFO: pulse height fill bit: 0
[12:58:26.971] <TB1> INFO: buffer corruption: 0
[12:58:27.060] <TB1> INFO: ######################################################################
[12:58:27.060] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[12:58:27.060] <TB1> INFO: ######################################################################
[12:58:27.060] <TB1> INFO: ----------------------------------------------------------------------
[12:58:27.060] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[12:58:27.060] <TB1> INFO: ----------------------------------------------------------------------
[12:58:27.060] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[12:58:27.075] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[12:58:27.075] <TB1> INFO: run 1 of 1
[12:58:27.400] <TB1> INFO: Expecting 36608000 events.
[12:58:50.968] <TB1> INFO: 669200 events read in total (22976ms).
[12:59:13.952] <TB1> INFO: 1336350 events read in total (45960ms).
[12:59:36.927] <TB1> INFO: 2002950 events read in total (68935ms).
[12:59:59.915] <TB1> INFO: 2667500 events read in total (91923ms).
[13:00:22.762] <TB1> INFO: 3334550 events read in total (114770ms).
[13:00:45.750] <TB1> INFO: 4002000 events read in total (137758ms).
[13:01:09.158] <TB1> INFO: 4669400 events read in total (161166ms).
[13:01:31.822] <TB1> INFO: 5332900 events read in total (183830ms).
[13:01:54.803] <TB1> INFO: 5999200 events read in total (206811ms).
[13:02:17.881] <TB1> INFO: 6667650 events read in total (229889ms).
[13:02:40.599] <TB1> INFO: 7334400 events read in total (252607ms).
[13:03:03.578] <TB1> INFO: 7999500 events read in total (275586ms).
[13:03:26.548] <TB1> INFO: 8666050 events read in total (298556ms).
[13:03:49.364] <TB1> INFO: 9333100 events read in total (321372ms).
[13:04:12.354] <TB1> INFO: 10000450 events read in total (344362ms).
[13:04:35.126] <TB1> INFO: 10666100 events read in total (367134ms).
[13:04:58.183] <TB1> INFO: 11332500 events read in total (390191ms).
[13:05:21.238] <TB1> INFO: 11999150 events read in total (413246ms).
[13:05:44.633] <TB1> INFO: 12665150 events read in total (436641ms).
[13:06:07.622] <TB1> INFO: 13329400 events read in total (459630ms).
[13:06:30.581] <TB1> INFO: 13992900 events read in total (482589ms).
[13:06:53.557] <TB1> INFO: 14657400 events read in total (505565ms).
[13:07:16.639] <TB1> INFO: 15322050 events read in total (528647ms).
[13:07:39.889] <TB1> INFO: 15986100 events read in total (551897ms).
[13:08:03.140] <TB1> INFO: 16648950 events read in total (575148ms).
[13:08:26.092] <TB1> INFO: 17313650 events read in total (598100ms).
[13:08:48.954] <TB1> INFO: 17976050 events read in total (620962ms).
[13:09:11.916] <TB1> INFO: 18637850 events read in total (643924ms).
[13:09:35.272] <TB1> INFO: 19300650 events read in total (667280ms).
[13:09:58.617] <TB1> INFO: 19961750 events read in total (690625ms).
[13:10:21.687] <TB1> INFO: 20622050 events read in total (713696ms).
[13:10:44.631] <TB1> INFO: 21284150 events read in total (736639ms).
[13:11:07.380] <TB1> INFO: 21944350 events read in total (759388ms).
[13:11:30.433] <TB1> INFO: 22603850 events read in total (782441ms).
[13:11:53.531] <TB1> INFO: 23264150 events read in total (805539ms).
[13:12:16.519] <TB1> INFO: 23924550 events read in total (828527ms).
[13:12:39.662] <TB1> INFO: 24583900 events read in total (851670ms).
[13:13:02.441] <TB1> INFO: 25243200 events read in total (874449ms).
[13:13:25.343] <TB1> INFO: 25902450 events read in total (897351ms).
[13:13:48.147] <TB1> INFO: 26560800 events read in total (920155ms).
[13:14:11.175] <TB1> INFO: 27219850 events read in total (943183ms).
[13:14:34.027] <TB1> INFO: 27878150 events read in total (966035ms).
[13:14:56.916] <TB1> INFO: 28537000 events read in total (988924ms).
[13:15:19.791] <TB1> INFO: 29195800 events read in total (1011799ms).
[13:15:42.544] <TB1> INFO: 29854250 events read in total (1034552ms).
[13:16:05.501] <TB1> INFO: 30510300 events read in total (1057509ms).
[13:16:28.292] <TB1> INFO: 31168550 events read in total (1080300ms).
[13:16:51.417] <TB1> INFO: 31825000 events read in total (1103425ms).
[13:17:14.334] <TB1> INFO: 32482150 events read in total (1126342ms).
[13:17:37.363] <TB1> INFO: 33140200 events read in total (1149371ms).
[13:18:00.346] <TB1> INFO: 33798900 events read in total (1172354ms).
[13:18:23.179] <TB1> INFO: 34457700 events read in total (1195187ms).
[13:18:46.557] <TB1> INFO: 35115650 events read in total (1218565ms).
[13:19:09.433] <TB1> INFO: 35773900 events read in total (1241441ms).
[13:19:32.897] <TB1> INFO: 36437250 events read in total (1264905ms).
[13:19:39.294] <TB1> INFO: 36608000 events read in total (1271302ms).
[13:19:39.460] <TB1> INFO: Test took 1272385ms.
[13:19:40.037] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:42.006] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:43.864] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:45.644] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:47.108] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:48.602] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:50.085] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:51.556] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:53.009] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:54.498] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:55.969] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:57.488] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:19:59.204] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:20:01.121] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:20:02.606] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:20:04.207] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[13:20:05.757] <TB1> INFO: PixTestScurves::scurves() done
[13:20:05.757] <TB1> INFO: Vcal mean: 117.98 106.34 134.75 121.69 109.14 113.40 113.29 113.93 118.68 118.07 117.44 110.20 118.98 124.32 122.99 120.96
[13:20:05.757] <TB1> INFO: Vcal RMS: 5.54 4.93 6.66 6.47 5.02 4.81 4.51 4.61 6.05 6.20 6.31 5.26 7.07 6.45 5.64 5.70
[13:20:05.758] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1298 seconds
[13:20:05.758] <TB1> INFO: Decoding statistics:
[13:20:05.758] <TB1> INFO: General information:
[13:20:05.758] <TB1> INFO: 16bit words read: 0
[13:20:05.758] <TB1> INFO: valid events total: 0
[13:20:05.758] <TB1> INFO: empty events: 0
[13:20:05.758] <TB1> INFO: valid events with pixels: 0
[13:20:05.758] <TB1> INFO: valid pixel hits: 0
[13:20:05.758] <TB1> INFO: Event errors: 0
[13:20:05.758] <TB1> INFO: start marker: 0
[13:20:05.758] <TB1> INFO: stop marker: 0
[13:20:05.758] <TB1> INFO: overflow: 0
[13:20:05.758] <TB1> INFO: invalid 5bit words: 0
[13:20:05.758] <TB1> INFO: invalid XOR eye diagram: 0
[13:20:05.758] <TB1> INFO: frame (failed synchr.): 0
[13:20:05.758] <TB1> INFO: idle data (no TBM trl): 0
[13:20:05.758] <TB1> INFO: no data (only TBM hdr): 0
[13:20:05.758] <TB1> INFO: TBM errors: 0
[13:20:05.758] <TB1> INFO: flawed TBM headers: 0
[13:20:05.758] <TB1> INFO: flawed TBM trailers: 0
[13:20:05.758] <TB1> INFO: event ID mismatches: 0
[13:20:05.758] <TB1> INFO: ROC errors: 0
[13:20:05.758] <TB1> INFO: missing ROC header(s): 0
[13:20:05.758] <TB1> INFO: misplaced readback start: 0
[13:20:05.758] <TB1> INFO: Pixel decoding errors: 0
[13:20:05.758] <TB1> INFO: pixel data incomplete: 0
[13:20:05.758] <TB1> INFO: pixel address: 0
[13:20:05.758] <TB1> INFO: pulse height fill bit: 0
[13:20:05.758] <TB1> INFO: buffer corruption: 0
[13:20:05.839] <TB1> INFO: ######################################################################
[13:20:05.839] <TB1> INFO: PixTestTrim::doTest()
[13:20:05.839] <TB1> INFO: ######################################################################
[13:20:05.840] <TB1> INFO: ----------------------------------------------------------------------
[13:20:05.840] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[13:20:05.840] <TB1> INFO: ----------------------------------------------------------------------
[13:20:05.899] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[13:20:05.899] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[13:20:05.911] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:20:05.911] <TB1> INFO: run 1 of 1
[13:20:06.157] <TB1> INFO: Expecting 5025280 events.
[13:20:36.732] <TB1> INFO: 820592 events read in total (29972ms).
[13:21:06.922] <TB1> INFO: 1640272 events read in total (60162ms).
[13:21:37.007] <TB1> INFO: 2458288 events read in total (90248ms).
[13:22:07.240] <TB1> INFO: 3271128 events read in total (120480ms).
[13:22:36.982] <TB1> INFO: 4081080 events read in total (150222ms).
[13:23:08.037] <TB1> INFO: 4888656 events read in total (181277ms).
[13:23:13.332] <TB1> INFO: 5025280 events read in total (186572ms).
[13:23:13.396] <TB1> INFO: Test took 187484ms.
[13:23:32.487] <TB1> INFO: ROC 0 VthrComp = 124
[13:23:32.487] <TB1> INFO: ROC 1 VthrComp = 112
[13:23:32.487] <TB1> INFO: ROC 2 VthrComp = 132
[13:23:32.487] <TB1> INFO: ROC 3 VthrComp = 120
[13:23:32.487] <TB1> INFO: ROC 4 VthrComp = 117
[13:23:32.487] <TB1> INFO: ROC 5 VthrComp = 126
[13:23:32.487] <TB1> INFO: ROC 6 VthrComp = 113
[13:23:32.487] <TB1> INFO: ROC 7 VthrComp = 122
[13:23:32.488] <TB1> INFO: ROC 8 VthrComp = 127
[13:23:32.488] <TB1> INFO: ROC 9 VthrComp = 124
[13:23:32.489] <TB1> INFO: ROC 10 VthrComp = 128
[13:23:32.489] <TB1> INFO: ROC 11 VthrComp = 117
[13:23:32.489] <TB1> INFO: ROC 12 VthrComp = 117
[13:23:32.489] <TB1> INFO: ROC 13 VthrComp = 128
[13:23:32.489] <TB1> INFO: ROC 14 VthrComp = 130
[13:23:32.489] <TB1> INFO: ROC 15 VthrComp = 132
[13:23:32.729] <TB1> INFO: Expecting 41600 events.
[13:23:36.336] <TB1> INFO: 41600 events read in total (3015ms).
[13:23:36.337] <TB1> INFO: Test took 3846ms.
[13:23:36.346] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[13:23:36.346] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[13:23:36.358] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:23:36.358] <TB1> INFO: run 1 of 1
[13:23:36.636] <TB1> INFO: Expecting 5025280 events.
[13:24:03.303] <TB1> INFO: 587800 events read in total (26075ms).
[13:24:29.312] <TB1> INFO: 1175968 events read in total (52084ms).
[13:24:55.065] <TB1> INFO: 1764456 events read in total (77837ms).
[13:25:20.842] <TB1> INFO: 2352120 events read in total (103614ms).
[13:25:47.131] <TB1> INFO: 2938080 events read in total (129903ms).
[13:26:12.989] <TB1> INFO: 3522512 events read in total (155761ms).
[13:26:39.421] <TB1> INFO: 4106328 events read in total (182193ms).
[13:27:05.745] <TB1> INFO: 4688704 events read in total (208517ms).
[13:27:20.996] <TB1> INFO: 5025280 events read in total (223768ms).
[13:27:21.103] <TB1> INFO: Test took 224745ms.
[13:27:50.262] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 58.2382 for pixel 26/71 mean/min/max = 45.4739/32.6273/58.3204
[13:27:50.262] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 56.4884 for pixel 6/79 mean/min/max = 45.1968/33.701/56.6927
[13:27:50.263] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 68.9596 for pixel 0/9 mean/min/max = 52.5128/35.9608/69.0647
[13:27:50.263] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 61.8994 for pixel 3/72 mean/min/max = 47.5576/33.1641/61.951
[13:27:50.264] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 58.0739 for pixel 0/50 mean/min/max = 45.0361/31.9219/58.1503
[13:27:50.265] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 55.2634 for pixel 28/5 mean/min/max = 43.6358/31.5938/55.6778
[13:27:50.265] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 58.4211 for pixel 51/17 mean/min/max = 46.165/33.8946/58.4354
[13:27:50.266] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 56.6225 for pixel 14/2 mean/min/max = 45.2504/33.777/56.7238
[13:27:50.266] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 58.8041 for pixel 3/26 mean/min/max = 45.3003/31.6633/58.9373
[13:27:50.267] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 58.7028 for pixel 3/79 mean/min/max = 45.3952/32.0623/58.7281
[13:27:50.268] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 59.376 for pixel 0/63 mean/min/max = 45.5406/31.5232/59.558
[13:27:50.268] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 56.6884 for pixel 1/2 mean/min/max = 44.8791/32.9836/56.7747
[13:27:50.269] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 62.4318 for pixel 0/58 mean/min/max = 47.2799/32.0821/62.4777
[13:27:50.270] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 61.5796 for pixel 4/24 mean/min/max = 46.3774/31.0591/61.6958
[13:27:50.270] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 60.5027 for pixel 9/9 mean/min/max = 46.6651/32.678/60.6523
[13:27:50.271] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 58.2541 for pixel 0/7 mean/min/max = 45.4978/32.7188/58.2767
[13:27:50.271] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[13:27:50.361] <TB1> INFO: Expecting 411648 events.
[13:27:59.832] <TB1> INFO: 411648 events read in total (8879ms).
[13:27:59.839] <TB1> INFO: Expecting 411648 events.
[13:28:09.049] <TB1> INFO: 411648 events read in total (8806ms).
[13:28:09.059] <TB1> INFO: Expecting 411648 events.
[13:28:18.332] <TB1> INFO: 411648 events read in total (8869ms).
[13:28:18.349] <TB1> INFO: Expecting 411648 events.
[13:28:27.551] <TB1> INFO: 411648 events read in total (8798ms).
[13:28:27.571] <TB1> INFO: Expecting 411648 events.
[13:28:36.794] <TB1> INFO: 411648 events read in total (8820ms).
[13:28:36.815] <TB1> INFO: Expecting 411648 events.
[13:28:46.140] <TB1> INFO: 411648 events read in total (8921ms).
[13:28:46.167] <TB1> INFO: Expecting 411648 events.
[13:28:55.465] <TB1> INFO: 411648 events read in total (8895ms).
[13:28:55.489] <TB1> INFO: Expecting 411648 events.
[13:29:04.830] <TB1> INFO: 411648 events read in total (8938ms).
[13:29:04.857] <TB1> INFO: Expecting 411648 events.
[13:29:14.268] <TB1> INFO: 411648 events read in total (9008ms).
[13:29:14.297] <TB1> INFO: Expecting 411648 events.
[13:29:23.581] <TB1> INFO: 411648 events read in total (8880ms).
[13:29:23.623] <TB1> INFO: Expecting 411648 events.
[13:29:32.797] <TB1> INFO: 411648 events read in total (8771ms).
[13:29:32.832] <TB1> INFO: Expecting 411648 events.
[13:29:42.101] <TB1> INFO: 411648 events read in total (8866ms).
[13:29:42.138] <TB1> INFO: Expecting 411648 events.
[13:29:51.480] <TB1> INFO: 411648 events read in total (8939ms).
[13:29:51.537] <TB1> INFO: Expecting 411648 events.
[13:30:00.882] <TB1> INFO: 411648 events read in total (8942ms).
[13:30:01.014] <TB1> INFO: Expecting 411648 events.
[13:30:10.332] <TB1> INFO: 411648 events read in total (8915ms).
[13:30:10.394] <TB1> INFO: Expecting 411648 events.
[13:30:19.643] <TB1> INFO: 411648 events read in total (8846ms).
[13:30:19.710] <TB1> INFO: Test took 149439ms.
[13:30:20.464] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[13:30:20.477] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:30:20.477] <TB1> INFO: run 1 of 1
[13:30:20.714] <TB1> INFO: Expecting 5025280 events.
[13:30:47.032] <TB1> INFO: 585576 events read in total (25726ms).
[13:31:12.992] <TB1> INFO: 1169928 events read in total (51686ms).
[13:31:38.762] <TB1> INFO: 1754248 events read in total (77456ms).
[13:32:04.978] <TB1> INFO: 2337832 events read in total (103672ms).
[13:32:31.373] <TB1> INFO: 2920968 events read in total (130067ms).
[13:32:57.766] <TB1> INFO: 3504176 events read in total (156460ms).
[13:33:24.307] <TB1> INFO: 4086584 events read in total (183001ms).
[13:33:50.400] <TB1> INFO: 4668904 events read in total (209094ms).
[13:34:07.235] <TB1> INFO: 5025280 events read in total (225929ms).
[13:34:07.369] <TB1> INFO: Test took 226893ms.
[13:34:33.792] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 11.500000 .. 142.590983
[13:34:34.030] <TB1> INFO: Expecting 208000 events.
[13:34:43.713] <TB1> INFO: 208000 events read in total (9091ms).
[13:34:43.715] <TB1> INFO: Test took 9922ms.
[13:34:43.768] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 1 .. 152 (-1/-1) hits flags = 528 (plus default)
[13:34:43.782] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:34:43.782] <TB1> INFO: run 1 of 1
[13:34:44.060] <TB1> INFO: Expecting 5058560 events.
[13:35:10.232] <TB1> INFO: 585216 events read in total (25580ms).
[13:35:36.234] <TB1> INFO: 1170832 events read in total (51582ms).
[13:36:01.865] <TB1> INFO: 1756344 events read in total (77213ms).
[13:36:27.786] <TB1> INFO: 2341704 events read in total (103134ms).
[13:36:53.448] <TB1> INFO: 2927184 events read in total (128796ms).
[13:37:19.653] <TB1> INFO: 3512136 events read in total (155001ms).
[13:37:45.585] <TB1> INFO: 4096624 events read in total (180933ms).
[13:38:12.505] <TB1> INFO: 4680424 events read in total (207853ms).
[13:38:29.532] <TB1> INFO: 5058560 events read in total (224880ms).
[13:38:29.666] <TB1> INFO: Test took 225884ms.
[13:38:57.754] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 27.393811 .. 45.968600
[13:38:57.992] <TB1> INFO: Expecting 208000 events.
[13:39:07.947] <TB1> INFO: 208000 events read in total (9363ms).
[13:39:07.948] <TB1> INFO: Test took 10192ms.
[13:39:07.997] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 55 (-1/-1) hits flags = 528 (plus default)
[13:39:08.010] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:39:08.010] <TB1> INFO: run 1 of 1
[13:39:08.288] <TB1> INFO: Expecting 1297920 events.
[13:39:36.807] <TB1> INFO: 658096 events read in total (27928ms).
[13:40:04.551] <TB1> INFO: 1297920 events read in total (55673ms).
[13:40:04.588] <TB1> INFO: Test took 56579ms.
[13:40:19.053] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 26.285978 .. 47.645427
[13:40:19.291] <TB1> INFO: Expecting 208000 events.
[13:40:29.283] <TB1> INFO: 208000 events read in total (9401ms).
[13:40:29.284] <TB1> INFO: Test took 10229ms.
[13:40:29.336] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 16 .. 57 (-1/-1) hits flags = 528 (plus default)
[13:40:29.353] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:40:29.353] <TB1> INFO: run 1 of 1
[13:40:29.631] <TB1> INFO: Expecting 1397760 events.
[13:40:57.633] <TB1> INFO: 655448 events read in total (27411ms).
[13:41:25.493] <TB1> INFO: 1311168 events read in total (55272ms).
[13:41:29.497] <TB1> INFO: 1397760 events read in total (59275ms).
[13:41:29.529] <TB1> INFO: Test took 60177ms.
[13:41:43.369] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 23.631376 .. 45.232521
[13:41:43.623] <TB1> INFO: Expecting 208000 events.
[13:41:53.452] <TB1> INFO: 208000 events read in total (9238ms).
[13:41:53.453] <TB1> INFO: Test took 10081ms.
[13:41:53.503] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 13 .. 55 (-1/-1) hits flags = 528 (plus default)
[13:41:53.515] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:41:53.515] <TB1> INFO: run 1 of 1
[13:41:53.794] <TB1> INFO: Expecting 1431040 events.
[13:42:22.122] <TB1> INFO: 675160 events read in total (27736ms).
[13:42:50.385] <TB1> INFO: 1351232 events read in total (55999ms).
[13:42:54.103] <TB1> INFO: 1431040 events read in total (59717ms).
[13:42:54.151] <TB1> INFO: Test took 60636ms.
[13:43:06.627] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[13:43:06.627] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[13:43:06.640] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[13:43:06.640] <TB1> INFO: run 1 of 1
[13:43:06.920] <TB1> INFO: Expecting 1364480 events.
[13:43:36.528] <TB1> INFO: 668248 events read in total (29016ms).
[13:44:04.328] <TB1> INFO: 1335280 events read in total (56817ms).
[13:44:05.958] <TB1> INFO: 1364480 events read in total (58446ms).
[13:44:05.988] <TB1> INFO: Test took 59348ms.
[13:44:20.523] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C0.dat
[13:44:20.523] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C1.dat
[13:44:20.523] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C2.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C3.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C4.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C5.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C6.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C7.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C8.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C9.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C10.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C11.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C12.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C13.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C14.dat
[13:44:20.524] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C15.dat
[13:44:20.525] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C0.dat
[13:44:20.530] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C1.dat
[13:44:20.535] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C2.dat
[13:44:20.539] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C3.dat
[13:44:20.544] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C4.dat
[13:44:20.549] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C5.dat
[13:44:20.554] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C6.dat
[13:44:20.559] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C7.dat
[13:44:20.563] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C8.dat
[13:44:20.568] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C9.dat
[13:44:20.573] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C10.dat
[13:44:20.578] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C11.dat
[13:44:20.582] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C12.dat
[13:44:20.587] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C13.dat
[13:44:20.592] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C14.dat
[13:44:20.597] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters35_C15.dat
[13:44:20.602] <TB1> INFO: PixTestTrim::trimTest() done
[13:44:20.602] <TB1> INFO: vtrim: 125 101 167 126 120 109 116 106 137 117 125 109 120 145 131 122
[13:44:20.602] <TB1> INFO: vthrcomp: 124 112 132 120 117 126 113 122 127 124 128 117 117 128 130 132
[13:44:20.602] <TB1> INFO: vcal mean: 35.00 34.92 35.32 35.20 34.91 34.93 34.94 34.97 34.89 34.89 34.98 34.99 35.04 34.97 34.99 34.93
[13:44:20.602] <TB1> INFO: vcal RMS: 0.94 0.90 1.52 1.29 1.02 0.99 0.99 0.90 1.17 1.01 1.10 1.00 1.20 1.14 1.03 0.97
[13:44:20.602] <TB1> INFO: bits mean: 9.49 9.21 7.93 9.40 9.55 10.00 8.89 9.11 9.81 9.19 8.99 9.59 8.82 9.75 9.38 9.15
[13:44:20.602] <TB1> INFO: bits RMS: 2.66 2.59 2.55 2.61 2.72 2.65 2.74 2.70 2.69 2.90 3.04 2.61 2.99 2.70 2.61 2.81
[13:44:20.609] <TB1> INFO: ----------------------------------------------------------------------
[13:44:20.609] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[13:44:20.609] <TB1> INFO: ----------------------------------------------------------------------
[13:44:20.612] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[13:44:20.625] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:44:20.625] <TB1> INFO: run 1 of 1
[13:44:20.865] <TB1> INFO: Expecting 4160000 events.
[13:44:53.250] <TB1> INFO: 748770 events read in total (31793ms).
[13:45:25.296] <TB1> INFO: 1496770 events read in total (63839ms).
[13:45:57.243] <TB1> INFO: 2240045 events read in total (95786ms).
[13:46:29.129] <TB1> INFO: 2979705 events read in total (127672ms).
[13:47:01.406] <TB1> INFO: 3715815 events read in total (159949ms).
[13:47:20.718] <TB1> INFO: 4160000 events read in total (179261ms).
[13:47:20.815] <TB1> INFO: Test took 180191ms.
[13:47:51.556] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 207 (-1/-1) hits flags = 528 (plus default)
[13:47:51.569] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:47:51.569] <TB1> INFO: run 1 of 1
[13:47:51.810] <TB1> INFO: Expecting 4326400 events.
[13:48:23.731] <TB1> INFO: 715010 events read in total (31329ms).
[13:48:54.815] <TB1> INFO: 1428905 events read in total (62413ms).
[13:49:26.369] <TB1> INFO: 2139680 events read in total (93967ms).
[13:49:57.574] <TB1> INFO: 2847070 events read in total (125172ms).
[13:50:28.274] <TB1> INFO: 3550585 events read in total (155872ms).
[13:50:59.116] <TB1> INFO: 4253505 events read in total (186714ms).
[13:51:02.571] <TB1> INFO: 4326400 events read in total (190169ms).
[13:51:02.681] <TB1> INFO: Test took 191111ms.
[13:51:32.615] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 200 (-1/-1) hits flags = 528 (plus default)
[13:51:32.630] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:51:32.630] <TB1> INFO: run 1 of 1
[13:51:32.894] <TB1> INFO: Expecting 4180800 events.
[13:52:05.520] <TB1> INFO: 724315 events read in total (32034ms).
[13:52:37.483] <TB1> INFO: 1447845 events read in total (63997ms).
[13:53:09.528] <TB1> INFO: 2167430 events read in total (96042ms).
[13:53:41.372] <TB1> INFO: 2882450 events read in total (127886ms).
[13:54:11.895] <TB1> INFO: 3593695 events read in total (158409ms).
[13:54:37.789] <TB1> INFO: 4180800 events read in total (184303ms).
[13:54:37.881] <TB1> INFO: Test took 185251ms.
[13:55:06.546] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[13:55:06.560] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:55:06.560] <TB1> INFO: run 1 of 1
[13:55:06.892] <TB1> INFO: Expecting 4139200 events.
[13:55:39.009] <TB1> INFO: 726820 events read in total (31525ms).
[13:56:10.860] <TB1> INFO: 1451765 events read in total (63376ms).
[13:56:42.359] <TB1> INFO: 2173925 events read in total (94875ms).
[13:57:13.864] <TB1> INFO: 2891620 events read in total (126380ms).
[13:57:44.751] <TB1> INFO: 3605395 events read in total (157267ms).
[13:58:08.194] <TB1> INFO: 4139200 events read in total (180710ms).
[13:58:08.280] <TB1> INFO: Test took 181719ms.
[13:58:33.583] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[13:58:33.597] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[13:58:33.597] <TB1> INFO: run 1 of 1
[13:58:33.850] <TB1> INFO: Expecting 4160000 events.
[13:59:05.407] <TB1> INFO: 725780 events read in total (30966ms).
[13:59:36.742] <TB1> INFO: 1450225 events read in total (62301ms).
[14:00:08.152] <TB1> INFO: 2171165 events read in total (93711ms).
[14:00:39.429] <TB1> INFO: 2887870 events read in total (124988ms).
[14:01:11.652] <TB1> INFO: 3600615 events read in total (157211ms).
[14:01:36.503] <TB1> INFO: 4160000 events read in total (182062ms).
[14:01:36.626] <TB1> INFO: Test took 183030ms.
[14:02:01.774] <TB1> INFO: PixTestTrim::trimBitTest() done
[14:02:01.776] <TB1> INFO: PixTestTrim::doTest() done, duration: 2515 seconds
[14:02:01.776] <TB1> INFO: Decoding statistics:
[14:02:01.776] <TB1> INFO: General information:
[14:02:01.776] <TB1> INFO: 16bit words read: 0
[14:02:01.776] <TB1> INFO: valid events total: 0
[14:02:01.776] <TB1> INFO: empty events: 0
[14:02:01.776] <TB1> INFO: valid events with pixels: 0
[14:02:01.776] <TB1> INFO: valid pixel hits: 0
[14:02:01.776] <TB1> INFO: Event errors: 0
[14:02:01.776] <TB1> INFO: start marker: 0
[14:02:01.776] <TB1> INFO: stop marker: 0
[14:02:01.776] <TB1> INFO: overflow: 0
[14:02:01.776] <TB1> INFO: invalid 5bit words: 0
[14:02:01.776] <TB1> INFO: invalid XOR eye diagram: 0
[14:02:01.776] <TB1> INFO: frame (failed synchr.): 0
[14:02:01.776] <TB1> INFO: idle data (no TBM trl): 0
[14:02:01.776] <TB1> INFO: no data (only TBM hdr): 0
[14:02:01.776] <TB1> INFO: TBM errors: 0
[14:02:01.776] <TB1> INFO: flawed TBM headers: 0
[14:02:01.776] <TB1> INFO: flawed TBM trailers: 0
[14:02:01.776] <TB1> INFO: event ID mismatches: 0
[14:02:01.776] <TB1> INFO: ROC errors: 0
[14:02:01.776] <TB1> INFO: missing ROC header(s): 0
[14:02:01.776] <TB1> INFO: misplaced readback start: 0
[14:02:01.776] <TB1> INFO: Pixel decoding errors: 0
[14:02:01.776] <TB1> INFO: pixel data incomplete: 0
[14:02:01.777] <TB1> INFO: pixel address: 0
[14:02:01.777] <TB1> INFO: pulse height fill bit: 0
[14:02:01.777] <TB1> INFO: buffer corruption: 0
[14:02:02.577] <TB1> INFO: ######################################################################
[14:02:02.577] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[14:02:02.577] <TB1> INFO: ######################################################################
[14:02:02.861] <TB1> INFO: Expecting 41600 events.
[14:02:06.421] <TB1> INFO: 41600 events read in total (2968ms).
[14:02:06.428] <TB1> INFO: Test took 3848ms.
[14:02:06.884] <TB1> INFO: Expecting 41600 events.
[14:02:10.363] <TB1> INFO: 41600 events read in total (2887ms).
[14:02:10.364] <TB1> INFO: Test took 3733ms.
[14:02:10.662] <TB1> INFO: Expecting 41600 events.
[14:02:14.285] <TB1> INFO: 41600 events read in total (3031ms).
[14:02:14.286] <TB1> INFO: Test took 3897ms.
[14:02:14.576] <TB1> INFO: Expecting 41600 events.
[14:02:18.255] <TB1> INFO: 41600 events read in total (3088ms).
[14:02:18.256] <TB1> INFO: Test took 3945ms.
[14:02:18.545] <TB1> INFO: Expecting 41600 events.
[14:02:22.436] <TB1> INFO: 41600 events read in total (3299ms).
[14:02:22.436] <TB1> INFO: Test took 4155ms.
[14:02:22.736] <TB1> INFO: Expecting 41600 events.
[14:02:26.405] <TB1> INFO: 41600 events read in total (3078ms).
[14:02:26.406] <TB1> INFO: Test took 3945ms.
[14:02:26.696] <TB1> INFO: Expecting 41600 events.
[14:02:30.252] <TB1> INFO: 41600 events read in total (2964ms).
[14:02:30.253] <TB1> INFO: Test took 3822ms.
[14:02:30.608] <TB1> INFO: Expecting 41600 events.
[14:02:34.148] <TB1> INFO: 41600 events read in total (2949ms).
[14:02:34.149] <TB1> INFO: Test took 3867ms.
[14:02:34.451] <TB1> INFO: Expecting 41600 events.
[14:02:37.998] <TB1> INFO: 41600 events read in total (2956ms).
[14:02:37.000] <TB1> INFO: Test took 3826ms.
[14:02:38.291] <TB1> INFO: Expecting 41600 events.
[14:02:41.795] <TB1> INFO: 41600 events read in total (2912ms).
[14:02:41.796] <TB1> INFO: Test took 3769ms.
[14:02:42.087] <TB1> INFO: Expecting 41600 events.
[14:02:45.675] <TB1> INFO: 41600 events read in total (2996ms).
[14:02:45.676] <TB1> INFO: Test took 3856ms.
[14:02:45.968] <TB1> INFO: Expecting 41600 events.
[14:02:49.442] <TB1> INFO: 41600 events read in total (2882ms).
[14:02:49.443] <TB1> INFO: Test took 3740ms.
[14:02:49.733] <TB1> INFO: Expecting 41600 events.
[14:02:53.261] <TB1> INFO: 41600 events read in total (2936ms).
[14:02:53.262] <TB1> INFO: Test took 3795ms.
[14:02:53.551] <TB1> INFO: Expecting 41600 events.
[14:02:57.048] <TB1> INFO: 41600 events read in total (2905ms).
[14:02:57.049] <TB1> INFO: Test took 3763ms.
[14:02:57.364] <TB1> INFO: Expecting 41600 events.
[14:03:00.869] <TB1> INFO: 41600 events read in total (2914ms).
[14:03:00.870] <TB1> INFO: Test took 3796ms.
[14:03:01.163] <TB1> INFO: Expecting 41600 events.
[14:03:04.701] <TB1> INFO: 41600 events read in total (2946ms).
[14:03:04.702] <TB1> INFO: Test took 3804ms.
[14:03:04.992] <TB1> INFO: Expecting 41600 events.
[14:03:08.531] <TB1> INFO: 41600 events read in total (2947ms).
[14:03:08.532] <TB1> INFO: Test took 3805ms.
[14:03:08.822] <TB1> INFO: Expecting 41600 events.
[14:03:12.379] <TB1> INFO: 41600 events read in total (2966ms).
[14:03:12.380] <TB1> INFO: Test took 3823ms.
[14:03:12.670] <TB1> INFO: Expecting 41600 events.
[14:03:16.191] <TB1> INFO: 41600 events read in total (2929ms).
[14:03:16.192] <TB1> INFO: Test took 3787ms.
[14:03:16.481] <TB1> INFO: Expecting 41600 events.
[14:03:20.085] <TB1> INFO: 41600 events read in total (3012ms).
[14:03:20.086] <TB1> INFO: Test took 3870ms.
[14:03:20.377] <TB1> INFO: Expecting 41600 events.
[14:03:23.994] <TB1> INFO: 41600 events read in total (3026ms).
[14:03:23.995] <TB1> INFO: Test took 3885ms.
[14:03:24.288] <TB1> INFO: Expecting 41600 events.
[14:03:27.784] <TB1> INFO: 41600 events read in total (2904ms).
[14:03:27.785] <TB1> INFO: Test took 3762ms.
[14:03:28.074] <TB1> INFO: Expecting 41600 events.
[14:03:31.579] <TB1> INFO: 41600 events read in total (2913ms).
[14:03:31.581] <TB1> INFO: Test took 3772ms.
[14:03:31.871] <TB1> INFO: Expecting 41600 events.
[14:03:35.377] <TB1> INFO: 41600 events read in total (2914ms).
[14:03:35.377] <TB1> INFO: Test took 3772ms.
[14:03:35.669] <TB1> INFO: Expecting 41600 events.
[14:03:39.199] <TB1> INFO: 41600 events read in total (2938ms).
[14:03:39.200] <TB1> INFO: Test took 3796ms.
[14:03:39.490] <TB1> INFO: Expecting 41600 events.
[14:03:42.966] <TB1> INFO: 41600 events read in total (2885ms).
[14:03:42.966] <TB1> INFO: Test took 3743ms.
[14:03:43.256] <TB1> INFO: Expecting 41600 events.
[14:03:46.814] <TB1> INFO: 41600 events read in total (2967ms).
[14:03:46.815] <TB1> INFO: Test took 3824ms.
[14:03:47.105] <TB1> INFO: Expecting 41600 events.
[14:03:50.658] <TB1> INFO: 41600 events read in total (2961ms).
[14:03:50.659] <TB1> INFO: Test took 3820ms.
[14:03:50.949] <TB1> INFO: Expecting 41600 events.
[14:03:54.447] <TB1> INFO: 41600 events read in total (2906ms).
[14:03:54.448] <TB1> INFO: Test took 3764ms.
[14:03:54.737] <TB1> INFO: Expecting 2560 events.
[14:03:55.621] <TB1> INFO: 2560 events read in total (292ms).
[14:03:55.621] <TB1> INFO: Test took 1160ms.
[14:03:55.929] <TB1> INFO: Expecting 2560 events.
[14:03:56.813] <TB1> INFO: 2560 events read in total (292ms).
[14:03:56.813] <TB1> INFO: Test took 1191ms.
[14:03:57.121] <TB1> INFO: Expecting 2560 events.
[14:03:58.007] <TB1> INFO: 2560 events read in total (294ms).
[14:03:58.007] <TB1> INFO: Test took 1193ms.
[14:03:58.314] <TB1> INFO: Expecting 2560 events.
[14:03:59.200] <TB1> INFO: 2560 events read in total (294ms).
[14:03:59.200] <TB1> INFO: Test took 1192ms.
[14:03:59.507] <TB1> INFO: Expecting 2560 events.
[14:04:00.405] <TB1> INFO: 2560 events read in total (306ms).
[14:04:00.405] <TB1> INFO: Test took 1204ms.
[14:04:00.713] <TB1> INFO: Expecting 2560 events.
[14:04:01.599] <TB1> INFO: 2560 events read in total (294ms).
[14:04:01.599] <TB1> INFO: Test took 1192ms.
[14:04:01.908] <TB1> INFO: Expecting 2560 events.
[14:04:02.790] <TB1> INFO: 2560 events read in total (290ms).
[14:04:02.790] <TB1> INFO: Test took 1189ms.
[14:04:03.097] <TB1> INFO: Expecting 2560 events.
[14:04:03.988] <TB1> INFO: 2560 events read in total (299ms).
[14:04:03.988] <TB1> INFO: Test took 1197ms.
[14:04:04.294] <TB1> INFO: Expecting 2560 events.
[14:04:05.175] <TB1> INFO: 2560 events read in total (288ms).
[14:04:05.176] <TB1> INFO: Test took 1187ms.
[14:04:05.484] <TB1> INFO: Expecting 2560 events.
[14:04:06.365] <TB1> INFO: 2560 events read in total (289ms).
[14:04:06.365] <TB1> INFO: Test took 1188ms.
[14:04:06.671] <TB1> INFO: Expecting 2560 events.
[14:04:07.564] <TB1> INFO: 2560 events read in total (301ms).
[14:04:07.565] <TB1> INFO: Test took 1199ms.
[14:04:07.874] <TB1> INFO: Expecting 2560 events.
[14:04:08.770] <TB1> INFO: 2560 events read in total (303ms).
[14:04:08.771] <TB1> INFO: Test took 1206ms.
[14:04:09.079] <TB1> INFO: Expecting 2560 events.
[14:04:09.975] <TB1> INFO: 2560 events read in total (304ms).
[14:04:09.975] <TB1> INFO: Test took 1204ms.
[14:04:10.282] <TB1> INFO: Expecting 2560 events.
[14:04:11.167] <TB1> INFO: 2560 events read in total (292ms).
[14:04:11.168] <TB1> INFO: Test took 1192ms.
[14:04:11.474] <TB1> INFO: Expecting 2560 events.
[14:04:12.366] <TB1> INFO: 2560 events read in total (300ms).
[14:04:12.366] <TB1> INFO: Test took 1197ms.
[14:04:12.673] <TB1> INFO: Expecting 2560 events.
[14:04:13.564] <TB1> INFO: 2560 events read in total (300ms).
[14:04:13.564] <TB1> INFO: Test took 1197ms.
[14:04:13.570] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:04:13.873] <TB1> INFO: Expecting 655360 events.
[14:04:28.872] <TB1> INFO: 655360 events read in total (14408ms).
[14:04:28.887] <TB1> INFO: Expecting 655360 events.
[14:04:43.986] <TB1> INFO: 655360 events read in total (14696ms).
[14:04:44.011] <TB1> INFO: Expecting 655360 events.
[14:04:59.058] <TB1> INFO: 655360 events read in total (14644ms).
[14:04:59.080] <TB1> INFO: Expecting 655360 events.
[14:05:13.847] <TB1> INFO: 655360 events read in total (14365ms).
[14:05:13.878] <TB1> INFO: Expecting 655360 events.
[14:05:28.527] <TB1> INFO: 655360 events read in total (14246ms).
[14:05:28.560] <TB1> INFO: Expecting 655360 events.
[14:05:43.411] <TB1> INFO: 655360 events read in total (14448ms).
[14:05:43.450] <TB1> INFO: Expecting 655360 events.
[14:05:58.205] <TB1> INFO: 655360 events read in total (14352ms).
[14:05:58.256] <TB1> INFO: Expecting 655360 events.
[14:06:13.014] <TB1> INFO: 655360 events read in total (14355ms).
[14:06:13.072] <TB1> INFO: Expecting 655360 events.
[14:06:27.878] <TB1> INFO: 655360 events read in total (14403ms).
[14:06:27.940] <TB1> INFO: Expecting 655360 events.
[14:06:42.572] <TB1> INFO: 655360 events read in total (14229ms).
[14:06:42.663] <TB1> INFO: Expecting 655360 events.
[14:06:57.437] <TB1> INFO: 655360 events read in total (14371ms).
[14:06:57.509] <TB1> INFO: Expecting 655360 events.
[14:07:12.175] <TB1> INFO: 655360 events read in total (14263ms).
[14:07:12.264] <TB1> INFO: Expecting 655360 events.
[14:07:26.917] <TB1> INFO: 655360 events read in total (14250ms).
[14:07:26.003] <TB1> INFO: Expecting 655360 events.
[14:07:41.702] <TB1> INFO: 655360 events read in total (14296ms).
[14:07:41.803] <TB1> INFO: Expecting 655360 events.
[14:07:56.456] <TB1> INFO: 655360 events read in total (14250ms).
[14:07:56.553] <TB1> INFO: Expecting 655360 events.
[14:08:11.263] <TB1> INFO: 655360 events read in total (14307ms).
[14:08:11.383] <TB1> INFO: Test took 237813ms.
[14:08:11.486] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:08:11.737] <TB1> INFO: Expecting 655360 events.
[14:08:26.432] <TB1> INFO: 655360 events read in total (14104ms).
[14:08:26.448] <TB1> INFO: Expecting 655360 events.
[14:08:41.140] <TB1> INFO: 655360 events read in total (14289ms).
[14:08:41.164] <TB1> INFO: Expecting 655360 events.
[14:08:55.781] <TB1> INFO: 655360 events read in total (14214ms).
[14:08:55.805] <TB1> INFO: Expecting 655360 events.
[14:09:10.347] <TB1> INFO: 655360 events read in total (14139ms).
[14:09:10.379] <TB1> INFO: Expecting 655360 events.
[14:09:24.986] <TB1> INFO: 655360 events read in total (14204ms).
[14:09:25.027] <TB1> INFO: Expecting 655360 events.
[14:09:39.206] <TB1> INFO: 655360 events read in total (13776ms).
[14:09:39.243] <TB1> INFO: Expecting 655360 events.
[14:09:53.384] <TB1> INFO: 655360 events read in total (13738ms).
[14:09:53.446] <TB1> INFO: Expecting 655360 events.
[14:10:07.947] <TB1> INFO: 655360 events read in total (14098ms).
[14:10:07.999] <TB1> INFO: Expecting 655360 events.
[14:10:22.208] <TB1> INFO: 655360 events read in total (13806ms).
[14:10:22.256] <TB1> INFO: Expecting 655360 events.
[14:10:36.733] <TB1> INFO: 655360 events read in total (14074ms).
[14:10:36.795] <TB1> INFO: Expecting 655360 events.
[14:10:51.321] <TB1> INFO: 655360 events read in total (14123ms).
[14:10:51.383] <TB1> INFO: Expecting 655360 events.
[14:11:05.685] <TB1> INFO: 655360 events read in total (13899ms).
[14:11:05.761] <TB1> INFO: Expecting 655360 events.
[14:11:20.025] <TB1> INFO: 655360 events read in total (13861ms).
[14:11:20.113] <TB1> INFO: Expecting 655360 events.
[14:11:34.594] <TB1> INFO: 655360 events read in total (14078ms).
[14:11:34.675] <TB1> INFO: Expecting 655360 events.
[14:11:49.298] <TB1> INFO: 655360 events read in total (14220ms).
[14:11:49.399] <TB1> INFO: Expecting 655360 events.
[14:12:03.871] <TB1> INFO: 655360 events read in total (14069ms).
[14:12:03.970] <TB1> INFO: Test took 232484ms.
[14:12:04.141] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.147] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.153] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:12:04.158] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[14:12:04.164] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[14:12:04.169] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.175] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:12:04.181] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.187] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.193] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.200] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:12:04.206] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[14:12:04.212] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[14:12:04.219] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[14:12:04.225] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.230] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:12:04.236] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[14:12:04.242] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[14:12:04.247] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[14:12:04.253] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[14:12:04.259] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[14:12:04.265] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[14:12:04.271] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.277] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.283] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.289] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.295] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:12:04.300] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[14:12:04.306] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[14:12:04.312] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[14:12:04.319] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[14:12:04.324] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[14:12:04.331] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[14:12:04.337] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[14:12:04.343] <TB1> INFO: safety margin for low PH: adding 9, margin is now 29
[14:12:04.349] <TB1> INFO: safety margin for low PH: adding 10, margin is now 30
[14:12:04.356] <TB1> INFO: safety margin for low PH: adding 11, margin is now 31
[14:12:04.362] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.368] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.374] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[14:12:04.380] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[14:12:04.386] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.392] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.398] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[14:12:04.434] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C0.dat
[14:12:04.435] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C1.dat
[14:12:04.435] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C2.dat
[14:12:04.435] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C3.dat
[14:12:04.435] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C4.dat
[14:12:04.435] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C5.dat
[14:12:04.436] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C6.dat
[14:12:04.436] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C7.dat
[14:12:04.436] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C8.dat
[14:12:04.436] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C9.dat
[14:12:04.436] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C10.dat
[14:12:04.437] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C11.dat
[14:12:04.437] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C12.dat
[14:12:04.437] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C13.dat
[14:12:04.437] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C14.dat
[14:12:04.437] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters35_C15.dat
[14:12:04.696] <TB1> INFO: Expecting 41600 events.
[14:12:07.819] <TB1> INFO: 41600 events read in total (2531ms).
[14:12:07.820] <TB1> INFO: Test took 3378ms.
[14:12:08.273] <TB1> INFO: Expecting 41600 events.
[14:12:11.313] <TB1> INFO: 41600 events read in total (2448ms).
[14:12:11.314] <TB1> INFO: Test took 3278ms.
[14:12:11.772] <TB1> INFO: Expecting 41600 events.
[14:12:14.883] <TB1> INFO: 41600 events read in total (2519ms).
[14:12:14.884] <TB1> INFO: Test took 3358ms.
[14:12:15.102] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:15.192] <TB1> INFO: Expecting 2560 events.
[14:12:16.091] <TB1> INFO: 2560 events read in total (308ms).
[14:12:16.091] <TB1> INFO: Test took 989ms.
[14:12:16.096] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:16.399] <TB1> INFO: Expecting 2560 events.
[14:12:17.292] <TB1> INFO: 2560 events read in total (302ms).
[14:12:17.293] <TB1> INFO: Test took 1197ms.
[14:12:17.296] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:17.601] <TB1> INFO: Expecting 2560 events.
[14:12:18.495] <TB1> INFO: 2560 events read in total (302ms).
[14:12:18.495] <TB1> INFO: Test took 1199ms.
[14:12:18.498] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:18.804] <TB1> INFO: Expecting 2560 events.
[14:12:19.695] <TB1> INFO: 2560 events read in total (300ms).
[14:12:19.695] <TB1> INFO: Test took 1197ms.
[14:12:19.697] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:20.004] <TB1> INFO: Expecting 2560 events.
[14:12:20.889] <TB1> INFO: 2560 events read in total (293ms).
[14:12:20.890] <TB1> INFO: Test took 1193ms.
[14:12:20.893] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:21.200] <TB1> INFO: Expecting 2560 events.
[14:12:22.087] <TB1> INFO: 2560 events read in total (295ms).
[14:12:22.088] <TB1> INFO: Test took 1195ms.
[14:12:22.093] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:22.396] <TB1> INFO: Expecting 2560 events.
[14:12:23.284] <TB1> INFO: 2560 events read in total (297ms).
[14:12:23.284] <TB1> INFO: Test took 1191ms.
[14:12:23.286] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:23.593] <TB1> INFO: Expecting 2560 events.
[14:12:24.482] <TB1> INFO: 2560 events read in total (298ms).
[14:12:24.483] <TB1> INFO: Test took 1197ms.
[14:12:24.485] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:24.791] <TB1> INFO: Expecting 2560 events.
[14:12:25.674] <TB1> INFO: 2560 events read in total (291ms).
[14:12:25.674] <TB1> INFO: Test took 1189ms.
[14:12:25.676] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:25.982] <TB1> INFO: Expecting 2560 events.
[14:12:26.868] <TB1> INFO: 2560 events read in total (294ms).
[14:12:26.869] <TB1> INFO: Test took 1193ms.
[14:12:26.871] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:27.177] <TB1> INFO: Expecting 2560 events.
[14:12:28.065] <TB1> INFO: 2560 events read in total (295ms).
[14:12:28.066] <TB1> INFO: Test took 1195ms.
[14:12:28.076] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:28.374] <TB1> INFO: Expecting 2560 events.
[14:12:29.256] <TB1> INFO: 2560 events read in total (290ms).
[14:12:29.257] <TB1> INFO: Test took 1181ms.
[14:12:29.260] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:29.566] <TB1> INFO: Expecting 2560 events.
[14:12:30.456] <TB1> INFO: 2560 events read in total (298ms).
[14:12:30.456] <TB1> INFO: Test took 1196ms.
[14:12:30.459] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:30.765] <TB1> INFO: Expecting 2560 events.
[14:12:31.646] <TB1> INFO: 2560 events read in total (289ms).
[14:12:31.646] <TB1> INFO: Test took 1188ms.
[14:12:31.648] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:31.955] <TB1> INFO: Expecting 2560 events.
[14:12:32.846] <TB1> INFO: 2560 events read in total (299ms).
[14:12:32.847] <TB1> INFO: Test took 1199ms.
[14:12:32.850] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:33.155] <TB1> INFO: Expecting 2560 events.
[14:12:34.039] <TB1> INFO: 2560 events read in total (293ms).
[14:12:34.040] <TB1> INFO: Test took 1190ms.
[14:12:34.042] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:34.349] <TB1> INFO: Expecting 2560 events.
[14:12:35.236] <TB1> INFO: 2560 events read in total (296ms).
[14:12:35.236] <TB1> INFO: Test took 1194ms.
[14:12:35.239] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:35.545] <TB1> INFO: Expecting 2560 events.
[14:12:36.427] <TB1> INFO: 2560 events read in total (291ms).
[14:12:36.427] <TB1> INFO: Test took 1188ms.
[14:12:36.430] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:36.735] <TB1> INFO: Expecting 2560 events.
[14:12:37.617] <TB1> INFO: 2560 events read in total (291ms).
[14:12:37.618] <TB1> INFO: Test took 1188ms.
[14:12:37.620] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:37.927] <TB1> INFO: Expecting 2560 events.
[14:12:38.821] <TB1> INFO: 2560 events read in total (302ms).
[14:12:38.822] <TB1> INFO: Test took 1202ms.
[14:12:38.825] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:39.129] <TB1> INFO: Expecting 2560 events.
[14:12:40.018] <TB1> INFO: 2560 events read in total (297ms).
[14:12:40.018] <TB1> INFO: Test took 1193ms.
[14:12:40.022] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:40.327] <TB1> INFO: Expecting 2560 events.
[14:12:41.207] <TB1> INFO: 2560 events read in total (288ms).
[14:12:41.208] <TB1> INFO: Test took 1186ms.
[14:12:41.213] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:41.516] <TB1> INFO: Expecting 2560 events.
[14:12:42.402] <TB1> INFO: 2560 events read in total (294ms).
[14:12:42.403] <TB1> INFO: Test took 1190ms.
[14:12:42.406] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:42.711] <TB1> INFO: Expecting 2560 events.
[14:12:43.598] <TB1> INFO: 2560 events read in total (295ms).
[14:12:43.599] <TB1> INFO: Test took 1194ms.
[14:12:43.602] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:43.907] <TB1> INFO: Expecting 2560 events.
[14:12:44.796] <TB1> INFO: 2560 events read in total (298ms).
[14:12:44.797] <TB1> INFO: Test took 1196ms.
[14:12:44.800] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:45.105] <TB1> INFO: Expecting 2560 events.
[14:12:46.004] <TB1> INFO: 2560 events read in total (307ms).
[14:12:46.004] <TB1> INFO: Test took 1204ms.
[14:12:46.008] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:46.312] <TB1> INFO: Expecting 2560 events.
[14:12:47.208] <TB1> INFO: 2560 events read in total (304ms).
[14:12:47.209] <TB1> INFO: Test took 1202ms.
[14:12:47.212] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:47.516] <TB1> INFO: Expecting 2560 events.
[14:12:48.412] <TB1> INFO: 2560 events read in total (304ms).
[14:12:48.412] <TB1> INFO: Test took 1200ms.
[14:12:48.415] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:48.720] <TB1> INFO: Expecting 2560 events.
[14:12:49.614] <TB1> INFO: 2560 events read in total (302ms).
[14:12:49.614] <TB1> INFO: Test took 1199ms.
[14:12:49.617] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:49.922] <TB1> INFO: Expecting 2560 events.
[14:12:50.816] <TB1> INFO: 2560 events read in total (302ms).
[14:12:50.817] <TB1> INFO: Test took 1200ms.
[14:12:50.820] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:51.125] <TB1> INFO: Expecting 2560 events.
[14:12:52.023] <TB1> INFO: 2560 events read in total (307ms).
[14:12:52.023] <TB1> INFO: Test took 1204ms.
[14:12:52.026] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:12:52.331] <TB1> INFO: Expecting 2560 events.
[14:12:53.226] <TB1> INFO: 2560 events read in total (303ms).
[14:12:53.226] <TB1> INFO: Test took 1200ms.
[14:12:53.716] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 651 seconds
[14:12:53.717] <TB1> INFO: PH scale (per ROC): 36 51 43 51 32 46 48 62 36 66 36 45 42 39 46 43
[14:12:53.717] <TB1> INFO: PH offset (per ROC): 108 123 106 122 102 97 121 123 108 124 80 109 106 101 84 105
[14:12:53.730] <TB1> INFO: Decoding statistics:
[14:12:53.730] <TB1> INFO: General information:
[14:12:53.730] <TB1> INFO: 16bit words read: 127896
[14:12:53.730] <TB1> INFO: valid events total: 20480
[14:12:53.730] <TB1> INFO: empty events: 17972
[14:12:53.730] <TB1> INFO: valid events with pixels: 2508
[14:12:53.730] <TB1> INFO: valid pixel hits: 2508
[14:12:53.730] <TB1> INFO: Event errors: 0
[14:12:53.730] <TB1> INFO: start marker: 0
[14:12:53.730] <TB1> INFO: stop marker: 0
[14:12:53.730] <TB1> INFO: overflow: 0
[14:12:53.730] <TB1> INFO: invalid 5bit words: 0
[14:12:53.730] <TB1> INFO: invalid XOR eye diagram: 0
[14:12:53.730] <TB1> INFO: frame (failed synchr.): 0
[14:12:53.730] <TB1> INFO: idle data (no TBM trl): 0
[14:12:53.730] <TB1> INFO: no data (only TBM hdr): 0
[14:12:53.730] <TB1> INFO: TBM errors: 0
[14:12:53.730] <TB1> INFO: flawed TBM headers: 0
[14:12:53.730] <TB1> INFO: flawed TBM trailers: 0
[14:12:53.730] <TB1> INFO: event ID mismatches: 0
[14:12:53.731] <TB1> INFO: ROC errors: 0
[14:12:53.731] <TB1> INFO: missing ROC header(s): 0
[14:12:53.731] <TB1> INFO: misplaced readback start: 0
[14:12:53.731] <TB1> INFO: Pixel decoding errors: 0
[14:12:53.731] <TB1> INFO: pixel data incomplete: 0
[14:12:53.731] <TB1> INFO: pixel address: 0
[14:12:53.731] <TB1> INFO: pulse height fill bit: 0
[14:12:53.731] <TB1> INFO: buffer corruption: 0
[14:12:53.922] <TB1> INFO: ######################################################################
[14:12:53.922] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[14:12:53.922] <TB1> INFO: ######################################################################
[14:12:53.936] <TB1> INFO: scanning low vcal = 10
[14:12:54.181] <TB1> INFO: Expecting 41600 events.
[14:12:57.789] <TB1> INFO: 41600 events read in total (3017ms).
[14:12:57.789] <TB1> INFO: Test took 3853ms.
[14:12:57.791] <TB1> INFO: scanning low vcal = 20
[14:12:58.086] <TB1> INFO: Expecting 41600 events.
[14:13:01.693] <TB1> INFO: 41600 events read in total (3015ms).
[14:13:01.693] <TB1> INFO: Test took 3902ms.
[14:13:01.695] <TB1> INFO: scanning low vcal = 30
[14:13:01.989] <TB1> INFO: Expecting 41600 events.
[14:13:05.668] <TB1> INFO: 41600 events read in total (3087ms).
[14:13:05.669] <TB1> INFO: Test took 3974ms.
[14:13:05.671] <TB1> INFO: scanning low vcal = 40
[14:13:05.949] <TB1> INFO: Expecting 41600 events.
[14:13:09.966] <TB1> INFO: 41600 events read in total (3425ms).
[14:13:09.968] <TB1> INFO: Test took 4296ms.
[14:13:09.972] <TB1> INFO: scanning low vcal = 50
[14:13:10.248] <TB1> INFO: Expecting 41600 events.
[14:13:14.271] <TB1> INFO: 41600 events read in total (3431ms).
[14:13:14.272] <TB1> INFO: Test took 4300ms.
[14:13:14.276] <TB1> INFO: scanning low vcal = 60
[14:13:14.553] <TB1> INFO: Expecting 41600 events.
[14:13:18.593] <TB1> INFO: 41600 events read in total (3449ms).
[14:13:18.594] <TB1> INFO: Test took 4318ms.
[14:13:18.597] <TB1> INFO: scanning low vcal = 70
[14:13:18.874] <TB1> INFO: Expecting 41600 events.
[14:13:22.887] <TB1> INFO: 41600 events read in total (3421ms).
[14:13:22.887] <TB1> INFO: Test took 4290ms.
[14:13:22.891] <TB1> INFO: scanning low vcal = 80
[14:13:23.168] <TB1> INFO: Expecting 41600 events.
[14:13:27.216] <TB1> INFO: 41600 events read in total (3456ms).
[14:13:27.217] <TB1> INFO: Test took 4326ms.
[14:13:27.220] <TB1> INFO: scanning low vcal = 90
[14:13:27.496] <TB1> INFO: Expecting 41600 events.
[14:13:31.479] <TB1> INFO: 41600 events read in total (3391ms).
[14:13:31.480] <TB1> INFO: Test took 4259ms.
[14:13:31.484] <TB1> INFO: scanning low vcal = 100
[14:13:31.759] <TB1> INFO: Expecting 41600 events.
[14:13:35.743] <TB1> INFO: 41600 events read in total (3389ms).
[14:13:35.744] <TB1> INFO: Test took 4260ms.
[14:13:35.747] <TB1> INFO: scanning low vcal = 110
[14:13:36.024] <TB1> INFO: Expecting 41600 events.
[14:13:40.060] <TB1> INFO: 41600 events read in total (3444ms).
[14:13:40.062] <TB1> INFO: Test took 4315ms.
[14:13:40.068] <TB1> INFO: scanning low vcal = 120
[14:13:40.364] <TB1> INFO: Expecting 41600 events.
[14:13:44.362] <TB1> INFO: 41600 events read in total (3406ms).
[14:13:44.362] <TB1> INFO: Test took 4293ms.
[14:13:44.366] <TB1> INFO: scanning low vcal = 130
[14:13:44.643] <TB1> INFO: Expecting 41600 events.
[14:13:48.649] <TB1> INFO: 41600 events read in total (3411ms).
[14:13:48.651] <TB1> INFO: Test took 4285ms.
[14:13:48.654] <TB1> INFO: scanning low vcal = 140
[14:13:48.931] <TB1> INFO: Expecting 41600 events.
[14:13:52.930] <TB1> INFO: 41600 events read in total (3407ms).
[14:13:52.931] <TB1> INFO: Test took 4276ms.
[14:13:52.934] <TB1> INFO: scanning low vcal = 150
[14:13:53.211] <TB1> INFO: Expecting 41600 events.
[14:13:57.176] <TB1> INFO: 41600 events read in total (3373ms).
[14:13:57.177] <TB1> INFO: Test took 4243ms.
[14:13:57.181] <TB1> INFO: scanning low vcal = 160
[14:13:57.483] <TB1> INFO: Expecting 41600 events.
[14:14:01.468] <TB1> INFO: 41600 events read in total (3393ms).
[14:14:01.469] <TB1> INFO: Test took 4287ms.
[14:14:01.472] <TB1> INFO: scanning low vcal = 170
[14:14:01.749] <TB1> INFO: Expecting 41600 events.
[14:14:05.752] <TB1> INFO: 41600 events read in total (3411ms).
[14:14:05.753] <TB1> INFO: Test took 4281ms.
[14:14:05.759] <TB1> INFO: scanning low vcal = 180
[14:14:06.037] <TB1> INFO: Expecting 41600 events.
[14:14:10.038] <TB1> INFO: 41600 events read in total (3409ms).
[14:14:10.039] <TB1> INFO: Test took 4280ms.
[14:14:10.043] <TB1> INFO: scanning low vcal = 190
[14:14:10.329] <TB1> INFO: Expecting 41600 events.
[14:14:14.283] <TB1> INFO: 41600 events read in total (3362ms).
[14:14:14.284] <TB1> INFO: Test took 4241ms.
[14:14:14.287] <TB1> INFO: scanning low vcal = 200
[14:14:14.564] <TB1> INFO: Expecting 41600 events.
[14:14:18.533] <TB1> INFO: 41600 events read in total (3378ms).
[14:14:18.534] <TB1> INFO: Test took 4246ms.
[14:14:18.540] <TB1> INFO: scanning low vcal = 210
[14:14:18.814] <TB1> INFO: Expecting 41600 events.
[14:14:22.771] <TB1> INFO: 41600 events read in total (3365ms).
[14:14:22.772] <TB1> INFO: Test took 4232ms.
[14:14:22.776] <TB1> INFO: scanning low vcal = 220
[14:14:23.053] <TB1> INFO: Expecting 41600 events.
[14:14:27.024] <TB1> INFO: 41600 events read in total (3380ms).
[14:14:27.025] <TB1> INFO: Test took 4249ms.
[14:14:27.030] <TB1> INFO: scanning low vcal = 230
[14:14:27.305] <TB1> INFO: Expecting 41600 events.
[14:14:31.250] <TB1> INFO: 41600 events read in total (3354ms).
[14:14:31.251] <TB1> INFO: Test took 4221ms.
[14:14:31.256] <TB1> INFO: scanning low vcal = 240
[14:14:31.531] <TB1> INFO: Expecting 41600 events.
[14:14:35.467] <TB1> INFO: 41600 events read in total (3344ms).
[14:14:35.468] <TB1> INFO: Test took 4212ms.
[14:14:35.472] <TB1> INFO: scanning low vcal = 250
[14:14:35.753] <TB1> INFO: Expecting 41600 events.
[14:14:39.752] <TB1> INFO: 41600 events read in total (3407ms).
[14:14:39.753] <TB1> INFO: Test took 4281ms.
[14:14:39.758] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[14:14:40.033] <TB1> INFO: Expecting 41600 events.
[14:14:44.019] <TB1> INFO: 41600 events read in total (3394ms).
[14:14:44.020] <TB1> INFO: Test took 4262ms.
[14:14:44.023] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[14:14:44.300] <TB1> INFO: Expecting 41600 events.
[14:14:48.316] <TB1> INFO: 41600 events read in total (3425ms).
[14:14:48.317] <TB1> INFO: Test took 4294ms.
[14:14:48.320] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[14:14:48.598] <TB1> INFO: Expecting 41600 events.
[14:14:52.575] <TB1> INFO: 41600 events read in total (3386ms).
[14:14:52.576] <TB1> INFO: Test took 4255ms.
[14:14:52.580] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[14:14:52.856] <TB1> INFO: Expecting 41600 events.
[14:14:56.843] <TB1> INFO: 41600 events read in total (3396ms).
[14:14:56.843] <TB1> INFO: Test took 4263ms.
[14:14:56.847] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[14:14:57.123] <TB1> INFO: Expecting 41600 events.
[14:15:01.137] <TB1> INFO: 41600 events read in total (3423ms).
[14:15:01.139] <TB1> INFO: Test took 4292ms.
[14:15:01.609] <TB1> INFO: PixTestGainPedestal::measure() done
[14:15:38.880] <TB1> INFO: PixTestGainPedestal::fit() done
[14:15:38.880] <TB1> INFO: non-linearity mean: 0.924 0.979 0.944 0.981 0.955 0.944 0.980 0.983 0.981 0.984 0.977 0.945 0.942 0.906 0.921 0.884
[14:15:38.880] <TB1> INFO: non-linearity RMS: 0.156 0.004 0.067 0.004 0.186 0.174 0.003 0.003 0.175 0.003 0.194 0.075 0.076 0.117 0.169 0.163
[14:15:38.880] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C0.dat
[14:15:38.893] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C1.dat
[14:15:38.907] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C2.dat
[14:15:38.921] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C3.dat
[14:15:38.935] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C4.dat
[14:15:38.950] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C5.dat
[14:15:38.963] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C6.dat
[14:15:38.977] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C7.dat
[14:15:38.990] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C8.dat
[14:15:39.004] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C9.dat
[14:15:39.017] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C10.dat
[14:15:39.031] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C11.dat
[14:15:39.044] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C12.dat
[14:15:39.058] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C13.dat
[14:15:39.072] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C14.dat
[14:15:39.086] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//phCalibrationFitErr35_C15.dat
[14:15:39.104] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 165 seconds
[14:15:39.104] <TB1> INFO: Decoding statistics:
[14:15:39.104] <TB1> INFO: General information:
[14:15:39.104] <TB1> INFO: 16bit words read: 3318350
[14:15:39.104] <TB1> INFO: valid events total: 332800
[14:15:39.104] <TB1> INFO: empty events: 345
[14:15:39.104] <TB1> INFO: valid events with pixels: 332455
[14:15:39.104] <TB1> INFO: valid pixel hits: 660775
[14:15:39.104] <TB1> INFO: Event errors: 0
[14:15:39.104] <TB1> INFO: start marker: 0
[14:15:39.104] <TB1> INFO: stop marker: 0
[14:15:39.104] <TB1> INFO: overflow: 0
[14:15:39.104] <TB1> INFO: invalid 5bit words: 0
[14:15:39.104] <TB1> INFO: invalid XOR eye diagram: 0
[14:15:39.104] <TB1> INFO: frame (failed synchr.): 0
[14:15:39.104] <TB1> INFO: idle data (no TBM trl): 0
[14:15:39.104] <TB1> INFO: no data (only TBM hdr): 0
[14:15:39.104] <TB1> INFO: TBM errors: 0
[14:15:39.104] <TB1> INFO: flawed TBM headers: 0
[14:15:39.104] <TB1> INFO: flawed TBM trailers: 0
[14:15:39.104] <TB1> INFO: event ID mismatches: 0
[14:15:39.104] <TB1> INFO: ROC errors: 0
[14:15:39.104] <TB1> INFO: missing ROC header(s): 0
[14:15:39.104] <TB1> INFO: misplaced readback start: 0
[14:15:39.104] <TB1> INFO: Pixel decoding errors: 0
[14:15:39.104] <TB1> INFO: pixel data incomplete: 0
[14:15:39.104] <TB1> INFO: pixel address: 0
[14:15:39.104] <TB1> INFO: pulse height fill bit: 0
[14:15:39.104] <TB1> INFO: buffer corruption: 0
[14:15:39.127] <TB1> INFO: Decoding statistics:
[14:15:39.127] <TB1> INFO: General information:
[14:15:39.127] <TB1> INFO: 16bit words read: 3447782
[14:15:39.127] <TB1> INFO: valid events total: 353536
[14:15:39.127] <TB1> INFO: empty events: 18573
[14:15:39.127] <TB1> INFO: valid events with pixels: 334963
[14:15:39.127] <TB1> INFO: valid pixel hits: 663283
[14:15:39.127] <TB1> INFO: Event errors: 0
[14:15:39.127] <TB1> INFO: start marker: 0
[14:15:39.127] <TB1> INFO: stop marker: 0
[14:15:39.127] <TB1> INFO: overflow: 0
[14:15:39.127] <TB1> INFO: invalid 5bit words: 0
[14:15:39.127] <TB1> INFO: invalid XOR eye diagram: 0
[14:15:39.127] <TB1> INFO: frame (failed synchr.): 0
[14:15:39.127] <TB1> INFO: idle data (no TBM trl): 0
[14:15:39.127] <TB1> INFO: no data (only TBM hdr): 0
[14:15:39.127] <TB1> INFO: TBM errors: 0
[14:15:39.127] <TB1> INFO: flawed TBM headers: 0
[14:15:39.128] <TB1> INFO: flawed TBM trailers: 0
[14:15:39.128] <TB1> INFO: event ID mismatches: 0
[14:15:39.128] <TB1> INFO: ROC errors: 0
[14:15:39.128] <TB1> INFO: missing ROC header(s): 0
[14:15:39.128] <TB1> INFO: misplaced readback start: 0
[14:15:39.128] <TB1> INFO: Pixel decoding errors: 0
[14:15:39.128] <TB1> INFO: pixel data incomplete: 0
[14:15:39.128] <TB1> INFO: pixel address: 0
[14:15:39.128] <TB1> INFO: pulse height fill bit: 0
[14:15:39.128] <TB1> INFO: buffer corruption: 0
[14:15:39.128] <TB1> INFO: enter test to run
[14:15:39.128] <TB1> INFO: test: trim80 no parameter change
[14:15:39.128] <TB1> INFO: running: trim80
[14:15:39.130] <TB1> INFO: ######################################################################
[14:15:39.130] <TB1> INFO: PixTestTrim80::doTest()
[14:15:39.130] <TB1> INFO: ######################################################################
[14:15:39.131] <TB1> INFO: ----------------------------------------------------------------------
[14:15:39.131] <TB1> INFO: PixTestTrim80::trimTest() ntrig = 8, vcal = 80
[14:15:39.131] <TB1> INFO: ----------------------------------------------------------------------
[14:15:39.179] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[14:15:39.179] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[14:15:39.193] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:15:39.193] <TB1> INFO: run 1 of 1
[14:15:39.463] <TB1> INFO: Expecting 5025280 events.
[14:16:08.104] <TB1> INFO: 665248 events read in total (28049ms).
[14:16:35.043] <TB1> INFO: 1330024 events read in total (54988ms).
[14:17:02.237] <TB1> INFO: 1992856 events read in total (82182ms).
[14:17:29.647] <TB1> INFO: 2654328 events read in total (109592ms).
[14:17:56.845] <TB1> INFO: 3316512 events read in total (136790ms).
[14:18:24.031] <TB1> INFO: 3976968 events read in total (163976ms).
[14:18:51.589] <TB1> INFO: 4636432 events read in total (191534ms).
[14:19:08.128] <TB1> INFO: 5025280 events read in total (208073ms).
[14:19:08.218] <TB1> INFO: Test took 209026ms.
[14:19:31.751] <TB1> INFO: ROC 0 VthrComp = 73
[14:19:31.752] <TB1> INFO: ROC 1 VthrComp = 64
[14:19:31.752] <TB1> INFO: ROC 2 VthrComp = 87
[14:19:31.752] <TB1> INFO: ROC 3 VthrComp = 73
[14:19:31.752] <TB1> INFO: ROC 4 VthrComp = 67
[14:19:31.752] <TB1> INFO: ROC 5 VthrComp = 71
[14:19:31.752] <TB1> INFO: ROC 6 VthrComp = 70
[14:19:31.752] <TB1> INFO: ROC 7 VthrComp = 72
[14:19:31.752] <TB1> INFO: ROC 8 VthrComp = 74
[14:19:31.752] <TB1> INFO: ROC 9 VthrComp = 73
[14:19:31.753] <TB1> INFO: ROC 10 VthrComp = 74
[14:19:31.753] <TB1> INFO: ROC 11 VthrComp = 67
[14:19:31.753] <TB1> INFO: ROC 12 VthrComp = 71
[14:19:31.753] <TB1> INFO: ROC 13 VthrComp = 76
[14:19:31.753] <TB1> INFO: ROC 14 VthrComp = 77
[14:19:31.753] <TB1> INFO: ROC 15 VthrComp = 76
[14:19:31.995] <TB1> INFO: Expecting 41600 events.
[14:19:35.478] <TB1> INFO: 41600 events read in total (2891ms).
[14:19:35.479] <TB1> INFO: Test took 3723ms.
[14:19:35.488] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[14:19:35.488] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[14:19:35.499] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:19:35.500] <TB1> INFO: run 1 of 1
[14:19:35.778] <TB1> INFO: Expecting 5025280 events.
[14:20:03.692] <TB1> INFO: 680480 events read in total (27322ms).
[14:20:31.031] <TB1> INFO: 1358480 events read in total (54661ms).
[14:20:58.145] <TB1> INFO: 2036336 events read in total (81775ms).
[14:21:25.776] <TB1> INFO: 2712712 events read in total (109406ms).
[14:21:53.871] <TB1> INFO: 3386352 events read in total (137501ms).
[14:22:21.186] <TB1> INFO: 4057568 events read in total (164816ms).
[14:22:48.810] <TB1> INFO: 4727928 events read in total (192440ms).
[14:23:01.187] <TB1> INFO: 5025280 events read in total (204817ms).
[14:23:01.256] <TB1> INFO: Test took 205756ms.
[14:23:22.078] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 107.371 for pixel 0/17 mean/min/max = 92.2066/76.873/107.54
[14:23:22.078] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 104.401 for pixel 8/61 mean/min/max = 90.2979/75.9885/104.607
[14:23:22.079] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 108.663 for pixel 0/65 mean/min/max = 91.9168/74.9336/108.9
[14:23:22.080] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 110.429 for pixel 3/72 mean/min/max = 94.0931/77.4481/110.738
[14:23:22.080] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 104.848 for pixel 16/38 mean/min/max = 89.6624/74.1469/105.178
[14:23:22.081] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 104.08 for pixel 51/53 mean/min/max = 89.8659/75.5392/104.193
[14:23:22.081] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 102.673 for pixel 21/71 mean/min/max = 88.7552/74.3449/103.165
[14:23:22.081] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 104.915 for pixel 51/79 mean/min/max = 91.0338/77.0317/105.036
[14:23:22.082] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 109.059 for pixel 0/12 mean/min/max = 93.0075/76.9145/109.101
[14:23:22.082] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 109.066 for pixel 2/77 mean/min/max = 93.0351/76.5928/109.477
[14:23:22.083] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 112.419 for pixel 0/44 mean/min/max = 94.5525/76.6672/112.438
[14:23:22.083] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 105.161 for pixel 23/78 mean/min/max = 89.9468/74.4804/105.413
[14:23:22.084] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 111.5 for pixel 0/12 mean/min/max = 93.1041/74.4102/111.798
[14:23:22.084] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 113.114 for pixel 0/9 mean/min/max = 95.6646/78.0828/113.246
[14:23:22.084] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 109.701 for pixel 42/79 mean/min/max = 93.6448/77.5089/109.781
[14:23:22.085] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 108.357 for pixel 25/79 mean/min/max = 93.1391/77.6958/108.582
[14:23:22.085] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[14:23:22.181] <TB1> INFO: Expecting 411648 events.
[14:23:31.751] <TB1> INFO: 411648 events read in total (8978ms).
[14:23:31.759] <TB1> INFO: Expecting 411648 events.
[14:23:41.045] <TB1> INFO: 411648 events read in total (8873ms).
[14:23:41.058] <TB1> INFO: Expecting 411648 events.
[14:23:50.354] <TB1> INFO: 411648 events read in total (8893ms).
[14:23:50.369] <TB1> INFO: Expecting 411648 events.
[14:23:59.731] <TB1> INFO: 411648 events read in total (8959ms).
[14:23:59.748] <TB1> INFO: Expecting 411648 events.
[14:24:09.100] <TB1> INFO: 411648 events read in total (8949ms).
[14:24:09.119] <TB1> INFO: Expecting 411648 events.
[14:24:18.534] <TB1> INFO: 411648 events read in total (9012ms).
[14:24:18.557] <TB1> INFO: Expecting 411648 events.
[14:24:28.029] <TB1> INFO: 411648 events read in total (9069ms).
[14:24:28.055] <TB1> INFO: Expecting 411648 events.
[14:24:37.405] <TB1> INFO: 411648 events read in total (8947ms).
[14:24:37.433] <TB1> INFO: Expecting 411648 events.
[14:24:46.737] <TB1> INFO: 411648 events read in total (8901ms).
[14:24:46.776] <TB1> INFO: Expecting 411648 events.
[14:24:56.021] <TB1> INFO: 411648 events read in total (8841ms).
[14:24:56.066] <TB1> INFO: Expecting 411648 events.
[14:25:05.385] <TB1> INFO: 411648 events read in total (8916ms).
[14:25:05.430] <TB1> INFO: Expecting 411648 events.
[14:25:14.599] <TB1> INFO: 411648 events read in total (8766ms).
[14:25:14.655] <TB1> INFO: Expecting 411648 events.
[14:25:23.869] <TB1> INFO: 411648 events read in total (8810ms).
[14:25:23.921] <TB1> INFO: Expecting 411648 events.
[14:25:33.311] <TB1> INFO: 411648 events read in total (8987ms).
[14:25:33.378] <TB1> INFO: Expecting 411648 events.
[14:25:42.723] <TB1> INFO: 411648 events read in total (8942ms).
[14:25:42.816] <TB1> INFO: Expecting 411648 events.
[14:25:52.067] <TB1> INFO: 411648 events read in total (8848ms).
[14:25:52.150] <TB1> INFO: Test took 150065ms.
[14:25:53.737] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[14:25:53.749] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:25:53.749] <TB1> INFO: run 1 of 1
[14:25:53.988] <TB1> INFO: Expecting 5025280 events.
[14:26:21.843] <TB1> INFO: 668968 events read in total (27262ms).
[14:26:49.182] <TB1> INFO: 1337088 events read in total (54601ms).
[14:27:16.434] <TB1> INFO: 2005384 events read in total (81853ms).
[14:27:43.754] <TB1> INFO: 2672024 events read in total (109173ms).
[14:28:10.812] <TB1> INFO: 3335104 events read in total (136231ms).
[14:28:37.855] <TB1> INFO: 3995960 events read in total (163274ms).
[14:29:05.905] <TB1> INFO: 4653464 events read in total (191324ms).
[14:29:21.422] <TB1> INFO: 5025280 events read in total (206841ms).
[14:29:21.493] <TB1> INFO: Test took 207743ms.
[14:29:45.242] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 53.119968 .. 104.284463
[14:29:45.483] <TB1> INFO: Expecting 208000 events.
[14:29:55.293] <TB1> INFO: 208000 events read in total (9218ms).
[14:29:55.294] <TB1> INFO: Test took 10051ms.
[14:29:55.342] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 43 .. 114 (-1/-1) hits flags = 528 (plus default)
[14:29:55.356] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:29:55.356] <TB1> INFO: run 1 of 1
[14:29:55.634] <TB1> INFO: Expecting 2396160 events.
[14:30:24.950] <TB1> INFO: 677688 events read in total (28724ms).
[14:30:52.215] <TB1> INFO: 1354128 events read in total (55989ms).
[14:31:20.191] <TB1> INFO: 2026160 events read in total (83965ms).
[14:31:35.772] <TB1> INFO: 2396160 events read in total (99546ms).
[14:31:35.825] <TB1> INFO: Test took 100470ms.
[14:31:55.640] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 59.448108 .. 95.465874
[14:31:55.879] <TB1> INFO: Expecting 208000 events.
[14:32:05.815] <TB1> INFO: 208000 events read in total (9344ms).
[14:32:05.816] <TB1> INFO: Test took 10175ms.
[14:32:05.889] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 49 .. 105 (-1/-1) hits flags = 528 (plus default)
[14:32:05.904] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:32:05.905] <TB1> INFO: run 1 of 1
[14:32:06.230] <TB1> INFO: Expecting 1896960 events.
[14:32:36.494] <TB1> INFO: 685904 events read in total (29659ms).
[14:33:04.343] <TB1> INFO: 1372424 events read in total (57508ms).
[14:33:26.058] <TB1> INFO: 1896960 events read in total (79223ms).
[14:33:26.099] <TB1> INFO: Test took 80195ms.
[14:33:45.557] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 62.086046 .. 91.157026
[14:33:45.794] <TB1> INFO: Expecting 208000 events.
[14:33:55.822] <TB1> INFO: 208000 events read in total (9436ms).
[14:33:55.823] <TB1> INFO: Test took 10265ms.
[14:33:55.871] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 52 .. 101 (-1/-1) hits flags = 528 (plus default)
[14:33:55.885] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:33:55.885] <TB1> INFO: run 1 of 1
[14:33:56.164] <TB1> INFO: Expecting 1664000 events.
[14:34:25.446] <TB1> INFO: 691680 events read in total (28690ms).
[14:34:53.529] <TB1> INFO: 1383576 events read in total (56773ms).
[14:35:05.403] <TB1> INFO: 1664000 events read in total (68647ms).
[14:35:05.435] <TB1> INFO: Test took 69551ms.
[14:35:24.232] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 64.323844 .. 91.157026
[14:35:24.471] <TB1> INFO: Expecting 208000 events.
[14:35:34.280] <TB1> INFO: 208000 events read in total (9218ms).
[14:35:34.281] <TB1> INFO: Test took 10048ms.
[14:35:34.349] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 54 .. 101 (-1/-1) hits flags = 528 (plus default)
[14:35:34.363] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:35:34.363] <TB1> INFO: run 1 of 1
[14:35:34.642] <TB1> INFO: Expecting 1597440 events.
[14:36:03.251] <TB1> INFO: 687664 events read in total (28018ms).
[14:36:31.687] <TB1> INFO: 1374560 events read in total (56454ms).
[14:36:41.115] <TB1> INFO: 1597440 events read in total (65883ms).
[14:36:41.144] <TB1> INFO: Test took 66780ms.
[14:36:57.469] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 60 .. 100
[14:36:57.469] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 60 .. 100 (-1/-1) hits flags = 528 (plus default)
[14:36:57.483] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[14:36:57.483] <TB1> INFO: run 1 of 1
[14:36:57.768] <TB1> INFO: Expecting 1364480 events.
[14:37:25.547] <TB1> INFO: 667096 events read in total (27187ms).
[14:37:53.258] <TB1> INFO: 1335304 events read in total (54898ms).
[14:37:54.869] <TB1> INFO: 1364480 events read in total (56509ms).
[14:37:54.894] <TB1> INFO: Test took 57411ms.
[14:38:12.577] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C0.dat
[14:38:12.577] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C1.dat
[14:38:12.577] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C2.dat
[14:38:12.577] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C3.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C4.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C5.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C6.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C7.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C8.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C9.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C10.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C11.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C12.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C13.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C14.dat
[14:38:12.578] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//dacParameters80_C15.dat
[14:38:12.578] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C0.dat
[14:38:12.584] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C1.dat
[14:38:12.588] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C2.dat
[14:38:12.593] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C3.dat
[14:38:12.598] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C4.dat
[14:38:12.603] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C5.dat
[14:38:12.608] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C6.dat
[14:38:12.612] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C7.dat
[14:38:12.617] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C8.dat
[14:38:12.622] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C9.dat
[14:38:12.627] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C10.dat
[14:38:12.632] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C11.dat
[14:38:12.637] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C12.dat
[14:38:12.642] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C13.dat
[14:38:12.647] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C14.dat
[14:38:12.652] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1097_FullQualification_2016-10-31_10h24m_1477905852//003_FulltestTrim80_p17//trimParameters80_C15.dat
[14:38:12.656] <TB1> INFO: PixTestTrim80::trimTest() done
[14:38:12.656] <TB1> INFO: vtrim: 93 77 111 100 87 81 87 78 102 106 114 82 105 118 104 103
[14:38:12.656] <TB1> INFO: vthrcomp: 73 64 87 73 67 71 70 72 74 73 74 67 71 76 77 76
[14:38:12.656] <TB1> INFO: vcal mean: 79.93 79.87 79.91 79.91 79.84 79.90 79.89 79.93 79.94 79.89 79.95 79.88 79.83 79.92 79.89 79.93
[14:38:12.656] <TB1> INFO: vcal RMS: 0.73 0.79 0.78 0.73 0.83 0.77 0.70 0.65 1.42 0.76 0.73 0.91 0.86 0.78 0.77 0.72
[14:38:12.656] <TB1> INFO: bits mean: 9.30 9.96 9.57 9.46 10.33 10.04 10.60 9.33 9.29 9.55 9.20 10.25 9.79 9.00 9.50 9.45
[14:38:12.656] <TB1> INFO: bits RMS: 2.44 2.32 2.66 2.30 2.43 2.37 2.35 2.43 2.43 2.33 2.43 2.36 2.52 2.35 2.24 2.26
[14:38:12.663] <TB1> INFO: ----------------------------------------------------------------------
[14:38:12.663] <TB1> INFO: PixTestTrim80::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[14:38:12.663] <TB1> INFO: ----------------------------------------------------------------------
[14:38:12.666] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[14:38:12.678] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:38:12.678] <TB1> INFO: run 1 of 1
[14:38:12.917] <TB1> INFO: Expecting 4160000 events.
[14:38:45.638] <TB1> INFO: 748490 events read in total (32129ms).
[14:39:17.154] <TB1> INFO: 1495910 events read in total (63645ms).
[14:39:49.024] <TB1> INFO: 2239940 events read in total (95515ms).
[14:40:20.697] <TB1> INFO: 2979770 events read in total (127188ms).
[14:40:52.426] <TB1> INFO: 3715805 events read in total (158917ms).
[14:41:11.675] <TB1> INFO: 4160000 events read in total (178166ms).
[14:41:11.763] <TB1> INFO: Test took 179085ms.
[14:41:41.248] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 244 (-1/-1) hits flags = 528 (plus default)
[14:41:41.262] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:41:41.262] <TB1> INFO: run 1 of 1
[14:41:41.498] <TB1> INFO: Expecting 5096000 events.
[14:42:13.207] <TB1> INFO: 679505 events read in total (31118ms).
[14:42:43.477] <TB1> INFO: 1358515 events read in total (61388ms).
[14:43:13.583] <TB1> INFO: 2036705 events read in total (91494ms).
[14:43:43.774] <TB1> INFO: 2712000 events read in total (121685ms).
[14:44:14.262] <TB1> INFO: 3385415 events read in total (152173ms).
[14:44:44.479] <TB1> INFO: 4056595 events read in total (182390ms).
[14:45:14.628] <TB1> INFO: 4726330 events read in total (212539ms).
[14:45:31.791] <TB1> INFO: 5096000 events read in total (229702ms).
[14:45:31.934] <TB1> INFO: Test took 230672ms.
[14:46:04.296] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[14:46:04.310] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:46:04.310] <TB1> INFO: run 1 of 1
[14:46:04.555] <TB1> INFO: Expecting 4160000 events.
[14:46:36.512] <TB1> INFO: 725680 events read in total (31365ms).
[14:47:07.662] <TB1> INFO: 1449285 events read in total (62515ms).
[14:47:38.939] <TB1> INFO: 2170005 events read in total (93792ms).
[14:48:10.031] <TB1> INFO: 2886690 events read in total (124884ms).
[14:48:41.338] <TB1> INFO: 3599160 events read in total (156191ms).
[14:49:06.708] <TB1> INFO: 4160000 events read in total (181561ms).
[14:49:06.793] <TB1> INFO: Test took 182482ms.
[14:49:40.970] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 198 (-1/-1) hits flags = 528 (plus default)
[14:49:40.984] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:49:40.984] <TB1> INFO: run 1 of 1
[14:49:41.222] <TB1> INFO: Expecting 4139200 events.
[14:50:13.197] <TB1> INFO: 726815 events read in total (31383ms).
[14:50:44.461] <TB1> INFO: 1452500 events read in total (62647ms).
[14:51:15.944] <TB1> INFO: 2174620 events read in total (94130ms).
[14:51:47.165] <TB1> INFO: 2892230 events read in total (125351ms).
[14:52:18.297] <TB1> INFO: 3605880 events read in total (156483ms).
[14:52:42.062] <TB1> INFO: 4139200 events read in total (180248ms).
[14:52:42.171] <TB1> INFO: Test took 181187ms.
[14:53:09.075] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[14:53:09.088] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[14:53:09.088] <TB1> INFO: run 1 of 1
[14:53:09.336] <TB1> INFO: Expecting 4160000 events.
[14:53:41.132] <TB1> INFO: 725745 events read in total (31205ms).
[14:54:12.395] <TB1> INFO: 1449935 events read in total (62468ms).
[14:54:44.674] <TB1> INFO: 2170925 events read in total (94747ms).
[14:55:16.820] <TB1> INFO: 2888085 events read in total (126893ms).
[14:55:48.612] <TB1> INFO: 3601475 events read in total (158685ms).
[14:56:14.017] <TB1> INFO: 4160000 events read in total (184090ms).
[14:56:14.118] <TB1> INFO: Test took 185029ms.
[14:56:39.749] <TB1> INFO: PixTestTrim80::trimBitTest() done
[14:56:39.750] <TB1> INFO: PixTestTrim80::doTest() done, duration: 2460 seconds
[14:56:40.376] <TB1> INFO: enter test to run
[14:56:40.376] <TB1> INFO: test: exit no parameter change
[14:56:40.608] <TB1> QUIET: Connection to board 154 closed.
[14:56:40.609] <TB1> INFO: pXar: this is the end, my friend