[19:47:38.685] <TB1> INFO: *** Welcome to pxar ***
[19:47:38.685] <TB1> INFO: *** Today: 2016/10/26
[19:47:38.692] <TB1> INFO: *** Version: c8ba-dirty
[19:47:38.692] <TB1> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C15.dat
[19:47:38.693] <TB1> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[19:47:38.693] <TB1> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//defaultMaskFile.dat
[19:47:38.693] <TB1> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters_C15.dat
[19:47:38.797] <TB1> INFO: clk: 4
[19:47:38.797] <TB1> INFO: ctr: 4
[19:47:38.797] <TB1> INFO: sda: 19
[19:47:38.797] <TB1> INFO: tin: 9
[19:47:38.797] <TB1> INFO: level: 15
[19:47:38.797] <TB1> INFO: triggerdelay: 0
[19:47:38.797] <TB1> QUIET: Instanciating API for pxar v2.7.6+61~g7f4a123
[19:47:38.797] <TB1> INFO: Log level: INFO
[19:47:38.808] <TB1> INFO: Found DTB DTB_WXC03A
[19:47:38.819] <TB1> QUIET: Connection to board DTB_WXC03A opened.
[19:47:38.821] <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:
------------------------------------------------------
[19:47:38.823] <TB1> INFO: RPC call hashes of host and DTB match: 486171790
[19:47:40.314] <TB1> INFO: DUT info:
[19:47:40.314] <TB1> INFO: The DUT currently contains the following objects:
[19:47:40.314] <TB1> INFO: 4 TBM Cores tbm10c (4 ON)
[19:47:40.314] <TB1> INFO: TBM Core alpha (0): 7 registers set
[19:47:40.314] <TB1> INFO: TBM Core beta (1): 7 registers set
[19:47:40.314] <TB1> INFO: TBM Core alpha (2): 7 registers set
[19:47:40.314] <TB1> INFO: TBM Core beta (3): 7 registers set
[19:47:40.314] <TB1> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[19:47:40.314] <TB1> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.314] <TB1> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.314] <TB1> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.314] <TB1> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.314] <TB1> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.315] <TB1> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[19:47:40.716] <TB1> INFO: enter 'restricted' command line mode
[19:47:40.716] <TB1> INFO: enter test to run
[19:47:40.716] <TB1> INFO: test: pretest no parameter change
[19:47:40.716] <TB1> INFO: running: pretest
[19:47:40.721] <TB1> INFO: ######################################################################
[19:47:40.721] <TB1> INFO: PixTestPretest::doTest()
[19:47:40.721] <TB1> INFO: ######################################################################
[19:47:40.722] <TB1> INFO: ----------------------------------------------------------------------
[19:47:40.722] <TB1> INFO: PixTestPretest::programROC()
[19:47:40.722] <TB1> INFO: ----------------------------------------------------------------------
[19:47:58.736] <TB1> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[19:47:58.736] <TB1> INFO: IA differences per ROC: 18.5 20.1 18.5 19.3 16.9 20.1 20.1 17.7 18.5 18.5 20.1 21.7 20.9 20.1 19.3 19.3
[19:47:58.791] <TB1> INFO: ----------------------------------------------------------------------
[19:47:58.791] <TB1> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[19:47:58.791] <TB1> INFO: ----------------------------------------------------------------------
[19:48:04.682] <TB1> INFO: PixTestPretest::setVana() done, Module Ia 384.3 mA = 24.0187 mA/ROC
[19:48:04.683] <TB1> INFO: i(loss) [mA/ROC]: 19.3 20.1 19.3 19.3 20.1 19.3 18.5 19.3 19.3 19.3 19.3 18.5 18.5 19.3 19.3 19.3
[19:48:04.715] <TB1> INFO: ----------------------------------------------------------------------
[19:48:04.715] <TB1> INFO: PixTestPretest::findTiming()
[19:48:04.715] <TB1> INFO: ----------------------------------------------------------------------
[19:48:04.715] <TB1> INFO: PixTestCmd::init()

[19:48:36.827] <TB1> INFO: TBM phases: 160MHz: 7, 400MHz: 3, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[19:48:36.827] <TB1> INFO: (success/tries = 100/100), width = 4
[19:48:38.332] <TB1> INFO: ----------------------------------------------------------------------
[19:48:38.332] <TB1> INFO: PixTestPretest::findWorkingPixel()
[19:48:38.332] <TB1> INFO: ----------------------------------------------------------------------
[19:48:38.428] <TB1> INFO: Expecting 231680 events.
[19:48:48.420] <TB1> INFO: 231680 events read in total (9400ms).
[19:48:48.428] <TB1> INFO: Test took 10090ms.
[19:48:48.676] <TB1> INFO: Found working pixel in all ROCs: col/row = 12/22
[19:48:48.710] <TB1> INFO: ----------------------------------------------------------------------
[19:48:48.710] <TB1> INFO: PixTestPretest::setVthrCompCalDel()
[19:48:48.710] <TB1> INFO: ----------------------------------------------------------------------
[19:48:48.805] <TB1> INFO: Expecting 231680 events.
[19:48:58.704] <TB1> INFO: 231680 events read in total (9307ms).
[19:48:58.716] <TB1> INFO: Test took 10001ms.
[19:48:58.984] <TB1> INFO: PixTestPretest::setVthrCompCalDel() done
[19:48:58.984] <TB1> INFO: CalDel: 80 95 86 83 90 88 95 96 69 79 89 99 82 106 87 81
[19:48:58.984] <TB1> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 53 51 51 51 51 51
[19:48:58.989] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C0.dat
[19:48:58.989] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C1.dat
[19:48:58.989] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C2.dat
[19:48:58.990] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C3.dat
[19:48:58.990] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C4.dat
[19:48:58.990] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C5.dat
[19:48:58.990] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C6.dat
[19:48:58.990] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C7.dat
[19:48:58.990] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C8.dat
[19:48:58.991] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C9.dat
[19:48:58.991] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C10.dat
[19:48:58.991] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C11.dat
[19:48:58.991] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C12.dat
[19:48:58.991] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C13.dat
[19:48:58.991] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C14.dat
[19:48:58.992] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters_C15.dat
[19:48:58.992] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//tbmParameters_C0a.dat
[19:48:58.992] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//tbmParameters_C0b.dat
[19:48:58.992] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//tbmParameters_C1a.dat
[19:48:58.992] <TB1> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//tbmParameters_C1b.dat
[19:48:58.992] <TB1> INFO: PixTestPretest::doTest() done, duration: 78 seconds
[19:48:59.048] <TB1> INFO: enter test to run
[19:48:59.048] <TB1> INFO: test: fulltest no parameter change
[19:48:59.048] <TB1> INFO: running: fulltest
[19:48:59.048] <TB1> INFO: ######################################################################
[19:48:59.048] <TB1> INFO: PixTestFullTest::doTest()
[19:48:59.048] <TB1> INFO: ######################################################################
[19:48:59.049] <TB1> INFO: ######################################################################
[19:48:59.049] <TB1> INFO: PixTestAlive::doTest()
[19:48:59.049] <TB1> INFO: ######################################################################
[19:48:59.050] <TB1> INFO: ----------------------------------------------------------------------
[19:48:59.050] <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)
[19:48:59.050] <TB1> INFO: ----------------------------------------------------------------------
[19:48:59.289] <TB1> INFO: Expecting 41600 events.
[19:49:02.776] <TB1> INFO: 41600 events read in total (2895ms).
[19:49:02.776] <TB1> INFO: Test took 3724ms.
[19:49:03.009] <TB1> INFO: PixTestAlive::aliveTest() done
[19:49:03.009] <TB1> INFO: number of dead pixels (per ROC): 0 0 1 1 0 0 0 0 1 1 0 0 0 1 0 0
[19:49:03.011] <TB1> INFO: ----------------------------------------------------------------------
[19:49:03.011] <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)
[19:49:03.011] <TB1> INFO: ----------------------------------------------------------------------
[19:49:03.303] <TB1> INFO: Expecting 41600 events.
[19:49:06.335] <TB1> INFO: 41600 events read in total (2440ms).
[19:49:06.335] <TB1> INFO: Test took 3322ms.
[19:49:06.336] <TB1> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[19:49:06.569] <TB1> INFO: PixTestAlive::maskTest() done
[19:49:06.570] <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
[19:49:06.571] <TB1> INFO: ----------------------------------------------------------------------
[19:49:06.571] <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)
[19:49:06.571] <TB1> INFO: ----------------------------------------------------------------------
[19:49:06.830] <TB1> INFO: Expecting 41600 events.
[19:49:10.347] <TB1> INFO: 41600 events read in total (2925ms).
[19:49:10.348] <TB1> INFO: Test took 3774ms.
[19:49:10.582] <TB1> INFO: PixTestAlive::addressDecodingTest() done
[19:49:10.582] <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
[19:49:10.583] <TB1> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[19:49:10.583] <TB1> INFO: Decoding statistics:
[19:49:10.583] <TB1> INFO: General information:
[19:49:10.583] <TB1> INFO: 16bit words read: 0
[19:49:10.583] <TB1> INFO: valid events total: 0
[19:49:10.583] <TB1> INFO: empty events: 0
[19:49:10.583] <TB1> INFO: valid events with pixels: 0
[19:49:10.583] <TB1> INFO: valid pixel hits: 0
[19:49:10.583] <TB1> INFO: Event errors: 0
[19:49:10.583] <TB1> INFO: start marker: 0
[19:49:10.583] <TB1> INFO: stop marker: 0
[19:49:10.583] <TB1> INFO: overflow: 0
[19:49:10.583] <TB1> INFO: invalid 5bit words: 0
[19:49:10.583] <TB1> INFO: invalid XOR eye diagram: 0
[19:49:10.583] <TB1> INFO: frame (failed synchr.): 0
[19:49:10.583] <TB1> INFO: idle data (no TBM trl): 0
[19:49:10.583] <TB1> INFO: no data (only TBM hdr): 0
[19:49:10.583] <TB1> INFO: TBM errors: 0
[19:49:10.583] <TB1> INFO: flawed TBM headers: 0
[19:49:10.583] <TB1> INFO: flawed TBM trailers: 0
[19:49:10.583] <TB1> INFO: event ID mismatches: 0
[19:49:10.583] <TB1> INFO: ROC errors: 0
[19:49:10.583] <TB1> INFO: missing ROC header(s): 0
[19:49:10.583] <TB1> INFO: misplaced readback start: 0
[19:49:10.583] <TB1> INFO: Pixel decoding errors: 0
[19:49:10.583] <TB1> INFO: pixel data incomplete: 0
[19:49:10.583] <TB1> INFO: pixel address: 0
[19:49:10.584] <TB1> INFO: pulse height fill bit: 0
[19:49:10.584] <TB1> INFO: buffer corruption: 0
[19:49:10.592] <TB1> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C15.dat
[19:49:10.593] <TB1> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr_C15.dat

[19:49:10.593] <TB1> INFO: ######################################################################
[19:49:10.593] <TB1> INFO: PixTestReadback::doTest()
[19:49:10.593] <TB1> INFO: ######################################################################
[19:49:10.593] <TB1> INFO: ----------------------------------------------------------------------
[19:49:10.593] <TB1> INFO: PixTestReadback::CalibrateVd()
[19:49:10.593] <TB1> INFO: ----------------------------------------------------------------------
[19:49:20.550] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C0.dat
[19:49:20.550] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C1.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C2.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C3.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C4.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C5.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C6.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C7.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C8.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C9.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C10.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C11.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C12.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C13.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C14.dat
[19:49:20.551] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C15.dat
[19:49:20.579] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[19:49:20.579] <TB1> INFO: ----------------------------------------------------------------------
[19:49:20.579] <TB1> INFO: PixTestReadback::CalibrateVa()
[19:49:20.579] <TB1> INFO: ----------------------------------------------------------------------
[19:49:30.500] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C0.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C1.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C2.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C3.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C4.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C5.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C6.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C7.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C8.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C9.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C10.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C11.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C12.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C13.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C14.dat
[19:49:30.501] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C15.dat
[19:49:30.533] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[19:49:30.533] <TB1> INFO: ----------------------------------------------------------------------
[19:49:30.533] <TB1> INFO: PixTestReadback::readbackVbg()
[19:49:30.533] <TB1> INFO: ----------------------------------------------------------------------
[19:49:38.205] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[19:49:38.205] <TB1> INFO: ----------------------------------------------------------------------
[19:49:38.205] <TB1> INFO: PixTestReadback::getCalibratedVbg()
[19:49:38.206] <TB1> INFO: ----------------------------------------------------------------------
[19:49:38.206] <TB1> INFO: Vbg will be calibrated using Vd calibration
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 152.5calibrated Vbg = 1.19905 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 152.5calibrated Vbg = 1.2013 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 152.6calibrated Vbg = 1.19954 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 151.1calibrated Vbg = 1.18992 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 156.2calibrated Vbg = 1.19363 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 164.2calibrated Vbg = 1.20489 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 150.1calibrated Vbg = 1.20391 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 151.4calibrated Vbg = 1.20548 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 155calibrated Vbg = 1.19605 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 158calibrated Vbg = 1.19752 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 159.3calibrated Vbg = 1.1854 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 154.8calibrated Vbg = 1.19033 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 159.7calibrated Vbg = 1.19058 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 149.6calibrated Vbg = 1.19861 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 160calibrated Vbg = 1.19039 :::*/*/*/*/
[19:49:38.206] <TB1> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 154.6calibrated Vbg = 1.19458 :::*/*/*/*/
[19:49:38.209] <TB1> INFO: ----------------------------------------------------------------------
[19:49:38.209] <TB1> INFO: PixTestReadback::CalibrateIa()
[19:49:38.209] <TB1> INFO: ----------------------------------------------------------------------
[19:52:19.075] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C0.dat
[19:52:19.075] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C1.dat
[19:52:19.075] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C2.dat
[19:52:19.075] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C3.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C4.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C5.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C6.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C7.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C8.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C9.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C10.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C11.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C12.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C13.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C14.dat
[19:52:19.076] <TB1> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//readbackCal_C15.dat
[19:52:19.108] <TB1> INFO: PixTestPattern:: pg_setup set to default.
[19:52:19.110] <TB1> INFO: PixTestReadback::doTest() done
[19:52:19.110] <TB1> INFO: Decoding statistics:
[19:52:19.111] <TB1> INFO: General information:
[19:52:19.111] <TB1> INFO: 16bit words read: 1536
[19:52:19.111] <TB1> INFO: valid events total: 256
[19:52:19.111] <TB1> INFO: empty events: 256
[19:52:19.111] <TB1> INFO: valid events with pixels: 0
[19:52:19.111] <TB1> INFO: valid pixel hits: 0
[19:52:19.111] <TB1> INFO: Event errors: 0
[19:52:19.111] <TB1> INFO: start marker: 0
[19:52:19.111] <TB1> INFO: stop marker: 0
[19:52:19.111] <TB1> INFO: overflow: 0
[19:52:19.111] <TB1> INFO: invalid 5bit words: 0
[19:52:19.111] <TB1> INFO: invalid XOR eye diagram: 0
[19:52:19.111] <TB1> INFO: frame (failed synchr.): 0
[19:52:19.111] <TB1> INFO: idle data (no TBM trl): 0
[19:52:19.111] <TB1> INFO: no data (only TBM hdr): 0
[19:52:19.111] <TB1> INFO: TBM errors: 0
[19:52:19.111] <TB1> INFO: flawed TBM headers: 0
[19:52:19.111] <TB1> INFO: flawed TBM trailers: 0
[19:52:19.111] <TB1> INFO: event ID mismatches: 0
[19:52:19.111] <TB1> INFO: ROC errors: 0
[19:52:19.111] <TB1> INFO: missing ROC header(s): 0
[19:52:19.111] <TB1> INFO: misplaced readback start: 0
[19:52:19.111] <TB1> INFO: Pixel decoding errors: 0
[19:52:19.111] <TB1> INFO: pixel data incomplete: 0
[19:52:19.111] <TB1> INFO: pixel address: 0
[19:52:19.111] <TB1> INFO: pulse height fill bit: 0
[19:52:19.111] <TB1> INFO: buffer corruption: 0
[19:52:19.179] <TB1> INFO: ######################################################################
[19:52:19.179] <TB1> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[19:52:19.179] <TB1> INFO: ######################################################################
[19:52:19.182] <TB1> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[19:52:19.201] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[19:52:19.201] <TB1> INFO: run 1 of 1
[19:52:19.437] <TB1> INFO: Expecting 3120000 events.
[19:52:50.172] <TB1> INFO: 674250 events read in total (30143ms).




















[19:53:20.338] <TB1> INFO: 1344980 events read in total (60309ms).











[19:53:50.561] <TB1> INFO: 2011125 events read in total (90532ms).











[19:54:20.852] <TB1> INFO: 2675425 events read in total (120823ms).











[19:54:41.096] <TB1> INFO: 3120000 events read in total (141067ms).
[19:54:41.168] <TB1> INFO: Test took 141968ms.
[19:55:03.470] <TB1> INFO: PixTestBBMap::doTest() done, duration: 164 seconds
[19:55:03.470] <TB1> INFO: number of dead bumps (per ROC): 1 0 3 0 0 0 1 0 0 0 0 25 24 6 1 0
[19:55:03.470] <TB1> INFO: separation cut (per ROC): 103 103 110 106 103 110 109 112 104 102 112 118 105 105 113 104
[19:55:03.470] <TB1> INFO: Decoding statistics:
[19:55:03.470] <TB1> INFO: General information:
[19:55:03.470] <TB1> INFO: 16bit words read: 0
[19:55:03.470] <TB1> INFO: valid events total: 0
[19:55:03.470] <TB1> INFO: empty events: 0
[19:55:03.470] <TB1> INFO: valid events with pixels: 0
[19:55:03.470] <TB1> INFO: valid pixel hits: 0
[19:55:03.470] <TB1> INFO: Event errors: 0
[19:55:03.470] <TB1> INFO: start marker: 0
[19:55:03.470] <TB1> INFO: stop marker: 0
[19:55:03.470] <TB1> INFO: overflow: 0
[19:55:03.470] <TB1> INFO: invalid 5bit words: 0
[19:55:03.471] <TB1> INFO: invalid XOR eye diagram: 0
[19:55:03.471] <TB1> INFO: frame (failed synchr.): 0
[19:55:03.471] <TB1> INFO: idle data (no TBM trl): 0
[19:55:03.471] <TB1> INFO: no data (only TBM hdr): 0
[19:55:03.471] <TB1> INFO: TBM errors: 0
[19:55:03.471] <TB1> INFO: flawed TBM headers: 0
[19:55:03.471] <TB1> INFO: flawed TBM trailers: 0
[19:55:03.471] <TB1> INFO: event ID mismatches: 0
[19:55:03.471] <TB1> INFO: ROC errors: 0
[19:55:03.471] <TB1> INFO: missing ROC header(s): 0
[19:55:03.471] <TB1> INFO: misplaced readback start: 0
[19:55:03.471] <TB1> INFO: Pixel decoding errors: 0
[19:55:03.471] <TB1> INFO: pixel data incomplete: 0
[19:55:03.471] <TB1> INFO: pixel address: 0
[19:55:03.471] <TB1> INFO: pulse height fill bit: 0
[19:55:03.471] <TB1> INFO: buffer corruption: 0
[19:55:03.514] <TB1> INFO: ######################################################################
[19:55:03.514] <TB1> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[19:55:03.514] <TB1> INFO: ######################################################################
[19:55:03.514] <TB1> INFO: ----------------------------------------------------------------------
[19:55:03.514] <TB1> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[19:55:03.514] <TB1> INFO: ----------------------------------------------------------------------
[19:55:03.514] <TB1> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[19:55:03.529] <TB1> INFO: dacScan split into 1 runs with ntrig = 50
[19:55:03.529] <TB1> INFO: run 1 of 1
[19:55:03.781] <TB1> INFO: Expecting 36608000 events.
[19:55:27.410] <TB1> INFO: 690900 events read in total (23037ms).
[19:55:50.466] <TB1> INFO: 1365650 events read in total (46093ms).
[19:56:13.420] <TB1> INFO: 2041350 events read in total (69047ms).
[19:56:36.354] <TB1> INFO: 2715900 events read in total (91981ms).
[19:56:59.436] <TB1> INFO: 3389750 events read in total (115063ms).
[19:57:22.318] <TB1> INFO: 4064100 events read in total (137945ms).
[19:57:45.179] <TB1> INFO: 4738600 events read in total (160806ms).
[19:58:08.235] <TB1> INFO: 5409400 events read in total (183862ms).
[19:58:31.283] <TB1> INFO: 6083850 events read in total (206910ms).
[19:58:54.347] <TB1> INFO: 6757100 events read in total (229974ms).
[19:59:17.642] <TB1> INFO: 7429050 events read in total (253270ms).
[19:59:40.457] <TB1> INFO: 8099000 events read in total (276084ms).
[20:00:03.187] <TB1> INFO: 8770050 events read in total (298814ms).
[20:00:26.132] <TB1> INFO: 9439700 events read in total (321759ms).
[20:00:49.100] <TB1> INFO: 10109350 events read in total (344727ms).
[20:01:11.767] <TB1> INFO: 10781200 events read in total (367394ms).
[20:01:34.636] <TB1> INFO: 11453100 events read in total (390263ms).
[20:01:57.421] <TB1> INFO: 12119100 events read in total (413048ms).
[20:02:20.496] <TB1> INFO: 12785600 events read in total (436123ms).
[20:02:43.328] <TB1> INFO: 13454250 events read in total (458955ms).
[20:03:06.226] <TB1> INFO: 14121750 events read in total (481853ms).
[20:03:29.108] <TB1> INFO: 14788750 events read in total (504735ms).
[20:03:52.120] <TB1> INFO: 15452200 events read in total (527747ms).
[20:04:15.285] <TB1> INFO: 16119350 events read in total (550912ms).
[20:04:38.271] <TB1> INFO: 16787000 events read in total (573898ms).
[20:05:00.880] <TB1> INFO: 17451000 events read in total (596507ms).
[20:05:23.815] <TB1> INFO: 18115050 events read in total (619442ms).
[20:05:47.309] <TB1> INFO: 18778500 events read in total (642936ms).
[20:06:10.049] <TB1> INFO: 19442000 events read in total (665676ms).
[20:06:32.898] <TB1> INFO: 20103850 events read in total (688525ms).
[20:06:55.597] <TB1> INFO: 20765750 events read in total (711224ms).
[20:07:18.433] <TB1> INFO: 21427600 events read in total (734060ms).
[20:07:41.636] <TB1> INFO: 22091550 events read in total (757263ms).
[20:08:04.588] <TB1> INFO: 22753300 events read in total (780215ms).
[20:08:27.769] <TB1> INFO: 23414400 events read in total (803396ms).
[20:08:50.611] <TB1> INFO: 24075450 events read in total (826239ms).
[20:09:13.383] <TB1> INFO: 24736150 events read in total (849010ms).
[20:09:36.158] <TB1> INFO: 25396200 events read in total (871785ms).
[20:09:59.403] <TB1> INFO: 26060150 events read in total (895030ms).
[20:10:22.154] <TB1> INFO: 26721950 events read in total (917781ms).
[20:10:44.893] <TB1> INFO: 27382450 events read in total (940520ms).
[20:11:07.640] <TB1> INFO: 28040050 events read in total (963267ms).
[20:11:30.633] <TB1> INFO: 28699550 events read in total (986260ms).
[20:11:53.064] <TB1> INFO: 29356750 events read in total (1008691ms).
[20:12:15.632] <TB1> INFO: 30014750 events read in total (1031259ms).
[20:12:38.067] <TB1> INFO: 30671550 events read in total (1053694ms).
[20:13:00.762] <TB1> INFO: 31328950 events read in total (1076389ms).
[20:13:23.507] <TB1> INFO: 31988650 events read in total (1099134ms).
[20:13:46.232] <TB1> INFO: 32647400 events read in total (1121859ms).
[20:14:09.010] <TB1> INFO: 33307900 events read in total (1144637ms).
[20:14:31.564] <TB1> INFO: 33967300 events read in total (1167191ms).
[20:14:54.444] <TB1> INFO: 34627650 events read in total (1190071ms).
[20:15:17.041] <TB1> INFO: 35286300 events read in total (1212668ms).
[20:15:39.550] <TB1> INFO: 35947900 events read in total (1235177ms).
[20:16:02.088] <TB1> INFO: 36608000 events read in total (1257715ms).
[20:16:02.157] <TB1> INFO: Test took 1258627ms.
[20:16:02.604] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:04.367] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:06.079] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:07.879] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:09.717] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:11.653] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:13.848] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:15.942] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:17.997] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:20.026] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:21.999] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:23.902] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:25.861] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:27.655] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:29.374] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:31.708] <TB1> INFO: dumping ASCII scurve output file: SCurveData
[20:16:34.149] <TB1> INFO: PixTestScurves::scurves() done
[20:16:34.149] <TB1> INFO: Vcal mean: 119.19 111.33 115.37 110.54 120.17 121.26 116.90 112.50 121.12 118.13 128.01 125.44 114.77 120.88 122.37 111.44
[20:16:34.149] <TB1> INFO: Vcal RMS: 5.21 4.85 6.59 5.08 6.11 6.03 5.63 5.46 5.97 5.73 6.11 7.24 5.34 6.75 5.70 4.53
[20:16:34.149] <TB1> INFO: PixTestScurves::fullTest() done, duration: 1290 seconds
[20:16:34.149] <TB1> INFO: Decoding statistics:
[20:16:34.149] <TB1> INFO: General information:
[20:16:34.149] <TB1> INFO: 16bit words read: 0
[20:16:34.149] <TB1> INFO: valid events total: 0
[20:16:34.149] <TB1> INFO: empty events: 0
[20:16:34.149] <TB1> INFO: valid events with pixels: 0
[20:16:34.149] <TB1> INFO: valid pixel hits: 0
[20:16:34.149] <TB1> INFO: Event errors: 0
[20:16:34.149] <TB1> INFO: start marker: 0
[20:16:34.149] <TB1> INFO: stop marker: 0
[20:16:34.149] <TB1> INFO: overflow: 0
[20:16:34.149] <TB1> INFO: invalid 5bit words: 0
[20:16:34.149] <TB1> INFO: invalid XOR eye diagram: 0
[20:16:34.149] <TB1> INFO: frame (failed synchr.): 0
[20:16:34.149] <TB1> INFO: idle data (no TBM trl): 0
[20:16:34.149] <TB1> INFO: no data (only TBM hdr): 0
[20:16:34.149] <TB1> INFO: TBM errors: 0
[20:16:34.149] <TB1> INFO: flawed TBM headers: 0
[20:16:34.149] <TB1> INFO: flawed TBM trailers: 0
[20:16:34.149] <TB1> INFO: event ID mismatches: 0
[20:16:34.149] <TB1> INFO: ROC errors: 0
[20:16:34.149] <TB1> INFO: missing ROC header(s): 0
[20:16:34.149] <TB1> INFO: misplaced readback start: 0
[20:16:34.149] <TB1> INFO: Pixel decoding errors: 0
[20:16:34.149] <TB1> INFO: pixel data incomplete: 0
[20:16:34.149] <TB1> INFO: pixel address: 0
[20:16:34.149] <TB1> INFO: pulse height fill bit: 0
[20:16:34.149] <TB1> INFO: buffer corruption: 0
[20:16:34.243] <TB1> INFO: ######################################################################
[20:16:34.243] <TB1> INFO: PixTestTrim::doTest()
[20:16:34.243] <TB1> INFO: ######################################################################
[20:16:34.244] <TB1> INFO: ----------------------------------------------------------------------
[20:16:34.244] <TB1> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[20:16:34.244] <TB1> INFO: ----------------------------------------------------------------------
[20:16:34.313] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[20:16:34.313] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[20:16:34.327] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:16:34.327] <TB1> INFO: run 1 of 1
[20:16:34.652] <TB1> INFO: Expecting 5025280 events.
[20:17:05.327] <TB1> INFO: 824616 events read in total (30073ms).
[20:17:35.182] <TB1> INFO: 1646480 events read in total (59928ms).
[20:18:04.894] <TB1> INFO: 2464960 events read in total (89641ms).
[20:18:34.879] <TB1> INFO: 3279208 events read in total (119625ms).
[20:19:04.589] <TB1> INFO: 4089752 events read in total (149336ms).
[20:19:34.306] <TB1> INFO: 4898120 events read in total (179053ms).
[20:19:39.161] <TB1> INFO: 5025280 events read in total (183907ms).
[20:19:39.206] <TB1> INFO: Test took 184879ms.
[20:19:57.357] <TB1> INFO: ROC 0 VthrComp = 128
[20:19:57.357] <TB1> INFO: ROC 1 VthrComp = 115
[20:19:57.357] <TB1> INFO: ROC 2 VthrComp = 118
[20:19:57.357] <TB1> INFO: ROC 3 VthrComp = 119
[20:19:57.357] <TB1> INFO: ROC 4 VthrComp = 118
[20:19:57.357] <TB1> INFO: ROC 5 VthrComp = 128
[20:19:57.358] <TB1> INFO: ROC 6 VthrComp = 124
[20:19:57.358] <TB1> INFO: ROC 7 VthrComp = 119
[20:19:57.358] <TB1> INFO: ROC 8 VthrComp = 132
[20:19:57.358] <TB1> INFO: ROC 9 VthrComp = 125
[20:19:57.358] <TB1> INFO: ROC 10 VthrComp = 129
[20:19:57.358] <TB1> INFO: ROC 11 VthrComp = 124
[20:19:57.358] <TB1> INFO: ROC 12 VthrComp = 124
[20:19:57.358] <TB1> INFO: ROC 13 VthrComp = 121
[20:19:57.359] <TB1> INFO: ROC 14 VthrComp = 126
[20:19:57.359] <TB1> INFO: ROC 15 VthrComp = 121
[20:19:57.623] <TB1> INFO: Expecting 41600 events.
[20:20:01.242] <TB1> INFO: 41600 events read in total (3028ms).
[20:20:01.243] <TB1> INFO: Test took 3883ms.
[20:20:01.254] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[20:20:01.254] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[20:20:01.267] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:20:01.267] <TB1> INFO: run 1 of 1
[20:20:01.545] <TB1> INFO: Expecting 5025280 events.
[20:20:27.459] <TB1> INFO: 589984 events read in total (25322ms).
[20:20:53.142] <TB1> INFO: 1178496 events read in total (51005ms).
[20:21:18.473] <TB1> INFO: 1767792 events read in total (76336ms).
[20:21:44.535] <TB1> INFO: 2355936 events read in total (102398ms).
[20:22:10.196] <TB1> INFO: 2942024 events read in total (128059ms).
[20:22:35.760] <TB1> INFO: 3526736 events read in total (153623ms).
[20:23:01.749] <TB1> INFO: 4110224 events read in total (179612ms).
[20:23:27.315] <TB1> INFO: 4692888 events read in total (205178ms).
[20:23:42.633] <TB1> INFO: 5025280 events read in total (220496ms).
[20:23:42.719] <TB1> INFO: Test took 221452ms.
[20:24:07.649] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 57.7279 for pixel 37/1 mean/min/max = 45.2426/32.6258/57.8593
[20:24:07.650] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 58.6116 for pixel 2/2 mean/min/max = 45.7402/32.8261/58.6544
[20:24:07.650] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 61.6252 for pixel 2/42 mean/min/max = 46.2761/30.8813/61.6709
[20:24:07.651] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 56.0432 for pixel 9/64 mean/min/max = 44.163/32.1285/56.1975
[20:24:07.652] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 60.314 for pixel 9/1 mean/min/max = 46.2907/32.2484/60.333
[20:24:07.652] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 58.9749 for pixel 17/9 mean/min/max = 45.5719/32.0437/59.1
[20:24:07.653] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 59.2267 for pixel 10/71 mean/min/max = 46.094/32.7526/59.4353
[20:24:07.653] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 58.8523 for pixel 0/12 mean/min/max = 45.1501/31.3629/58.9373
[20:24:07.654] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 56.3954 for pixel 18/79 mean/min/max = 44.5685/32.7274/56.4097
[20:24:07.654] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 57.6832 for pixel 1/76 mean/min/max = 45.4042/33.1227/57.6858
[20:24:07.655] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 61.0303 for pixel 4/2 mean/min/max = 46.9573/32.8491/61.0655
[20:24:07.655] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 62.7083 for pixel 35/17 mean/min/max = 47.4119/32.0874/62.7364
[20:24:07.656] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 56.8875 for pixel 8/7 mean/min/max = 45.0053/33.0389/56.9717
[20:24:07.656] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 61.7549 for pixel 15/79 mean/min/max = 47.1775/32.5468/61.8082
[20:24:07.657] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 58.6019 for pixel 49/72 mean/min/max = 45.8009/32.9052/58.6965
[20:24:07.657] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 56.0689 for pixel 20/7 mean/min/max = 44.6325/33.0844/56.1806
[20:24:07.658] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:24:07.747] <TB1> INFO: Expecting 411648 events.
[20:24:17.326] <TB1> INFO: 411648 events read in total (8988ms).
[20:24:17.333] <TB1> INFO: Expecting 411648 events.
[20:24:26.409] <TB1> INFO: 411648 events read in total (8673ms).
[20:24:26.419] <TB1> INFO: Expecting 411648 events.
[20:24:35.681] <TB1> INFO: 411648 events read in total (8859ms).
[20:24:35.695] <TB1> INFO: Expecting 411648 events.
[20:24:44.948] <TB1> INFO: 411648 events read in total (8850ms).
[20:24:44.968] <TB1> INFO: Expecting 411648 events.
[20:24:54.342] <TB1> INFO: 411648 events read in total (8971ms).
[20:24:54.360] <TB1> INFO: Expecting 411648 events.
[20:25:03.698] <TB1> INFO: 411648 events read in total (8934ms).
[20:25:03.720] <TB1> INFO: Expecting 411648 events.
[20:25:13.007] <TB1> INFO: 411648 events read in total (8884ms).
[20:25:13.032] <TB1> INFO: Expecting 411648 events.
[20:25:22.447] <TB1> INFO: 411648 events read in total (9012ms).
[20:25:22.476] <TB1> INFO: Expecting 411648 events.
[20:25:31.810] <TB1> INFO: 411648 events read in total (8931ms).
[20:25:31.841] <TB1> INFO: Expecting 411648 events.
[20:25:41.239] <TB1> INFO: 411648 events read in total (8995ms).
[20:25:41.272] <TB1> INFO: Expecting 411648 events.
[20:25:50.638] <TB1> INFO: 411648 events read in total (8963ms).
[20:25:50.672] <TB1> INFO: Expecting 411648 events.
[20:26:00.032] <TB1> INFO: 411648 events read in total (8957ms).
[20:26:00.070] <TB1> INFO: Expecting 411648 events.
[20:26:09.316] <TB1> INFO: 411648 events read in total (8842ms).
[20:26:09.357] <TB1> INFO: Expecting 411648 events.
[20:26:18.734] <TB1> INFO: 411648 events read in total (8974ms).
[20:26:18.778] <TB1> INFO: Expecting 411648 events.
[20:26:28.086] <TB1> INFO: 411648 events read in total (8905ms).
[20:26:28.148] <TB1> INFO: Expecting 411648 events.
[20:26:37.439] <TB1> INFO: 411648 events read in total (8888ms).
[20:26:37.496] <TB1> INFO: Test took 149838ms.
[20:26:38.245] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[20:26:38.258] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:26:38.258] <TB1> INFO: run 1 of 1
[20:26:38.507] <TB1> INFO: Expecting 5025280 events.
[20:27:04.694] <TB1> INFO: 586304 events read in total (25595ms).
[20:27:30.497] <TB1> INFO: 1171456 events read in total (51400ms).
[20:27:56.708] <TB1> INFO: 1755504 events read in total (77609ms).
[20:28:22.957] <TB1> INFO: 2339272 events read in total (103858ms).
[20:28:48.759] <TB1> INFO: 2923632 events read in total (129660ms).
[20:29:14.761] <TB1> INFO: 3509408 events read in total (155662ms).
[20:29:40.890] <TB1> INFO: 4095248 events read in total (181791ms).
[20:30:07.370] <TB1> INFO: 4681080 events read in total (208271ms).
[20:30:22.640] <TB1> INFO: 5025280 events read in total (223541ms).
[20:30:22.783] <TB1> INFO: Test took 224525ms.
[20:30:50.624] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 9.428103 .. 147.489559
[20:30:50.919] <TB1> INFO: Expecting 208000 events.
[20:31:00.504] <TB1> INFO: 208000 events read in total (8993ms).
[20:31:00.505] <TB1> INFO: Test took 9880ms.
[20:31:00.553] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 9 .. 157 (-1/-1) hits flags = 528 (plus default)
[20:31:00.567] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:31:00.567] <TB1> INFO: run 1 of 1
[20:31:00.844] <TB1> INFO: Expecting 4958720 events.
[20:31:26.699] <TB1> INFO: 573160 events read in total (25263ms).
[20:31:52.355] <TB1> INFO: 1146392 events read in total (50919ms).
[20:32:18.234] <TB1> INFO: 1719720 events read in total (76798ms).
[20:32:43.830] <TB1> INFO: 2292944 events read in total (102394ms).
[20:33:09.467] <TB1> INFO: 2866144 events read in total (128031ms).
[20:33:35.527] <TB1> INFO: 3438408 events read in total (154091ms).
[20:34:01.201] <TB1> INFO: 4010264 events read in total (179766ms).
[20:34:27.256] <TB1> INFO: 4581256 events read in total (205820ms).
[20:34:44.067] <TB1> INFO: 4958720 events read in total (222631ms).
[20:34:44.204] <TB1> INFO: Test took 223637ms.
[20:35:10.923] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 27.674968 .. 44.934027
[20:35:11.174] <TB1> INFO: Expecting 208000 events.
[20:35:20.747] <TB1> INFO: 208000 events read in total (8981ms).
[20:35:20.749] <TB1> INFO: Test took 9824ms.
[20:35:20.797] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 17 .. 54 (-1/-1) hits flags = 528 (plus default)
[20:35:20.810] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:35:20.810] <TB1> INFO: run 1 of 1
[20:35:21.088] <TB1> INFO: Expecting 1264640 events.
[20:35:49.611] <TB1> INFO: 664504 events read in total (27931ms).
[20:36:15.234] <TB1> INFO: 1264640 events read in total (53555ms).
[20:36:15.272] <TB1> INFO: Test took 54463ms.
[20:36:30.053] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 25.103970 .. 47.134770
[20:36:30.294] <TB1> INFO: Expecting 208000 events.
[20:36:40.043] <TB1> INFO: 208000 events read in total (9157ms).
[20:36:40.044] <TB1> INFO: Test took 9990ms.
[20:36:40.093] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 15 .. 57 (-1/-1) hits flags = 528 (plus default)
[20:36:40.106] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:36:40.106] <TB1> INFO: run 1 of 1
[20:36:40.384] <TB1> INFO: Expecting 1431040 events.
[20:37:08.405] <TB1> INFO: 660576 events read in total (27429ms).
[20:37:36.227] <TB1> INFO: 1320424 events read in total (55252ms).
[20:37:41.101] <TB1> INFO: 1431040 events read in total (60125ms).
[20:37:41.133] <TB1> INFO: Test took 61028ms.
[20:37:54.417] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 24.672208 .. 48.103678
[20:37:54.687] <TB1> INFO: Expecting 208000 events.
[20:38:04.297] <TB1> INFO: 208000 events read in total (9019ms).
[20:38:04.297] <TB1> INFO: Test took 9878ms.
[20:38:04.367] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 14 .. 58 (-1/-1) hits flags = 528 (plus default)
[20:38:04.381] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:38:04.381] <TB1> INFO: run 1 of 1
[20:38:04.660] <TB1> INFO: Expecting 1497600 events.
[20:38:32.509] <TB1> INFO: 659792 events read in total (27257ms).
[20:38:59.948] <TB1> INFO: 1319840 events read in total (54696ms).
[20:39:07.815] <TB1> INFO: 1497600 events read in total (62563ms).
[20:39:07.844] <TB1> INFO: Test took 63464ms.
[20:39:22.713] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[20:39:22.713] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[20:39:22.727] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[20:39:22.727] <TB1> INFO: run 1 of 1
[20:39:22.966] <TB1> INFO: Expecting 1364480 events.
[20:39:50.003] <TB1> INFO: 667960 events read in total (27445ms).
[20:40:18.372] <TB1> INFO: 1335800 events read in total (54814ms).
[20:40:19.945] <TB1> INFO: 1364480 events read in total (56387ms).
[20:40:19.972] <TB1> INFO: Test took 57245ms.
[20:40:33.478] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C0.dat
[20:40:33.478] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C1.dat
[20:40:33.478] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C2.dat
[20:40:33.478] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C3.dat
[20:40:33.478] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C4.dat
[20:40:33.478] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C5.dat
[20:40:33.478] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C6.dat
[20:40:33.478] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C7.dat
[20:40:33.479] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C8.dat
[20:40:33.479] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C9.dat
[20:40:33.479] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C10.dat
[20:40:33.479] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C11.dat
[20:40:33.479] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C12.dat
[20:40:33.479] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C13.dat
[20:40:33.479] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C14.dat
[20:40:33.479] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C15.dat
[20:40:33.479] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C0.dat
[20:40:33.486] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C1.dat
[20:40:33.492] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C2.dat
[20:40:33.498] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C3.dat
[20:40:33.504] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C4.dat
[20:40:33.510] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C5.dat
[20:40:33.516] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C6.dat
[20:40:33.520] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C7.dat
[20:40:33.525] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C8.dat
[20:40:33.530] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C9.dat
[20:40:33.534] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C10.dat
[20:40:33.539] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C11.dat
[20:40:33.544] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C12.dat
[20:40:33.548] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C13.dat
[20:40:33.553] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C14.dat
[20:40:33.558] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters35_C15.dat
[20:40:33.562] <TB1> INFO: PixTestTrim::trimTest() done
[20:40:33.562] <TB1> INFO: vtrim: 118 120 134 112 128 137 142 127 130 112 138 122 119 133 122 121
[20:40:33.562] <TB1> INFO: vthrcomp: 128 115 118 119 118 128 124 119 132 125 129 124 124 121 126 121
[20:40:33.562] <TB1> INFO: vcal mean: 34.98 34.94 34.96 34.92 35.01 34.97 34.99 34.91 34.91 34.98 35.50 35.08 34.93 34.96 34.95 34.96
[20:40:33.562] <TB1> INFO: vcal RMS: 1.00 0.98 1.19 1.11 1.18 0.98 1.11 1.00 1.11 1.18 1.70 1.24 0.96 1.16 1.01 0.92
[20:40:33.563] <TB1> INFO: bits mean: 9.87 9.05 9.64 10.00 9.49 9.89 9.79 9.45 9.55 9.27 9.48 9.46 9.69 9.18 9.01 9.51
[20:40:33.563] <TB1> INFO: bits RMS: 2.53 2.79 2.79 2.52 2.74 2.61 2.49 2.84 2.68 2.75 2.75 2.71 2.53 2.76 2.84 2.58
[20:40:33.570] <TB1> INFO: ----------------------------------------------------------------------
[20:40:33.570] <TB1> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[20:40:33.570] <TB1> INFO: ----------------------------------------------------------------------
[20:40:33.573] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[20:40:33.585] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:40:33.585] <TB1> INFO: run 1 of 1
[20:40:33.835] <TB1> INFO: Expecting 4160000 events.
[20:41:06.493] <TB1> INFO: 760720 events read in total (32066ms).
[20:41:38.395] <TB1> INFO: 1512480 events read in total (63968ms).
[20:42:09.959] <TB1> INFO: 2257620 events read in total (95532ms).
[20:42:41.877] <TB1> INFO: 2999110 events read in total (127450ms).
[20:43:13.442] <TB1> INFO: 3736045 events read in total (159015ms).
[20:43:31.575] <TB1> INFO: 4160000 events read in total (177148ms).
[20:43:31.792] <TB1> INFO: Test took 178207ms.
[20:43:59.785] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 202 (-1/-1) hits flags = 528 (plus default)
[20:43:59.799] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:43:59.799] <TB1> INFO: run 1 of 1
[20:44:00.081] <TB1> INFO: Expecting 4222400 events.
[20:44:32.090] <TB1> INFO: 731715 events read in total (31417ms).
[20:45:03.173] <TB1> INFO: 1455455 events read in total (62500ms).
[20:45:34.228] <TB1> INFO: 2174675 events read in total (93555ms).
[20:46:05.280] <TB1> INFO: 2889000 events read in total (124607ms).
[20:46:36.194] <TB1> INFO: 3599965 events read in total (155521ms).
[20:47:03.724] <TB1> INFO: 4222400 events read in total (183051ms).
[20:47:03.826] <TB1> INFO: Test took 184027ms.
[20:47:34.456] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 188 (-1/-1) hits flags = 528 (plus default)
[20:47:34.470] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:47:34.470] <TB1> INFO: run 1 of 1
[20:47:34.708] <TB1> INFO: Expecting 3931200 events.
[20:48:07.764] <TB1> INFO: 752290 events read in total (32464ms).
[20:48:39.648] <TB1> INFO: 1495080 events read in total (64348ms).
[20:49:11.864] <TB1> INFO: 2231830 events read in total (96564ms).
[20:49:43.711] <TB1> INFO: 2964865 events read in total (128411ms).
[20:50:15.234] <TB1> INFO: 3693135 events read in total (159934ms).
[20:50:25.831] <TB1> INFO: 3931200 events read in total (170531ms).
[20:50:25.895] <TB1> INFO: Test took 171424ms.
[20:50:49.901] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 189 (-1/-1) hits flags = 528 (plus default)
[20:50:49.914] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:50:49.914] <TB1> INFO: run 1 of 1
[20:50:50.152] <TB1> INFO: Expecting 3952000 events.
[20:51:22.793] <TB1> INFO: 750635 events read in total (32050ms).
[20:51:54.519] <TB1> INFO: 1492980 events read in total (63776ms).
[20:52:26.602] <TB1> INFO: 2228535 events read in total (95859ms).
[20:52:58.508] <TB1> INFO: 2960165 events read in total (127765ms).
[20:53:29.892] <TB1> INFO: 3687255 events read in total (159150ms).
[20:53:41.403] <TB1> INFO: 3952000 events read in total (170660ms).
[20:53:41.770] <TB1> INFO: Test took 171855ms.
[20:54:08.224] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 188 (-1/-1) hits flags = 528 (plus default)
[20:54:08.237] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[20:54:08.237] <TB1> INFO: run 1 of 1
[20:54:08.478] <TB1> INFO: Expecting 3931200 events.
[20:54:43.283] <TB1> INFO: 752180 events read in total (34213ms).
[20:55:15.237] <TB1> INFO: 1495685 events read in total (66167ms).
[20:55:46.684] <TB1> INFO: 2232355 events read in total (97615ms).
[20:56:18.265] <TB1> INFO: 2965220 events read in total (129195ms).
[20:56:49.389] <TB1> INFO: 3693970 events read in total (160319ms).
[20:56:59.678] <TB1> INFO: 3931200 events read in total (170608ms).
[20:56:59.744] <TB1> INFO: Test took 171507ms.
[20:57:24.921] <TB1> INFO: PixTestTrim::trimBitTest() done
[20:57:24.922] <TB1> INFO: PixTestTrim::doTest() done, duration: 2450 seconds
[20:57:24.922] <TB1> INFO: Decoding statistics:
[20:57:24.922] <TB1> INFO: General information:
[20:57:24.922] <TB1> INFO: 16bit words read: 0
[20:57:24.922] <TB1> INFO: valid events total: 0
[20:57:24.922] <TB1> INFO: empty events: 0
[20:57:24.922] <TB1> INFO: valid events with pixels: 0
[20:57:24.922] <TB1> INFO: valid pixel hits: 0
[20:57:24.922] <TB1> INFO: Event errors: 0
[20:57:24.922] <TB1> INFO: start marker: 0
[20:57:24.922] <TB1> INFO: stop marker: 0
[20:57:24.922] <TB1> INFO: overflow: 0
[20:57:24.922] <TB1> INFO: invalid 5bit words: 0
[20:57:24.922] <TB1> INFO: invalid XOR eye diagram: 0
[20:57:24.922] <TB1> INFO: frame (failed synchr.): 0
[20:57:24.922] <TB1> INFO: idle data (no TBM trl): 0
[20:57:24.922] <TB1> INFO: no data (only TBM hdr): 0
[20:57:24.922] <TB1> INFO: TBM errors: 0
[20:57:24.922] <TB1> INFO: flawed TBM headers: 0
[20:57:24.922] <TB1> INFO: flawed TBM trailers: 0
[20:57:24.922] <TB1> INFO: event ID mismatches: 0
[20:57:24.922] <TB1> INFO: ROC errors: 0
[20:57:24.922] <TB1> INFO: missing ROC header(s): 0
[20:57:24.922] <TB1> INFO: misplaced readback start: 0
[20:57:24.922] <TB1> INFO: Pixel decoding errors: 0
[20:57:24.923] <TB1> INFO: pixel data incomplete: 0
[20:57:24.923] <TB1> INFO: pixel address: 0
[20:57:24.923] <TB1> INFO: pulse height fill bit: 0
[20:57:24.923] <TB1> INFO: buffer corruption: 0
[20:57:25.534] <TB1> INFO: ######################################################################
[20:57:25.534] <TB1> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[20:57:25.534] <TB1> INFO: ######################################################################
[20:57:25.860] <TB1> INFO: Expecting 41600 events.
[20:57:29.415] <TB1> INFO: 41600 events read in total (2964ms).
[20:57:29.416] <TB1> INFO: Test took 3881ms.
[20:57:29.900] <TB1> INFO: Expecting 41600 events.
[20:57:33.437] <TB1> INFO: 41600 events read in total (2946ms).
[20:57:33.438] <TB1> INFO: Test took 3819ms.
[20:57:33.729] <TB1> INFO: Expecting 41600 events.
[20:57:37.276] <TB1> INFO: 41600 events read in total (2955ms).
[20:57:37.277] <TB1> INFO: Test took 3813ms.
[20:57:37.565] <TB1> INFO: Expecting 41600 events.
[20:57:41.117] <TB1> INFO: 41600 events read in total (2960ms).
[20:57:41.118] <TB1> INFO: Test took 3817ms.
[20:57:41.409] <TB1> INFO: Expecting 41600 events.
[20:57:44.909] <TB1> INFO: 41600 events read in total (2908ms).
[20:57:44.910] <TB1> INFO: Test took 3766ms.
[20:57:45.204] <TB1> INFO: Expecting 41600 events.
[20:57:48.733] <TB1> INFO: 41600 events read in total (2937ms).
[20:57:48.734] <TB1> INFO: Test took 3797ms.
[20:57:49.023] <TB1> INFO: Expecting 41600 events.
[20:57:52.547] <TB1> INFO: 41600 events read in total (2932ms).
[20:57:52.547] <TB1> INFO: Test took 3789ms.
[20:57:52.837] <TB1> INFO: Expecting 41600 events.
[20:57:56.360] <TB1> INFO: 41600 events read in total (2932ms).
[20:57:56.361] <TB1> INFO: Test took 3789ms.
[20:57:56.660] <TB1> INFO: Expecting 41600 events.
[20:58:00.137] <TB1> INFO: 41600 events read in total (2886ms).
[20:58:00.138] <TB1> INFO: Test took 3748ms.
[20:58:00.430] <TB1> INFO: Expecting 41600 events.
[20:58:04.005] <TB1> INFO: 41600 events read in total (2983ms).
[20:58:04.006] <TB1> INFO: Test took 3841ms.
[20:58:04.295] <TB1> INFO: Expecting 41600 events.
[20:58:07.878] <TB1> INFO: 41600 events read in total (2991ms).
[20:58:07.878] <TB1> INFO: Test took 3848ms.
[20:58:08.169] <TB1> INFO: Expecting 41600 events.
[20:58:11.782] <TB1> INFO: 41600 events read in total (3021ms).
[20:58:11.783] <TB1> INFO: Test took 3879ms.
[20:58:12.137] <TB1> INFO: Expecting 41600 events.
[20:58:15.627] <TB1> INFO: 41600 events read in total (2898ms).
[20:58:15.628] <TB1> INFO: Test took 3816ms.
[20:58:15.917] <TB1> INFO: Expecting 41600 events.
[20:58:19.392] <TB1> INFO: 41600 events read in total (2883ms).
[20:58:19.393] <TB1> INFO: Test took 3741ms.
[20:58:19.684] <TB1> INFO: Expecting 41600 events.
[20:58:23.177] <TB1> INFO: 41600 events read in total (2901ms).
[20:58:23.178] <TB1> INFO: Test took 3760ms.
[20:58:23.469] <TB1> INFO: Expecting 41600 events.
[20:58:26.943] <TB1> INFO: 41600 events read in total (2882ms).
[20:58:26.944] <TB1> INFO: Test took 3742ms.
[20:58:27.233] <TB1> INFO: Expecting 41600 events.
[20:58:30.876] <TB1> INFO: 41600 events read in total (3051ms).
[20:58:30.877] <TB1> INFO: Test took 3909ms.
[20:58:31.169] <TB1> INFO: Expecting 41600 events.
[20:58:34.725] <TB1> INFO: 41600 events read in total (2964ms).
[20:58:34.725] <TB1> INFO: Test took 3822ms.
[20:58:35.026] <TB1> INFO: Expecting 41600 events.
[20:58:38.659] <TB1> INFO: 41600 events read in total (3041ms).
[20:58:38.660] <TB1> INFO: Test took 3901ms.
[20:58:38.950] <TB1> INFO: Expecting 41600 events.
[20:58:42.504] <TB1> INFO: 41600 events read in total (2963ms).
[20:58:42.504] <TB1> INFO: Test took 3819ms.
[20:58:42.793] <TB1> INFO: Expecting 41600 events.
[20:58:46.350] <TB1> INFO: 41600 events read in total (2964ms).
[20:58:46.351] <TB1> INFO: Test took 3822ms.
[20:58:46.640] <TB1> INFO: Expecting 41600 events.
[20:58:50.262] <TB1> INFO: 41600 events read in total (3030ms).
[20:58:50.263] <TB1> INFO: Test took 3888ms.
[20:58:50.551] <TB1> INFO: Expecting 41600 events.
[20:58:54.181] <TB1> INFO: 41600 events read in total (3038ms).
[20:58:54.181] <TB1> INFO: Test took 3894ms.
[20:58:54.473] <TB1> INFO: Expecting 41600 events.
[20:58:58.092] <TB1> INFO: 41600 events read in total (3027ms).
[20:58:58.093] <TB1> INFO: Test took 3885ms.
[20:58:58.443] <TB1> INFO: Expecting 41600 events.
[20:59:01.948] <TB1> INFO: 41600 events read in total (2914ms).
[20:59:01.949] <TB1> INFO: Test took 3831ms.
[20:59:02.250] <TB1> INFO: Expecting 41600 events.
[20:59:05.752] <TB1> INFO: 41600 events read in total (2910ms).
[20:59:05.752] <TB1> INFO: Test took 3778ms.
[20:59:06.052] <TB1> INFO: Expecting 41600 events.
[20:59:09.612] <TB1> INFO: 41600 events read in total (2966ms).
[20:59:09.613] <TB1> INFO: Test took 3837ms.
[20:59:09.904] <TB1> INFO: Expecting 41600 events.
[20:59:13.417] <TB1> INFO: 41600 events read in total (2921ms).
[20:59:13.418] <TB1> INFO: Test took 3779ms.
[20:59:13.712] <TB1> INFO: Expecting 2560 events.
[20:59:14.603] <TB1> INFO: 2560 events read in total (299ms).
[20:59:14.604] <TB1> INFO: Test took 1168ms.
[20:59:14.913] <TB1> INFO: Expecting 2560 events.
[20:59:15.806] <TB1> INFO: 2560 events read in total (301ms).
[20:59:15.806] <TB1> INFO: Test took 1202ms.
[20:59:16.114] <TB1> INFO: Expecting 2560 events.
[20:59:16.998] <TB1> INFO: 2560 events read in total (292ms).
[20:59:16.998] <TB1> INFO: Test took 1191ms.
[20:59:17.306] <TB1> INFO: Expecting 2560 events.
[20:59:18.194] <TB1> INFO: 2560 events read in total (297ms).
[20:59:18.194] <TB1> INFO: Test took 1196ms.
[20:59:18.502] <TB1> INFO: Expecting 2560 events.
[20:59:19.395] <TB1> INFO: 2560 events read in total (301ms).
[20:59:19.395] <TB1> INFO: Test took 1201ms.
[20:59:19.702] <TB1> INFO: Expecting 2560 events.
[20:59:20.589] <TB1> INFO: 2560 events read in total (295ms).
[20:59:20.589] <TB1> INFO: Test took 1193ms.
[20:59:20.897] <TB1> INFO: Expecting 2560 events.
[20:59:21.777] <TB1> INFO: 2560 events read in total (289ms).
[20:59:21.777] <TB1> INFO: Test took 1188ms.
[20:59:22.085] <TB1> INFO: Expecting 2560 events.
[20:59:22.973] <TB1> INFO: 2560 events read in total (296ms).
[20:59:22.973] <TB1> INFO: Test took 1195ms.
[20:59:23.282] <TB1> INFO: Expecting 2560 events.
[20:59:24.170] <TB1> INFO: 2560 events read in total (296ms).
[20:59:24.170] <TB1> INFO: Test took 1196ms.
[20:59:24.478] <TB1> INFO: Expecting 2560 events.
[20:59:25.364] <TB1> INFO: 2560 events read in total (294ms).
[20:59:25.364] <TB1> INFO: Test took 1193ms.
[20:59:25.672] <TB1> INFO: Expecting 2560 events.
[20:59:26.562] <TB1> INFO: 2560 events read in total (298ms).
[20:59:26.562] <TB1> INFO: Test took 1198ms.
[20:59:26.869] <TB1> INFO: Expecting 2560 events.
[20:59:27.763] <TB1> INFO: 2560 events read in total (302ms).
[20:59:27.763] <TB1> INFO: Test took 1200ms.
[20:59:28.070] <TB1> INFO: Expecting 2560 events.
[20:59:28.952] <TB1> INFO: 2560 events read in total (291ms).
[20:59:28.952] <TB1> INFO: Test took 1188ms.
[20:59:29.260] <TB1> INFO: Expecting 2560 events.
[20:59:30.147] <TB1> INFO: 2560 events read in total (295ms).
[20:59:30.147] <TB1> INFO: Test took 1194ms.
[20:59:30.454] <TB1> INFO: Expecting 2560 events.
[20:59:31.348] <TB1> INFO: 2560 events read in total (302ms).
[20:59:31.348] <TB1> INFO: Test took 1200ms.
[20:59:31.656] <TB1> INFO: Expecting 2560 events.
[20:59:32.540] <TB1> INFO: 2560 events read in total (292ms).
[20:59:32.540] <TB1> INFO: Test took 1191ms.
[20:59:32.544] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[20:59:32.849] <TB1> INFO: Expecting 655360 events.
[20:59:47.882] <TB1> INFO: 655360 events read in total (14442ms).
[20:59:47.899] <TB1> INFO: Expecting 655360 events.
[21:00:02.523] <TB1> INFO: 655360 events read in total (14221ms).
[21:00:02.541] <TB1> INFO: Expecting 655360 events.
[21:00:17.294] <TB1> INFO: 655360 events read in total (14350ms).
[21:00:17.314] <TB1> INFO: Expecting 655360 events.
[21:00:31.893] <TB1> INFO: 655360 events read in total (14175ms).
[21:00:31.917] <TB1> INFO: Expecting 655360 events.
[21:00:46.451] <TB1> INFO: 655360 events read in total (14130ms).
[21:00:46.480] <TB1> INFO: Expecting 655360 events.
[21:01:00.920] <TB1> INFO: 655360 events read in total (14037ms).
[21:01:00.961] <TB1> INFO: Expecting 655360 events.
[21:01:15.439] <TB1> INFO: 655360 events read in total (14075ms).
[21:01:15.478] <TB1> INFO: Expecting 655360 events.
[21:01:29.984] <TB1> INFO: 655360 events read in total (14103ms).
[21:01:30.027] <TB1> INFO: Expecting 655360 events.
[21:01:44.565] <TB1> INFO: 655360 events read in total (14135ms).
[21:01:44.625] <TB1> INFO: Expecting 655360 events.
[21:01:59.359] <TB1> INFO: 655360 events read in total (14331ms).
[21:01:59.415] <TB1> INFO: Expecting 655360 events.
[21:02:14.070] <TB1> INFO: 655360 events read in total (14252ms).
[21:02:14.340] <TB1> INFO: Expecting 655360 events.
[21:02:29.182] <TB1> INFO: 655360 events read in total (14439ms).
[21:02:29.282] <TB1> INFO: Expecting 655360 events.
[21:02:43.951] <TB1> INFO: 655360 events read in total (14266ms).
[21:02:44.050] <TB1> INFO: Expecting 655360 events.
[21:02:58.772] <TB1> INFO: 655360 events read in total (14319ms).
[21:02:58.856] <TB1> INFO: Expecting 655360 events.
[21:03:13.596] <TB1> INFO: 655360 events read in total (14337ms).
[21:03:13.687] <TB1> INFO: Expecting 655360 events.
[21:03:28.446] <TB1> INFO: 655360 events read in total (14356ms).
[21:03:28.545] <TB1> INFO: Test took 236001ms.
[21:03:28.643] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:03:28.898] <TB1> INFO: Expecting 655360 events.
[21:03:43.741] <TB1> INFO: 655360 events read in total (14252ms).
[21:03:43.753] <TB1> INFO: Expecting 655360 events.
[21:03:58.215] <TB1> INFO: 655360 events read in total (14059ms).
[21:03:58.235] <TB1> INFO: Expecting 655360 events.
[21:04:12.870] <TB1> INFO: 655360 events read in total (14232ms).
[21:04:12.895] <TB1> INFO: Expecting 655360 events.
[21:04:27.659] <TB1> INFO: 655360 events read in total (14360ms).
[21:04:27.689] <TB1> INFO: Expecting 655360 events.
[21:04:42.226] <TB1> INFO: 655360 events read in total (14134ms).
[21:04:42.264] <TB1> INFO: Expecting 655360 events.
[21:04:56.881] <TB1> INFO: 655360 events read in total (14214ms).
[21:04:56.925] <TB1> INFO: Expecting 655360 events.
[21:05:11.450] <TB1> INFO: 655360 events read in total (14122ms).
[21:05:11.488] <TB1> INFO: Expecting 655360 events.
[21:05:25.904] <TB1> INFO: 655360 events read in total (14013ms).
[21:05:25.946] <TB1> INFO: Expecting 655360 events.
[21:05:40.370] <TB1> INFO: 655360 events read in total (14021ms).
[21:05:40.417] <TB1> INFO: Expecting 655360 events.
[21:05:55.059] <TB1> INFO: 655360 events read in total (14239ms).
[21:05:55.115] <TB1> INFO: Expecting 655360 events.
[21:06:09.561] <TB1> INFO: 655360 events read in total (14043ms).
[21:06:09.625] <TB1> INFO: Expecting 655360 events.
[21:06:24.419] <TB1> INFO: 655360 events read in total (14391ms).
[21:06:24.485] <TB1> INFO: Expecting 655360 events.
[21:06:39.361] <TB1> INFO: 655360 events read in total (14473ms).
[21:06:39.439] <TB1> INFO: Expecting 655360 events.
[21:06:54.005] <TB1> INFO: 655360 events read in total (14161ms).
[21:06:54.090] <TB1> INFO: Expecting 655360 events.
[21:07:08.266] <TB1> INFO: 655360 events read in total (13773ms).
[21:07:08.499] <TB1> INFO: Expecting 655360 events.
[21:07:22.800] <TB1> INFO: 655360 events read in total (13899ms).
[21:07:22.913] <TB1> INFO: Test took 234270ms.
[21:07:23.089] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.097] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[21:07:23.105] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[21:07:23.112] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[21:07:23.118] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[21:07:23.125] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[21:07:23.131] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[21:07:23.138] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[21:07:23.145] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[21:07:23.152] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.160] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[21:07:23.166] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.173] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.180] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.187] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.194] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.200] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.206] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.213] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.219] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.226] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[21:07:23.232] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[21:07:23.240] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[21:07:23.250] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[21:07:23.259] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[21:07:23.268] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[21:07:23.277] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[21:07:23.286] <TB1> INFO: safety margin for low PH: adding 8, margin is now 28
[21:07:23.294] <TB1> INFO: safety margin for low PH: adding 9, margin is now 29
[21:07:23.302] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.311] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[21:07:23.319] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.328] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.336] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[21:07:23.345] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[21:07:23.353] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[21:07:23.362] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[21:07:23.370] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.378] <TB1> INFO: safety margin for low PH: adding 0, margin is now 20
[21:07:23.387] <TB1> INFO: safety margin for low PH: adding 1, margin is now 21
[21:07:23.396] <TB1> INFO: safety margin for low PH: adding 2, margin is now 22
[21:07:23.404] <TB1> INFO: safety margin for low PH: adding 3, margin is now 23
[21:07:23.412] <TB1> INFO: safety margin for low PH: adding 4, margin is now 24
[21:07:23.421] <TB1> INFO: safety margin for low PH: adding 5, margin is now 25
[21:07:23.429] <TB1> INFO: safety margin for low PH: adding 6, margin is now 26
[21:07:23.438] <TB1> INFO: safety margin for low PH: adding 7, margin is now 27
[21:07:23.474] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C0.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C1.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C2.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C3.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C4.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C5.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C6.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C7.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C8.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C9.dat
[21:07:23.475] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C10.dat
[21:07:23.476] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C11.dat
[21:07:23.476] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C12.dat
[21:07:23.476] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C13.dat
[21:07:23.476] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C14.dat
[21:07:23.476] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters35_C15.dat
[21:07:23.715] <TB1> INFO: Expecting 41600 events.
[21:07:26.881] <TB1> INFO: 41600 events read in total (2574ms).
[21:07:26.882] <TB1> INFO: Test took 3403ms.
[21:07:27.333] <TB1> INFO: Expecting 41600 events.
[21:07:30.384] <TB1> INFO: 41600 events read in total (2460ms).
[21:07:30.385] <TB1> INFO: Test took 3288ms.
[21:07:30.831] <TB1> INFO: Expecting 41600 events.
[21:07:33.959] <TB1> INFO: 41600 events read in total (2536ms).
[21:07:33.960] <TB1> INFO: Test took 3364ms.
[21:07:34.176] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:34.265] <TB1> INFO: Expecting 2560 events.
[21:07:35.161] <TB1> INFO: 2560 events read in total (304ms).
[21:07:35.161] <TB1> INFO: Test took 985ms.
[21:07:35.165] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:35.469] <TB1> INFO: Expecting 2560 events.
[21:07:36.364] <TB1> INFO: 2560 events read in total (303ms).
[21:07:36.365] <TB1> INFO: Test took 1200ms.
[21:07:36.368] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:36.672] <TB1> INFO: Expecting 2560 events.
[21:07:37.564] <TB1> INFO: 2560 events read in total (300ms).
[21:07:37.564] <TB1> INFO: Test took 1196ms.
[21:07:37.567] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:37.873] <TB1> INFO: Expecting 2560 events.
[21:07:38.764] <TB1> INFO: 2560 events read in total (299ms).
[21:07:38.764] <TB1> INFO: Test took 1197ms.
[21:07:38.766] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:39.073] <TB1> INFO: Expecting 2560 events.
[21:07:39.964] <TB1> INFO: 2560 events read in total (299ms).
[21:07:39.964] <TB1> INFO: Test took 1198ms.
[21:07:39.966] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:40.273] <TB1> INFO: Expecting 2560 events.
[21:07:41.158] <TB1> INFO: 2560 events read in total (293ms).
[21:07:41.158] <TB1> INFO: Test took 1192ms.
[21:07:41.160] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:41.467] <TB1> INFO: Expecting 2560 events.
[21:07:42.353] <TB1> INFO: 2560 events read in total (294ms).
[21:07:42.353] <TB1> INFO: Test took 1193ms.
[21:07:42.356] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:42.662] <TB1> INFO: Expecting 2560 events.
[21:07:43.546] <TB1> INFO: 2560 events read in total (293ms).
[21:07:43.546] <TB1> INFO: Test took 1190ms.
[21:07:43.549] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:43.854] <TB1> INFO: Expecting 2560 events.
[21:07:44.738] <TB1> INFO: 2560 events read in total (292ms).
[21:07:44.738] <TB1> INFO: Test took 1189ms.
[21:07:44.740] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:45.047] <TB1> INFO: Expecting 2560 events.
[21:07:45.928] <TB1> INFO: 2560 events read in total (289ms).
[21:07:45.928] <TB1> INFO: Test took 1188ms.
[21:07:45.932] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:46.236] <TB1> INFO: Expecting 2560 events.
[21:07:47.119] <TB1> INFO: 2560 events read in total (292ms).
[21:07:47.120] <TB1> INFO: Test took 1188ms.
[21:07:47.124] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:47.427] <TB1> INFO: Expecting 2560 events.
[21:07:48.314] <TB1> INFO: 2560 events read in total (295ms).
[21:07:48.314] <TB1> INFO: Test took 1191ms.
[21:07:48.317] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:48.623] <TB1> INFO: Expecting 2560 events.
[21:07:49.507] <TB1> INFO: 2560 events read in total (292ms).
[21:07:49.507] <TB1> INFO: Test took 1190ms.
[21:07:49.510] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:49.815] <TB1> INFO: Expecting 2560 events.
[21:07:50.698] <TB1> INFO: 2560 events read in total (291ms).
[21:07:50.698] <TB1> INFO: Test took 1188ms.
[21:07:50.701] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:51.007] <TB1> INFO: Expecting 2560 events.
[21:07:51.888] <TB1> INFO: 2560 events read in total (289ms).
[21:07:51.889] <TB1> INFO: Test took 1189ms.
[21:07:51.892] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:52.197] <TB1> INFO: Expecting 2560 events.
[21:07:53.079] <TB1> INFO: 2560 events read in total (290ms).
[21:07:53.079] <TB1> INFO: Test took 1187ms.
[21:07:53.081] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:53.388] <TB1> INFO: Expecting 2560 events.
[21:07:54.272] <TB1> INFO: 2560 events read in total (292ms).
[21:07:54.272] <TB1> INFO: Test took 1191ms.
[21:07:54.274] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:54.580] <TB1> INFO: Expecting 2560 events.
[21:07:55.460] <TB1> INFO: 2560 events read in total (288ms).
[21:07:55.461] <TB1> INFO: Test took 1187ms.
[21:07:55.463] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:55.770] <TB1> INFO: Expecting 2560 events.
[21:07:56.655] <TB1> INFO: 2560 events read in total (293ms).
[21:07:56.655] <TB1> INFO: Test took 1192ms.
[21:07:56.657] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:56.964] <TB1> INFO: Expecting 2560 events.
[21:07:57.844] <TB1> INFO: 2560 events read in total (289ms).
[21:07:57.844] <TB1> INFO: Test took 1187ms.
[21:07:57.847] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:58.152] <TB1> INFO: Expecting 2560 events.
[21:07:59.032] <TB1> INFO: 2560 events read in total (288ms).
[21:07:59.033] <TB1> INFO: Test took 1186ms.
[21:07:59.035] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:07:59.341] <TB1> INFO: Expecting 2560 events.
[21:08:00.221] <TB1> INFO: 2560 events read in total (288ms).
[21:08:00.221] <TB1> INFO: Test took 1186ms.
[21:08:00.224] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:00.530] <TB1> INFO: Expecting 2560 events.
[21:08:01.410] <TB1> INFO: 2560 events read in total (289ms).
[21:08:01.410] <TB1> INFO: Test took 1186ms.
[21:08:01.413] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:01.718] <TB1> INFO: Expecting 2560 events.
[21:08:02.603] <TB1> INFO: 2560 events read in total (293ms).
[21:08:02.603] <TB1> INFO: Test took 1190ms.
[21:08:02.606] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:02.912] <TB1> INFO: Expecting 2560 events.
[21:08:03.806] <TB1> INFO: 2560 events read in total (302ms).
[21:08:03.807] <TB1> INFO: Test took 1201ms.
[21:08:03.810] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:04.115] <TB1> INFO: Expecting 2560 events.
[21:08:05.008] <TB1> INFO: 2560 events read in total (301ms).
[21:08:05.008] <TB1> INFO: Test took 1198ms.
[21:08:05.012] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:05.316] <TB1> INFO: Expecting 2560 events.
[21:08:06.208] <TB1> INFO: 2560 events read in total (301ms).
[21:08:06.208] <TB1> INFO: Test took 1197ms.
[21:08:06.211] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:06.516] <TB1> INFO: Expecting 2560 events.
[21:08:07.410] <TB1> INFO: 2560 events read in total (302ms).
[21:08:07.410] <TB1> INFO: Test took 1199ms.
[21:08:07.414] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:07.718] <TB1> INFO: Expecting 2560 events.
[21:08:08.607] <TB1> INFO: 2560 events read in total (297ms).
[21:08:08.607] <TB1> INFO: Test took 1193ms.
[21:08:08.611] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:08.916] <TB1> INFO: Expecting 2560 events.
[21:08:09.809] <TB1> INFO: 2560 events read in total (302ms).
[21:08:09.809] <TB1> INFO: Test took 1198ms.
[21:08:09.812] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:10.117] <TB1> INFO: Expecting 2560 events.
[21:08:11.011] <TB1> INFO: 2560 events read in total (302ms).
[21:08:11.012] <TB1> INFO: Test took 1200ms.
[21:08:11.016] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:08:11.319] <TB1> INFO: Expecting 2560 events.
[21:08:12.214] <TB1> INFO: 2560 events read in total (303ms).
[21:08:12.214] <TB1> INFO: Test took 1199ms.
[21:08:12.676] <TB1> INFO: PixTestPhOptimization::doTest() done, duration: 647 seconds
[21:08:12.676] <TB1> INFO: PH scale (per ROC): 35 51 52 60 29 39 46 45 37 52 31 31 39 30 55 48
[21:08:12.676] <TB1> INFO: PH offset (per ROC): 106 112 108 123 93 94 116 109 103 127 94 103 100 97 123 107
[21:08:12.683] <TB1> INFO: Decoding statistics:
[21:08:12.683] <TB1> INFO: General information:
[21:08:12.684] <TB1> INFO: 16bit words read: 127886
[21:08:12.684] <TB1> INFO: valid events total: 20480
[21:08:12.684] <TB1> INFO: empty events: 17977
[21:08:12.684] <TB1> INFO: valid events with pixels: 2503
[21:08:12.684] <TB1> INFO: valid pixel hits: 2503
[21:08:12.684] <TB1> INFO: Event errors: 0
[21:08:12.684] <TB1> INFO: start marker: 0
[21:08:12.684] <TB1> INFO: stop marker: 0
[21:08:12.684] <TB1> INFO: overflow: 0
[21:08:12.684] <TB1> INFO: invalid 5bit words: 0
[21:08:12.684] <TB1> INFO: invalid XOR eye diagram: 0
[21:08:12.684] <TB1> INFO: frame (failed synchr.): 0
[21:08:12.684] <TB1> INFO: idle data (no TBM trl): 0
[21:08:12.684] <TB1> INFO: no data (only TBM hdr): 0
[21:08:12.684] <TB1> INFO: TBM errors: 0
[21:08:12.684] <TB1> INFO: flawed TBM headers: 0
[21:08:12.684] <TB1> INFO: flawed TBM trailers: 0
[21:08:12.684] <TB1> INFO: event ID mismatches: 0
[21:08:12.684] <TB1> INFO: ROC errors: 0
[21:08:12.684] <TB1> INFO: missing ROC header(s): 0
[21:08:12.684] <TB1> INFO: misplaced readback start: 0
[21:08:12.684] <TB1> INFO: Pixel decoding errors: 0
[21:08:12.684] <TB1> INFO: pixel data incomplete: 0
[21:08:12.684] <TB1> INFO: pixel address: 0
[21:08:12.684] <TB1> INFO: pulse height fill bit: 0
[21:08:12.684] <TB1> INFO: buffer corruption: 0
[21:08:12.876] <TB1> INFO: ######################################################################
[21:08:12.876] <TB1> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[21:08:12.876] <TB1> INFO: ######################################################################
[21:08:12.891] <TB1> INFO: scanning low vcal = 10
[21:08:13.129] <TB1> INFO: Expecting 41600 events.
[21:08:16.703] <TB1> INFO: 41600 events read in total (2982ms).
[21:08:16.704] <TB1> INFO: Test took 3813ms.
[21:08:16.707] <TB1> INFO: scanning low vcal = 20
[21:08:16.999] <TB1> INFO: Expecting 41600 events.
[21:08:20.583] <TB1> INFO: 41600 events read in total (2993ms).
[21:08:20.584] <TB1> INFO: Test took 3877ms.
[21:08:20.586] <TB1> INFO: scanning low vcal = 30
[21:08:20.880] <TB1> INFO: Expecting 41600 events.
[21:08:24.530] <TB1> INFO: 41600 events read in total (3058ms).
[21:08:24.532] <TB1> INFO: Test took 3946ms.
[21:08:24.535] <TB1> INFO: scanning low vcal = 40
[21:08:24.815] <TB1> INFO: Expecting 41600 events.
[21:08:28.751] <TB1> INFO: 41600 events read in total (3344ms).
[21:08:28.752] <TB1> INFO: Test took 4217ms.
[21:08:28.755] <TB1> INFO: scanning low vcal = 50
[21:08:29.032] <TB1> INFO: Expecting 41600 events.
[21:08:33.106] <TB1> INFO: 41600 events read in total (3483ms).
[21:08:33.106] <TB1> INFO: Test took 4351ms.
[21:08:33.110] <TB1> INFO: scanning low vcal = 60
[21:08:33.387] <TB1> INFO: Expecting 41600 events.
[21:08:37.474] <TB1> INFO: 41600 events read in total (3496ms).
[21:08:37.475] <TB1> INFO: Test took 4365ms.
[21:08:37.479] <TB1> INFO: scanning low vcal = 70
[21:08:37.755] <TB1> INFO: Expecting 41600 events.
[21:08:41.736] <TB1> INFO: 41600 events read in total (3389ms).
[21:08:41.737] <TB1> INFO: Test took 4258ms.
[21:08:41.742] <TB1> INFO: scanning low vcal = 80
[21:08:42.017] <TB1> INFO: Expecting 41600 events.
[21:08:45.995] <TB1> INFO: 41600 events read in total (3386ms).
[21:08:45.996] <TB1> INFO: Test took 4254ms.
[21:08:45.999] <TB1> INFO: scanning low vcal = 90
[21:08:46.276] <TB1> INFO: Expecting 41600 events.
[21:08:50.250] <TB1> INFO: 41600 events read in total (3383ms).
[21:08:50.251] <TB1> INFO: Test took 4252ms.
[21:08:50.255] <TB1> INFO: scanning low vcal = 100
[21:08:50.531] <TB1> INFO: Expecting 41600 events.
[21:08:54.519] <TB1> INFO: 41600 events read in total (3396ms).
[21:08:54.520] <TB1> INFO: Test took 4264ms.
[21:08:54.524] <TB1> INFO: scanning low vcal = 110
[21:08:54.800] <TB1> INFO: Expecting 41600 events.
[21:08:58.797] <TB1> INFO: 41600 events read in total (3405ms).
[21:08:58.798] <TB1> INFO: Test took 4274ms.
[21:08:58.801] <TB1> INFO: scanning low vcal = 120
[21:08:59.078] <TB1> INFO: Expecting 41600 events.
[21:09:03.105] <TB1> INFO: 41600 events read in total (3436ms).
[21:09:03.106] <TB1> INFO: Test took 4305ms.
[21:09:03.109] <TB1> INFO: scanning low vcal = 130
[21:09:03.385] <TB1> INFO: Expecting 41600 events.
[21:09:07.399] <TB1> INFO: 41600 events read in total (3422ms).
[21:09:07.400] <TB1> INFO: Test took 4291ms.
[21:09:07.403] <TB1> INFO: scanning low vcal = 140
[21:09:07.679] <TB1> INFO: Expecting 41600 events.
[21:09:11.634] <TB1> INFO: 41600 events read in total (3363ms).
[21:09:11.635] <TB1> INFO: Test took 4232ms.
[21:09:11.638] <TB1> INFO: scanning low vcal = 150
[21:09:11.914] <TB1> INFO: Expecting 41600 events.
[21:09:15.876] <TB1> INFO: 41600 events read in total (3370ms).
[21:09:15.877] <TB1> INFO: Test took 4239ms.
[21:09:15.880] <TB1> INFO: scanning low vcal = 160
[21:09:16.156] <TB1> INFO: Expecting 41600 events.
[21:09:20.125] <TB1> INFO: 41600 events read in total (3377ms).
[21:09:20.126] <TB1> INFO: Test took 4245ms.
[21:09:20.129] <TB1> INFO: scanning low vcal = 170
[21:09:20.406] <TB1> INFO: Expecting 41600 events.
[21:09:24.369] <TB1> INFO: 41600 events read in total (3371ms).
[21:09:24.370] <TB1> INFO: Test took 4241ms.
[21:09:24.375] <TB1> INFO: scanning low vcal = 180
[21:09:24.649] <TB1> INFO: Expecting 41600 events.
[21:09:28.651] <TB1> INFO: 41600 events read in total (3410ms).
[21:09:28.652] <TB1> INFO: Test took 4277ms.
[21:09:28.655] <TB1> INFO: scanning low vcal = 190
[21:09:28.932] <TB1> INFO: Expecting 41600 events.
[21:09:32.963] <TB1> INFO: 41600 events read in total (3439ms).
[21:09:32.964] <TB1> INFO: Test took 4309ms.
[21:09:32.967] <TB1> INFO: scanning low vcal = 200
[21:09:33.244] <TB1> INFO: Expecting 41600 events.
[21:09:37.236] <TB1> INFO: 41600 events read in total (3401ms).
[21:09:37.237] <TB1> INFO: Test took 4270ms.
[21:09:37.240] <TB1> INFO: scanning low vcal = 210
[21:09:37.517] <TB1> INFO: Expecting 41600 events.
[21:09:41.494] <TB1> INFO: 41600 events read in total (3386ms).
[21:09:41.495] <TB1> INFO: Test took 4255ms.
[21:09:41.498] <TB1> INFO: scanning low vcal = 220
[21:09:41.775] <TB1> INFO: Expecting 41600 events.
[21:09:45.736] <TB1> INFO: 41600 events read in total (3369ms).
[21:09:45.737] <TB1> INFO: Test took 4239ms.
[21:09:45.740] <TB1> INFO: scanning low vcal = 230
[21:09:46.017] <TB1> INFO: Expecting 41600 events.
[21:09:49.974] <TB1> INFO: 41600 events read in total (3366ms).
[21:09:49.975] <TB1> INFO: Test took 4235ms.
[21:09:49.979] <TB1> INFO: scanning low vcal = 240
[21:09:50.255] <TB1> INFO: Expecting 41600 events.
[21:09:54.224] <TB1> INFO: 41600 events read in total (3377ms).
[21:09:54.225] <TB1> INFO: Test took 4246ms.
[21:09:54.228] <TB1> INFO: scanning low vcal = 250
[21:09:54.537] <TB1> INFO: Expecting 41600 events.
[21:09:58.530] <TB1> INFO: 41600 events read in total (3401ms).
[21:09:58.530] <TB1> INFO: Test took 4302ms.
[21:09:58.535] <TB1> INFO: scanning high vcal = 30 (= 210 in low range)
[21:09:58.811] <TB1> INFO: Expecting 41600 events.
[21:10:02.837] <TB1> INFO: 41600 events read in total (3434ms).
[21:10:02.838] <TB1> INFO: Test took 4303ms.
[21:10:02.841] <TB1> INFO: scanning high vcal = 50 (= 350 in low range)
[21:10:03.118] <TB1> INFO: Expecting 41600 events.
[21:10:07.124] <TB1> INFO: 41600 events read in total (3414ms).
[21:10:07.126] <TB1> INFO: Test took 4285ms.
[21:10:07.129] <TB1> INFO: scanning high vcal = 70 (= 490 in low range)
[21:10:07.405] <TB1> INFO: Expecting 41600 events.
[21:10:11.368] <TB1> INFO: 41600 events read in total (3371ms).
[21:10:11.369] <TB1> INFO: Test took 4240ms.
[21:10:11.372] <TB1> INFO: scanning high vcal = 90 (= 630 in low range)
[21:10:11.676] <TB1> INFO: Expecting 41600 events.
[21:10:15.615] <TB1> INFO: 41600 events read in total (3348ms).
[21:10:15.616] <TB1> INFO: Test took 4243ms.
[21:10:15.620] <TB1> INFO: scanning high vcal = 200 (= 1400 in low range)
[21:10:15.897] <TB1> INFO: Expecting 41600 events.
[21:10:19.884] <TB1> INFO: 41600 events read in total (3396ms).
[21:10:19.886] <TB1> INFO: Test took 4266ms.
[21:10:20.305] <TB1> INFO: PixTestGainPedestal::measure() done
[21:10:55.610] <TB1> INFO: PixTestGainPedestal::fit() done
[21:10:55.610] <TB1> INFO: non-linearity mean: 0.921 0.973 0.963 0.980 0.992 0.929 0.946 0.930 0.905 0.977 0.952 0.923 0.913 1.034 0.983 0.961
[21:10:55.610] <TB1> INFO: non-linearity RMS: 0.185 0.011 0.018 0.005 0.190 0.073 0.044 0.096 0.110 0.006 0.184 0.123 0.141 0.172 0.004 0.012
[21:10:55.610] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C0.dat
[21:10:55.631] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C1.dat
[21:10:55.650] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C2.dat
[21:10:55.669] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C3.dat
[21:10:55.682] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C4.dat
[21:10:55.695] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C5.dat
[21:10:55.708] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C6.dat
[21:10:55.721] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C7.dat
[21:10:55.734] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C8.dat
[21:10:55.746] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C9.dat
[21:10:55.759] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C10.dat
[21:10:55.772] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C11.dat
[21:10:55.785] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C12.dat
[21:10:55.798] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C13.dat
[21:10:55.811] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C14.dat
[21:10:55.824] <TB1> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//phCalibrationFitErr35_C15.dat
[21:10:55.837] <TB1> INFO: PixTestGainPedestal::fullTest() done, duration: 162 seconds
[21:10:55.837] <TB1> INFO: Decoding statistics:
[21:10:55.837] <TB1> INFO: General information:
[21:10:55.837] <TB1> INFO: 16bit words read: 3317220
[21:10:55.837] <TB1> INFO: valid events total: 332800
[21:10:55.837] <TB1> INFO: empty events: 49
[21:10:55.837] <TB1> INFO: valid events with pixels: 332751
[21:10:55.837] <TB1> INFO: valid pixel hits: 660210
[21:10:55.837] <TB1> INFO: Event errors: 0
[21:10:55.837] <TB1> INFO: start marker: 0
[21:10:55.837] <TB1> INFO: stop marker: 0
[21:10:55.837] <TB1> INFO: overflow: 0
[21:10:55.837] <TB1> INFO: invalid 5bit words: 0
[21:10:55.837] <TB1> INFO: invalid XOR eye diagram: 0
[21:10:55.837] <TB1> INFO: frame (failed synchr.): 0
[21:10:55.837] <TB1> INFO: idle data (no TBM trl): 0
[21:10:55.837] <TB1> INFO: no data (only TBM hdr): 0
[21:10:55.837] <TB1> INFO: TBM errors: 0
[21:10:55.837] <TB1> INFO: flawed TBM headers: 0
[21:10:55.837] <TB1> INFO: flawed TBM trailers: 0
[21:10:55.837] <TB1> INFO: event ID mismatches: 0
[21:10:55.837] <TB1> INFO: ROC errors: 0
[21:10:55.837] <TB1> INFO: missing ROC header(s): 0
[21:10:55.837] <TB1> INFO: misplaced readback start: 0
[21:10:55.837] <TB1> INFO: Pixel decoding errors: 0
[21:10:55.837] <TB1> INFO: pixel data incomplete: 0
[21:10:55.837] <TB1> INFO: pixel address: 0
[21:10:55.837] <TB1> INFO: pulse height fill bit: 0
[21:10:55.837] <TB1> INFO: buffer corruption: 0
[21:10:55.854] <TB1> INFO: Decoding statistics:
[21:10:55.854] <TB1> INFO: General information:
[21:10:55.854] <TB1> INFO: 16bit words read: 3446642
[21:10:55.854] <TB1> INFO: valid events total: 353536
[21:10:55.854] <TB1> INFO: empty events: 18282
[21:10:55.854] <TB1> INFO: valid events with pixels: 335254
[21:10:55.854] <TB1> INFO: valid pixel hits: 662713
[21:10:55.854] <TB1> INFO: Event errors: 0
[21:10:55.854] <TB1> INFO: start marker: 0
[21:10:55.854] <TB1> INFO: stop marker: 0
[21:10:55.854] <TB1> INFO: overflow: 0
[21:10:55.854] <TB1> INFO: invalid 5bit words: 0
[21:10:55.854] <TB1> INFO: invalid XOR eye diagram: 0
[21:10:55.854] <TB1> INFO: frame (failed synchr.): 0
[21:10:55.854] <TB1> INFO: idle data (no TBM trl): 0
[21:10:55.854] <TB1> INFO: no data (only TBM hdr): 0
[21:10:55.854] <TB1> INFO: TBM errors: 0
[21:10:55.854] <TB1> INFO: flawed TBM headers: 0
[21:10:55.854] <TB1> INFO: flawed TBM trailers: 0
[21:10:55.854] <TB1> INFO: event ID mismatches: 0
[21:10:55.854] <TB1> INFO: ROC errors: 0
[21:10:55.854] <TB1> INFO: missing ROC header(s): 0
[21:10:55.854] <TB1> INFO: misplaced readback start: 0
[21:10:55.854] <TB1> INFO: Pixel decoding errors: 0
[21:10:55.854] <TB1> INFO: pixel data incomplete: 0
[21:10:55.854] <TB1> INFO: pixel address: 0
[21:10:55.854] <TB1> INFO: pulse height fill bit: 0
[21:10:55.854] <TB1> INFO: buffer corruption: 0
[21:10:55.855] <TB1> INFO: enter test to run
[21:10:55.855] <TB1> INFO: test: trim80 no parameter change
[21:10:55.855] <TB1> INFO: running: trim80
[21:10:55.856] <TB1> INFO: ######################################################################
[21:10:55.856] <TB1> INFO: PixTestTrim80::doTest()
[21:10:55.856] <TB1> INFO: ######################################################################
[21:10:55.857] <TB1> INFO: ----------------------------------------------------------------------
[21:10:55.857] <TB1> INFO: PixTestTrim80::trimTest() ntrig = 8, vcal = 80
[21:10:55.857] <TB1> INFO: ----------------------------------------------------------------------
[21:10:55.899] <TB1> INFO: ---> VthrComp thr map (minimal VthrComp)
[21:10:55.899] <TB1> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[21:10:55.912] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[21:10:55.912] <TB1> INFO: run 1 of 1
[21:10:56.148] <TB1> INFO: Expecting 5025280 events.
[21:11:24.145] <TB1> INFO: 674008 events read in total (27405ms).
[21:11:50.952] <TB1> INFO: 1345056 events read in total (54212ms).
[21:12:18.086] <TB1> INFO: 2014112 events read in total (81346ms).
[21:12:45.655] <TB1> INFO: 2681424 events read in total (108915ms).
[21:13:12.850] <TB1> INFO: 3349416 events read in total (136110ms).
[21:13:39.995] <TB1> INFO: 4017296 events read in total (163255ms).
[21:14:07.173] <TB1> INFO: 4684928 events read in total (190433ms).
[21:14:21.171] <TB1> INFO: 5025280 events read in total (204431ms).
[21:14:21.243] <TB1> INFO: Test took 205331ms.
[21:14:43.504] <TB1> INFO: ROC 0 VthrComp = 75
[21:14:43.504] <TB1> INFO: ROC 1 VthrComp = 69
[21:14:43.504] <TB1> INFO: ROC 2 VthrComp = 70
[21:14:43.504] <TB1> INFO: ROC 3 VthrComp = 70
[21:14:43.504] <TB1> INFO: ROC 4 VthrComp = 73
[21:14:43.504] <TB1> INFO: ROC 5 VthrComp = 74
[21:14:43.505] <TB1> INFO: ROC 6 VthrComp = 72
[21:14:43.505] <TB1> INFO: ROC 7 VthrComp = 70
[21:14:43.505] <TB1> INFO: ROC 8 VthrComp = 76
[21:14:43.505] <TB1> INFO: ROC 9 VthrComp = 74
[21:14:43.505] <TB1> INFO: ROC 10 VthrComp = 80
[21:14:43.505] <TB1> INFO: ROC 11 VthrComp = 75
[21:14:43.505] <TB1> INFO: ROC 12 VthrComp = 72
[21:14:43.506] <TB1> INFO: ROC 13 VthrComp = 73
[21:14:43.506] <TB1> INFO: ROC 14 VthrComp = 76
[21:14:43.506] <TB1> INFO: ROC 15 VthrComp = 71
[21:14:43.777] <TB1> INFO: Expecting 41600 events.
[21:14:47.222] <TB1> INFO: 41600 events read in total (2853ms).
[21:14:47.223] <TB1> INFO: Test took 3714ms.
[21:14:47.234] <TB1> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[21:14:47.234] <TB1> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[21:14:47.248] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[21:14:47.248] <TB1> INFO: run 1 of 1
[21:14:47.526] <TB1> INFO: Expecting 5025280 events.
[21:15:16.680] <TB1> INFO: 682232 events read in total (28562ms).
[21:15:43.561] <TB1> INFO: 1362656 events read in total (55443ms).
[21:16:10.922] <TB1> INFO: 2043776 events read in total (82804ms).
[21:16:37.873] <TB1> INFO: 2720160 events read in total (109755ms).
[21:17:05.121] <TB1> INFO: 3392656 events read in total (137003ms).
[21:17:32.097] <TB1> INFO: 4063184 events read in total (163979ms).
[21:17:58.958] <TB1> INFO: 4732456 events read in total (190840ms).
[21:18:11.124] <TB1> INFO: 5025280 events read in total (203006ms).
[21:18:11.368] <TB1> INFO: Test took 204120ms.
[21:18:32.245] <TB1> INFO: roc 0 with ID = 0 has maximal Vcal 106.989 for pixel 51/79 mean/min/max = 92.4096/77.7937/107.026
[21:18:32.245] <TB1> INFO: roc 1 with ID = 1 has maximal Vcal 104.284 for pixel 3/76 mean/min/max = 89.5232/74.042/105.004
[21:18:32.245] <TB1> INFO: roc 2 with ID = 2 has maximal Vcal 111.367 for pixel 0/43 mean/min/max = 92.6467/73.8279/111.465
[21:18:32.246] <TB1> INFO: roc 3 with ID = 3 has maximal Vcal 102.635 for pixel 9/64 mean/min/max = 88.199/73.6668/102.731
[21:18:32.246] <TB1> INFO: roc 4 with ID = 4 has maximal Vcal 108.908 for pixel 1/37 mean/min/max = 92.6805/76.2973/109.064
[21:18:32.247] <TB1> INFO: roc 5 with ID = 5 has maximal Vcal 110.562 for pixel 0/48 mean/min/max = 94.5409/78.2924/110.789
[21:18:32.247] <TB1> INFO: roc 6 with ID = 6 has maximal Vcal 109.894 for pixel 3/79 mean/min/max = 93.5431/77.1885/109.898
[21:18:32.248] <TB1> INFO: roc 7 with ID = 7 has maximal Vcal 106.257 for pixel 1/14 mean/min/max = 90.4902/74.5174/106.463
[21:18:32.248] <TB1> INFO: roc 8 with ID = 8 has maximal Vcal 107.625 for pixel 16/79 mean/min/max = 92.9756/78.0929/107.858
[21:18:32.249] <TB1> INFO: roc 9 with ID = 9 has maximal Vcal 107.13 for pixel 16/79 mean/min/max = 92.2024/77.241/107.164
[21:18:32.249] <TB1> INFO: roc 10 with ID = 10 has maximal Vcal 107.481 for pixel 15/78 mean/min/max = 91.5466/75.4994/107.594
[21:18:32.250] <TB1> INFO: roc 11 with ID = 11 has maximal Vcal 112.709 for pixel 0/76 mean/min/max = 94.6763/76.4943/112.858
[21:18:32.250] <TB1> INFO: roc 12 with ID = 12 has maximal Vcal 106.967 for pixel 0/11 mean/min/max = 91.475/75.8946/107.055
[21:18:32.250] <TB1> INFO: roc 13 with ID = 13 has maximal Vcal 110.6 for pixel 0/65 mean/min/max = 94.0364/77.376/110.697
[21:18:32.251] <TB1> INFO: roc 14 with ID = 14 has maximal Vcal 108.031 for pixel 4/74 mean/min/max = 93.0738/77.9418/108.206
[21:18:32.251] <TB1> INFO: roc 15 with ID = 15 has maximal Vcal 101.59 for pixel 0/26 mean/min/max = 87.9794/73.8501/102.109
[21:18:32.251] <TB1> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[21:18:32.340] <TB1> INFO: Expecting 411648 events.
[21:18:41.972] <TB1> INFO: 411648 events read in total (9040ms).
[21:18:41.980] <TB1> INFO: Expecting 411648 events.
[21:18:51.106] <TB1> INFO: 411648 events read in total (8723ms).
[21:18:51.120] <TB1> INFO: Expecting 411648 events.
[21:19:00.375] <TB1> INFO: 411648 events read in total (8852ms).
[21:19:00.392] <TB1> INFO: Expecting 411648 events.
[21:19:09.578] <TB1> INFO: 411648 events read in total (8783ms).
[21:19:09.594] <TB1> INFO: Expecting 411648 events.
[21:19:18.919] <TB1> INFO: 411648 events read in total (8922ms).
[21:19:18.939] <TB1> INFO: Expecting 411648 events.
[21:19:28.198] <TB1> INFO: 411648 events read in total (8856ms).
[21:19:28.220] <TB1> INFO: Expecting 411648 events.
[21:19:37.433] <TB1> INFO: 411648 events read in total (8810ms).
[21:19:37.458] <TB1> INFO: Expecting 411648 events.
[21:19:46.821] <TB1> INFO: 411648 events read in total (8961ms).
[21:19:46.849] <TB1> INFO: Expecting 411648 events.
[21:19:56.113] <TB1> INFO: 411648 events read in total (8861ms).
[21:19:56.143] <TB1> INFO: Expecting 411648 events.
[21:20:05.425] <TB1> INFO: 411648 events read in total (8878ms).
[21:20:05.463] <TB1> INFO: Expecting 411648 events.
[21:20:14.966] <TB1> INFO: 411648 events read in total (9100ms).
[21:20:15.007] <TB1> INFO: Expecting 411648 events.
[21:20:24.278] <TB1> INFO: 411648 events read in total (8867ms).
[21:20:24.318] <TB1> INFO: Expecting 411648 events.
[21:20:33.590] <TB1> INFO: 411648 events read in total (8869ms).
[21:20:33.638] <TB1> INFO: Expecting 411648 events.
[21:20:43.191] <TB1> INFO: 411648 events read in total (9141ms).
[21:20:43.240] <TB1> INFO: Expecting 411648 events.
[21:20:52.499] <TB1> INFO: 411648 events read in total (8856ms).
[21:20:52.552] <TB1> INFO: Expecting 411648 events.
[21:21:01.887] <TB1> INFO: 411648 events read in total (8932ms).
[21:21:01.949] <TB1> INFO: Test took 149698ms.
[21:21:03.551] <TB1> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[21:21:03.565] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[21:21:03.565] <TB1> INFO: run 1 of 1
[21:21:03.806] <TB1> INFO: Expecting 5025280 events.
[21:21:31.142] <TB1> INFO: 669760 events read in total (26744ms).
[21:21:58.404] <TB1> INFO: 1338000 events read in total (54006ms).
[21:22:25.374] <TB1> INFO: 2005336 events read in total (80976ms).
[21:22:52.264] <TB1> INFO: 2669192 events read in total (107866ms).
[21:23:19.354] <TB1> INFO: 3329120 events read in total (134956ms).
[21:23:46.447] <TB1> INFO: 3987760 events read in total (162049ms).
[21:24:13.226] <TB1> INFO: 4644840 events read in total (188828ms).
[21:24:28.971] <TB1> INFO: 5025280 events read in total (204573ms).
[21:24:29.028] <TB1> INFO: Test took 205463ms.
[21:24:52.328] <TB1> INFO: ---> TrimStepCorr4 extremal thresholds: 55.915569 .. 138.797065
[21:24:52.568] <TB1> INFO: Expecting 208000 events.
[21:25:02.308] <TB1> INFO: 208000 events read in total (9148ms).
[21:25:02.309] <TB1> INFO: Test took 9979ms.
[21:25:02.371] <TB1> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 45 .. 148 (-1/-1) hits flags = 528 (plus default)
[21:25:02.387] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[21:25:02.387] <TB1> INFO: run 1 of 1
[21:25:02.665] <TB1> INFO: Expecting 3461120 events.
[21:25:29.793] <TB1> INFO: 619384 events read in total (26536ms).
[21:25:55.857] <TB1> INFO: 1239232 events read in total (52601ms).
[21:26:22.230] <TB1> INFO: 1857424 events read in total (78973ms).
[21:26:48.452] <TB1> INFO: 2472856 events read in total (105195ms).
[21:27:14.762] <TB1> INFO: 3085376 events read in total (131505ms).
[21:27:30.849] <TB1> INFO: 3461120 events read in total (147592ms).
[21:27:30.914] <TB1> INFO: Test took 148527ms.
[21:27:53.137] <TB1> INFO: ---> TrimStepCorr2 extremal thresholds: 63.808261 .. 124.711551
[21:27:53.414] <TB1> INFO: Expecting 208000 events.
[21:28:03.230] <TB1> INFO: 208000 events read in total (9224ms).
[21:28:03.231] <TB1> INFO: Test took 10091ms.
[21:28:03.282] <TB1> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 53 .. 134 (-1/-1) hits flags = 528 (plus default)
[21:28:03.297] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[21:28:03.297] <TB1> INFO: run 1 of 1
[21:28:03.575] <TB1> INFO: Expecting 2728960 events.
[21:28:30.568] <TB1> INFO: 616248 events read in total (26402ms).
[21:28:56.619] <TB1> INFO: 1232480 events read in total (52453ms).
[21:29:22.930] <TB1> INFO: 1848384 events read in total (78764ms).
[21:29:49.449] <TB1> INFO: 2463664 events read in total (105283ms).
[21:30:01.113] <TB1> INFO: 2728960 events read in total (116947ms).
[21:30:01.151] <TB1> INFO: Test took 117855ms.
[21:30:22.916] <TB1> INFO: ---> TrimStepCorr1a extremal thresholds: 67.366816 .. 116.518263
[21:30:23.156] <TB1> INFO: Expecting 208000 events.
[21:30:32.613] <TB1> INFO: 208000 events read in total (8865ms).
[21:30:32.614] <TB1> INFO: Test took 9696ms.
[21:30:32.661] <TB1> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 57 .. 126 (-1/-1) hits flags = 528 (plus default)
[21:30:32.675] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[21:30:32.675] <TB1> INFO: run 1 of 1
[21:30:32.953] <TB1> INFO: Expecting 2329600 events.
[21:31:00.317] <TB1> INFO: 616352 events read in total (26773ms).
[21:31:26.534] <TB1> INFO: 1232536 events read in total (52991ms).
[21:31:53.532] <TB1> INFO: 1848880 events read in total (79988ms).
[21:32:14.124] <TB1> INFO: 2329600 events read in total (100580ms).
[21:32:14.174] <TB1> INFO: Test took 101499ms.
[21:32:34.460] <TB1> INFO: ---> TrimStepCorr1b extremal thresholds: 69.817125 .. 116.518263
[21:32:34.701] <TB1> INFO: Expecting 208000 events.
[21:32:44.773] <TB1> INFO: 208000 events read in total (9480ms).
[21:32:44.773] <TB1> INFO: Test took 10310ms.
[21:32:44.823] <TB1> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 59 .. 126 (-1/-1) hits flags = 528 (plus default)
[21:32:44.837] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[21:32:44.837] <TB1> INFO: run 1 of 1
[21:32:45.115] <TB1> INFO: Expecting 2263040 events.
[21:33:12.196] <TB1> INFO: 611848 events read in total (26489ms).
[21:33:38.186] <TB1> INFO: 1223368 events read in total (52479ms).
[21:34:04.707] <TB1> INFO: 1834472 events read in total (79000ms).
[21:34:23.140] <TB1> INFO: 2263040 events read in total (97433ms).
[21:34:23.179] <TB1> INFO: Test took 98342ms.
[21:34:42.265] <TB1> INFO: ---> TrimThrFinal extremal thresholds: 60 .. 100
[21:34:42.265] <TB1> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 60 .. 100 (-1/-1) hits flags = 528 (plus default)
[21:34:42.278] <TB1> INFO: dacScan split into 1 runs with ntrig = 8
[21:34:42.278] <TB1> INFO: run 1 of 1
[21:34:42.559] <TB1> INFO: Expecting 1364480 events.
[21:35:10.800] <TB1> INFO: 669024 events read in total (27649ms).
[21:35:38.705] <TB1> INFO: 1337688 events read in total (55555ms).
[21:35:40.285] <TB1> INFO: 1364480 events read in total (57134ms).
[21:35:40.313] <TB1> INFO: Test took 58035ms.
[21:35:57.763] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C0.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C1.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C2.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C3.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C4.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C5.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C6.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C7.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C8.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C9.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C10.dat
[21:35:57.764] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C11.dat
[21:35:57.765] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C12.dat
[21:35:57.765] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C13.dat
[21:35:57.765] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C14.dat
[21:35:57.765] <TB1> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//dacParameters80_C15.dat
[21:35:57.765] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C0.dat
[21:35:57.770] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C1.dat
[21:35:57.775] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C2.dat
[21:35:57.780] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C3.dat
[21:35:57.785] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C4.dat
[21:35:57.790] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C5.dat
[21:35:57.794] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C6.dat
[21:35:57.800] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C7.dat
[21:35:57.804] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C8.dat
[21:35:57.809] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C9.dat
[21:35:57.814] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C10.dat
[21:35:57.819] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C11.dat
[21:35:57.824] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C12.dat
[21:35:57.828] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C13.dat
[21:35:57.833] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C14.dat
[21:35:57.838] <TB1> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1005_FullQualification_2016-10-26_17h20m_1477495221//003_FulltestTrim80_p17//trimParameters80_C15.dat
[21:35:57.843] <TB1> INFO: PixTestTrim80::trimTest() done
[21:35:57.843] <TB1> INFO: vtrim: 83 89 100 81 102 102 104 98 100 94 107 101 86 102 105 81
[21:35:57.843] <TB1> INFO: vthrcomp: 75 69 70 70 73 74 72 70 76 74 80 75 72 73 76 71
[21:35:57.843] <TB1> INFO: vcal mean: 79.96 79.93 79.95 79.92 80.00 79.97 80.01 79.94 79.94 79.95 79.98 80.01 79.98 80.00 79.97 79.93
[21:35:57.843] <TB1> INFO: vcal RMS: 0.66 0.74 1.46 1.45 0.73 0.68 0.71 1.44 1.41 1.42 0.71 0.74 0.71 1.43 0.69 0.74
[21:35:57.843] <TB1> INFO: bits mean: 9.21 10.26 9.78 10.84 9.67 8.86 9.27 10.07 8.76 9.58 9.92 9.59 9.54 9.11 9.33 10.63
[21:35:57.843] <TB1> INFO: bits RMS: 2.38 2.55 2.62 2.35 2.39 2.39 2.36 2.53 2.44 2.27 2.40 2.32 2.51 2.46 2.27 2.49
[21:35:57.850] <TB1> INFO: ----------------------------------------------------------------------
[21:35:57.850] <TB1> INFO: PixTestTrim80::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[21:35:57.850] <TB1> INFO: ----------------------------------------------------------------------
[21:35:57.853] <TB1> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[21:35:57.866] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[21:35:57.866] <TB1> INFO: run 1 of 1
[21:35:58.106] <TB1> INFO: Expecting 4160000 events.
[21:36:31.076] <TB1> INFO: 760175 events read in total (32379ms).
[21:37:02.942] <TB1> INFO: 1512110 events read in total (64245ms).
[21:37:34.812] <TB1> INFO: 2257540 events read in total (96115ms).
[21:38:06.549] <TB1> INFO: 2998895 events read in total (127852ms).
[21:38:38.941] <TB1> INFO: 3735890 events read in total (160244ms).
[21:38:57.067] <TB1> INFO: 4160000 events read in total (178370ms).
[21:38:57.289] <TB1> INFO: Test took 179422ms.
[21:39:20.829] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 201 (-1/-1) hits flags = 528 (plus default)
[21:39:20.842] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[21:39:20.842] <TB1> INFO: run 1 of 1
[21:39:21.080] <TB1> INFO: Expecting 4201600 events.
[21:39:52.970] <TB1> INFO: 732835 events read in total (31299ms).
[21:40:24.749] <TB1> INFO: 1458060 events read in total (63078ms).
[21:40:56.769] <TB1> INFO: 2178205 events read in total (95099ms).
[21:41:28.872] <TB1> INFO: 2893510 events read in total (127201ms).
[21:42:00.618] <TB1> INFO: 3605750 events read in total (158947ms).
[21:42:26.317] <TB1> INFO: 4201600 events read in total (184646ms).
[21:42:26.533] <TB1> INFO: Test took 185691ms.
[21:42:51.549] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 189 (-1/-1) hits flags = 528 (plus default)
[21:42:51.562] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[21:42:51.562] <TB1> INFO: run 1 of 1
[21:42:51.798] <TB1> INFO: Expecting 3952000 events.
[21:43:24.233] <TB1> INFO: 750930 events read in total (31843ms).
[21:43:57.010] <TB1> INFO: 1492490 events read in total (64621ms).
[21:44:29.142] <TB1> INFO: 2227910 events read in total (96752ms).
[21:45:01.414] <TB1> INFO: 2959760 events read in total (129024ms).
[21:45:33.266] <TB1> INFO: 3686505 events read in total (160876ms).
[21:45:45.123] <TB1> INFO: 3952000 events read in total (172733ms).
[21:45:45.217] <TB1> INFO: Test took 173654ms.
[21:46:10.258] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 186 (-1/-1) hits flags = 528 (plus default)
[21:46:10.272] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[21:46:10.272] <TB1> INFO: run 1 of 1
[21:46:10.510] <TB1> INFO: Expecting 3889600 events.
[21:46:43.656] <TB1> INFO: 755740 events read in total (32555ms).
[21:47:16.350] <TB1> INFO: 1502170 events read in total (65249ms).
[21:47:48.807] <TB1> INFO: 2241975 events read in total (97706ms).
[21:48:21.449] <TB1> INFO: 2977775 events read in total (130348ms).
[21:48:54.417] <TB1> INFO: 3709880 events read in total (163316ms).
[21:49:02.564] <TB1> INFO: 3889600 events read in total (171463ms).
[21:49:02.614] <TB1> INFO: Test took 172341ms.
[21:49:25.226] <TB1> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 188 (-1/-1) hits flags = 528 (plus default)
[21:49:25.240] <TB1> INFO: dacScan split into 1 runs with ntrig = 5
[21:49:25.240] <TB1> INFO: run 1 of 1
[21:49:25.477] <TB1> INFO: Expecting 3931200 events.
[21:49:59.095] <TB1> INFO: 753775 events read in total (33027ms).
[21:50:31.803] <TB1> INFO: 1498110 events read in total (65734ms).
[21:51:05.073] <TB1> INFO: 2236165 events read in total (99004ms).
[21:51:37.856] <TB1> INFO: 2970500 events read in total (131787ms).
[21:52:10.203] <TB1> INFO: 3700515 events read in total (164135ms).
[21:52:20.489] <TB1> INFO: 3931200 events read in total (174420ms).
[21:52:20.540] <TB1> INFO: Test took 175300ms.
[21:52:42.370] <TB1> INFO: PixTestTrim80::trimBitTest() done
[21:52:42.371] <TB1> INFO: PixTestTrim80::doTest() done, duration: 2506 seconds
[21:52:42.999] <TB1> INFO: enter test to run
[21:52:42.999] <TB1> INFO: test: exit no parameter change
[21:52:43.211] <TB1> QUIET: Connection to board 154 closed.
[21:52:43.212] <TB1> INFO: pXar: this is the end, my friend