[16:39:42.252] <TB3> INFO: *** Welcome to pxar ***
[16:39:42.252] <TB3> INFO: *** Today: 2016/10/19
[16:39:42.258] <TB3> INFO: *** Version: c8ba-dirty
[16:39:42.258] <TB3> INFO: readRocDacs: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C15.dat
[16:39:42.258] <TB3> INFO: readTbmDacs: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//tbmParameters_C0a.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//tbmParameters_C1b.dat
[16:39:42.258] <TB3> INFO: readMaskFile: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//defaultMaskFile.dat
[16:39:42.258] <TB3> INFO: readTrimFile: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters_C0.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters_C15.dat
[16:39:42.329] <TB3> INFO: clk: 4
[16:39:42.329] <TB3> INFO: ctr: 4
[16:39:42.329] <TB3> INFO: sda: 19
[16:39:42.329] <TB3> INFO: tin: 9
[16:39:42.329] <TB3> INFO: level: 15
[16:39:42.329] <TB3> INFO: triggerdelay: 0
[16:39:42.329] <TB3> QUIET: Instanciating API for pxar v2.7.6+55~gafdbfd9
[16:39:42.329] <TB3> INFO: Log level: INFO
[16:39:42.337] <TB3> INFO: Found DTB DTB_WWVASW
[16:39:42.346] <TB3> QUIET: Connection to board DTB_WWVASW opened.
[16:39:42.348] <TB3> INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 126
HW version: DTB1.2
FW version: 4.6
SW version: 4.7
Options:
USB id: DTB_WWVASW
MAC address: 40D85511807E
Hostname: pixelDTB126
Comment:
------------------------------------------------------
[16:39:42.349] <TB3> INFO: RPC call hashes of host and DTB match: 486171790
[16:39:43.853] <TB3> INFO: DUT info:
[16:39:43.853] <TB3> INFO: The DUT currently contains the following objects:
[16:39:43.853] <TB3> INFO: 4 TBM Cores tbm10c (4 ON)
[16:39:43.853] <TB3> INFO: TBM Core alpha (0): 7 registers set
[16:39:43.853] <TB3> INFO: TBM Core beta (1): 7 registers set
[16:39:43.853] <TB3> INFO: TBM Core alpha (2): 7 registers set
[16:39:43.853] <TB3> INFO: TBM Core beta (3): 7 registers set
[16:39:43.853] <TB3> INFO: 16 ROCs proc600 (16 ON) with 4160 pixelConfigs
[16:39:43.853] <TB3> INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:43.853] <TB3> INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:39:44.254] <TB3> INFO: enter 'restricted' command line mode
[16:39:44.254] <TB3> INFO: enter test to run
[16:39:44.255] <TB3> INFO: test: pretest no parameter change
[16:39:44.255] <TB3> INFO: running: pretest
[16:39:44.264] <TB3> INFO: ######################################################################
[16:39:44.264] <TB3> INFO: PixTestPretest::doTest()
[16:39:44.264] <TB3> INFO: ######################################################################
[16:39:44.265] <TB3> INFO: ----------------------------------------------------------------------
[16:39:44.265] <TB3> INFO: PixTestPretest::programROC()
[16:39:44.265] <TB3> INFO: ----------------------------------------------------------------------
[16:40:02.280] <TB3> INFO: PixTestPretest::programROC() done: ROCs are all programmable
[16:40:02.280] <TB3> INFO: IA differences per ROC: 16.9 19.3 18.5 19.3 19.3 20.1 20.9 20.1 18.5 16.9 20.1 19.3 20.1 20.9 21.7 19.3
[16:40:02.344] <TB3> INFO: ----------------------------------------------------------------------
[16:40:02.344] <TB3> INFO: PixTestPretest::setVana() target Ia = 24 mA/ROC
[16:40:02.344] <TB3> INFO: ----------------------------------------------------------------------
[16:40:08.040] <TB3> INFO: PixTestPretest::setVana() done, Module Ia 386.7 mA = 24.1687 mA/ROC
[16:40:08.040] <TB3> INFO: i(loss) [mA/ROC]: 20.1 20.1 19.3 19.3 19.3 20.1 20.1 19.3 19.3 20.1 20.1 20.1 20.1 20.1 19.3 19.3
[16:40:08.073] <TB3> INFO: ----------------------------------------------------------------------
[16:40:08.073] <TB3> INFO: PixTestPretest::findTiming()
[16:40:08.073] <TB3> INFO: ----------------------------------------------------------------------
[16:40:08.073] <TB3> INFO: PixTestCmd::init()

[16:40:40.310] <TB3> INFO: TBM phases: 160MHz: 0, 400MHz: 2, TBM delays: ROC(0/1):5, header/trailer: 1, token: 1
[16:40:40.310] <TB3> INFO: (success/tries = 100/100), width = 4
[16:40:41.811] <TB3> INFO: ----------------------------------------------------------------------
[16:40:41.811] <TB3> INFO: PixTestPretest::findWorkingPixel()
[16:40:41.811] <TB3> INFO: ----------------------------------------------------------------------
[16:40:41.906] <TB3> INFO: Expecting 231680 events.
[16:40:51.878] <TB3> INFO: 231680 events read in total (9380ms).
[16:40:51.888] <TB3> INFO: Test took 10072ms.
[16:40:52.137] <TB3> INFO: Found working pixel in all ROCs: col/row = 12/22
[16:40:52.173] <TB3> INFO: ----------------------------------------------------------------------
[16:40:52.173] <TB3> INFO: PixTestPretest::setVthrCompCalDel()
[16:40:52.173] <TB3> INFO: ----------------------------------------------------------------------
[16:40:52.267] <TB3> INFO: Expecting 231680 events.
[16:41:02.204] <TB3> INFO: 231680 events read in total (9345ms).
[16:41:02.216] <TB3> INFO: Test took 10039ms.
[16:41:02.478] <TB3> INFO: PixTestPretest::setVthrCompCalDel() done
[16:41:02.478] <TB3> INFO: CalDel: 71 79 96 112 85 90 84 89 75 77 82 81 105 86 103 94
[16:41:02.478] <TB3> INFO: VthrComp: 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51 51
[16:41:02.481] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C0.dat
[16:41:02.482] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C1.dat
[16:41:02.482] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C2.dat
[16:41:02.482] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C3.dat
[16:41:02.482] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C4.dat
[16:41:02.482] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C5.dat
[16:41:02.483] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C6.dat
[16:41:02.483] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C7.dat
[16:41:02.483] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C8.dat
[16:41:02.483] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C9.dat
[16:41:02.483] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C10.dat
[16:41:02.483] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C11.dat
[16:41:02.484] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C12.dat
[16:41:02.484] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C13.dat
[16:41:02.484] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C14.dat
[16:41:02.484] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters_C15.dat
[16:41:02.484] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//tbmParameters_C0a.dat
[16:41:02.484] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//tbmParameters_C0b.dat
[16:41:02.485] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//tbmParameters_C1a.dat
[16:41:02.485] <TB3> INFO: write tbm parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//tbmParameters_C1b.dat
[16:41:02.485] <TB3> INFO: PixTestPretest::doTest() done, duration: 78 seconds
[16:41:02.541] <TB3> INFO: enter test to run
[16:41:02.541] <TB3> INFO: test: FullTest no parameter change
[16:41:02.541] <TB3> INFO: running: fulltest
[16:41:02.541] <TB3> INFO: ######################################################################
[16:41:02.541] <TB3> INFO: PixTestFullTest::doTest()
[16:41:02.541] <TB3> INFO: ######################################################################
[16:41:02.542] <TB3> INFO: ######################################################################
[16:41:02.542] <TB3> INFO: PixTestAlive::doTest()
[16:41:02.542] <TB3> INFO: ######################################################################
[16:41:02.544] <TB3> INFO: ----------------------------------------------------------------------
[16:41:02.544] <TB3> INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:41:02.544] <TB3> INFO: ----------------------------------------------------------------------
[16:41:02.781] <TB3> INFO: Expecting 41600 events.
[16:41:06.373] <TB3> INFO: 41600 events read in total (3000ms).
[16:41:06.374] <TB3> INFO: Test took 3829ms.
[16:41:06.608] <TB3> INFO: PixTestAlive::aliveTest() done
[16:41:06.608] <TB3> INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 1 0 0 0 0 0 1 0 0 0
[16:41:06.610] <TB3> INFO: ----------------------------------------------------------------------
[16:41:06.610] <TB3> INFO: PixTestAlive::maskTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:41:06.610] <TB3> INFO: ----------------------------------------------------------------------
[16:41:06.854] <TB3> INFO: Expecting 41600 events.
[16:41:09.863] <TB3> INFO: 41600 events read in total (2417ms).
[16:41:09.863] <TB3> INFO: Test took 3250ms.
[16:41:09.864] <TB3> INFO: mask vs. old pixelAlive PixelAlive_C0_V0 .. PixelAlive_C15_V0
[16:41:10.107] <TB3> INFO: PixTestAlive::maskTest() done
[16:41:10.107] <TB3> INFO: number of mask-defect pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:41:10.109] <TB3> INFO: ----------------------------------------------------------------------
[16:41:10.109] <TB3> INFO: PixTestAlive::addressDecodingTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[16:41:10.109] <TB3> INFO: ----------------------------------------------------------------------
[16:41:10.354] <TB3> INFO: Expecting 41600 events.
[16:41:13.989] <TB3> INFO: 41600 events read in total (3043ms).
[16:41:13.989] <TB3> INFO: Test took 3878ms.
[16:41:14.223] <TB3> INFO: PixTestAlive::addressDecodingTest() done
[16:41:14.224] <TB3> INFO: number of address-decoding pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:41:14.224] <TB3> INFO: PixTestAlive::doTest() done, duration: 11 seconds
[16:41:14.224] <TB3> INFO: Decoding statistics:
[16:41:14.224] <TB3> INFO: General information:
[16:41:14.224] <TB3> INFO: 16bit words read: 0
[16:41:14.224] <TB3> INFO: valid events total: 0
[16:41:14.224] <TB3> INFO: empty events: 0
[16:41:14.224] <TB3> INFO: valid events with pixels: 0
[16:41:14.224] <TB3> INFO: valid pixel hits: 0
[16:41:14.224] <TB3> INFO: Event errors: 0
[16:41:14.224] <TB3> INFO: start marker: 0
[16:41:14.224] <TB3> INFO: stop marker: 0
[16:41:14.224] <TB3> INFO: overflow: 0
[16:41:14.224] <TB3> INFO: invalid 5bit words: 0
[16:41:14.224] <TB3> INFO: invalid XOR eye diagram: 0
[16:41:14.224] <TB3> INFO: frame (failed synchr.): 0
[16:41:14.224] <TB3> INFO: idle data (no TBM trl): 0
[16:41:14.224] <TB3> INFO: no data (only TBM hdr): 0
[16:41:14.224] <TB3> INFO: TBM errors: 0
[16:41:14.224] <TB3> INFO: flawed TBM headers: 0
[16:41:14.224] <TB3> INFO: flawed TBM trailers: 0
[16:41:14.224] <TB3> INFO: event ID mismatches: 0
[16:41:14.224] <TB3> INFO: ROC errors: 0
[16:41:14.224] <TB3> INFO: missing ROC header(s): 0
[16:41:14.224] <TB3> INFO: misplaced readback start: 0
[16:41:14.225] <TB3> INFO: Pixel decoding errors: 0
[16:41:14.225] <TB3> INFO: pixel data incomplete: 0
[16:41:14.225] <TB3> INFO: pixel address: 0
[16:41:14.225] <TB3> INFO: pulse height fill bit: 0
[16:41:14.225] <TB3> INFO: buffer corruption: 0
[16:41:14.232] <TB3> INFO: readReadbackCal: /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C0.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C15.dat
[16:41:14.232] <TB3> INFO: readGainPedestalParameters /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr_C0.dat .. /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr_C15.dat

[16:41:14.232] <TB3> INFO: ######################################################################
[16:41:14.232] <TB3> INFO: PixTestReadback::doTest()
[16:41:14.232] <TB3> INFO: ######################################################################
[16:41:14.232] <TB3> INFO: ----------------------------------------------------------------------
[16:41:14.232] <TB3> INFO: PixTestReadback::CalibrateVd()
[16:41:14.232] <TB3> INFO: ----------------------------------------------------------------------
[16:41:24.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C0.dat
[16:41:24.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C1.dat
[16:41:24.217] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C2.dat
[16:41:24.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C3.dat
[16:41:24.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C4.dat
[16:41:24.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C5.dat
[16:41:24.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C6.dat
[16:41:24.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C7.dat
[16:41:24.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C8.dat
[16:41:24.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C9.dat
[16:41:24.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C10.dat
[16:41:24.218] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C11.dat
[16:41:24.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C12.dat
[16:41:24.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C13.dat
[16:41:24.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C14.dat
[16:41:24.219] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C15.dat
[16:41:24.251] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[16:41:24.252] <TB3> INFO: ----------------------------------------------------------------------
[16:41:24.252] <TB3> INFO: PixTestReadback::CalibrateVa()
[16:41:24.252] <TB3> INFO: ----------------------------------------------------------------------
[16:41:34.190] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C0.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C1.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C2.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C3.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C4.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C5.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C6.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C7.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C8.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C9.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C10.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C11.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C12.dat
[16:41:34.191] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C13.dat
[16:41:34.192] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C14.dat
[16:41:34.192] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C15.dat
[16:41:34.221] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[16:41:34.221] <TB3> INFO: ----------------------------------------------------------------------
[16:41:34.221] <TB3> INFO: PixTestReadback::readbackVbg()
[16:41:34.221] <TB3> INFO: ----------------------------------------------------------------------
[16:41:41.892] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[16:41:41.893] <TB3> INFO: ----------------------------------------------------------------------
[16:41:41.893] <TB3> INFO: PixTestReadback::getCalibratedVbg()
[16:41:41.893] <TB3> INFO: ----------------------------------------------------------------------
[16:41:41.893] <TB3> INFO: Vbg will be calibrated using Vd calibration
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 0: uncalibrated Vbg = 158.9calibrated Vbg = 1.21057 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 1: uncalibrated Vbg = 163.2calibrated Vbg = 1.21975 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 2: uncalibrated Vbg = 151.3calibrated Vbg = 1.21344 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 3: uncalibrated Vbg = 153.8calibrated Vbg = 1.21029 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 4: uncalibrated Vbg = 168.2calibrated Vbg = 1.20517 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 5: uncalibrated Vbg = 149.3calibrated Vbg = 1.21102 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 6: uncalibrated Vbg = 158.1calibrated Vbg = 1.21819 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 7: uncalibrated Vbg = 148.9calibrated Vbg = 1.21006 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 8: uncalibrated Vbg = 159calibrated Vbg = 1.20584 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 9: uncalibrated Vbg = 156.4calibrated Vbg = 1.20363 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 10: uncalibrated Vbg = 153.1calibrated Vbg = 1.20468 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 11: uncalibrated Vbg = 151.9calibrated Vbg = 1.19778 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 12: uncalibrated Vbg = 146.8calibrated Vbg = 1.20183 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 13: uncalibrated Vbg = 152.2calibrated Vbg = 1.21114 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 14: uncalibrated Vbg = 151calibrated Vbg = 1.21108 :::*/*/*/*/
[16:41:41.893] <TB3> INFO: /*/*/*/*::: ROC 15: uncalibrated Vbg = 158.6calibrated Vbg = 1.20623 :::*/*/*/*/
[16:41:41.896] <TB3> INFO: ----------------------------------------------------------------------
[16:41:41.896] <TB3> INFO: PixTestReadback::CalibrateIa()
[16:41:41.896] <TB3> INFO: ----------------------------------------------------------------------
[16:44:22.724] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C0.dat
[16:44:22.724] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C1.dat
[16:44:22.724] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C2.dat
[16:44:22.724] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C3.dat
[16:44:22.724] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C4.dat
[16:44:22.724] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C5.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C6.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C7.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C8.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C9.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C10.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C11.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C12.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C13.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C14.dat
[16:44:22.725] <TB3> INFO: write readback calibration parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//readbackCal_C15.dat
[16:44:22.751] <TB3> INFO: PixTestPattern:: pg_setup set to default.
[16:44:22.752] <TB3> INFO: PixTestReadback::doTest() done
[16:44:22.752] <TB3> INFO: Decoding statistics:
[16:44:22.752] <TB3> INFO: General information:
[16:44:22.752] <TB3> INFO: 16bit words read: 1558
[16:44:22.752] <TB3> INFO: valid events total: 256
[16:44:22.752] <TB3> INFO: empty events: 245
[16:44:22.752] <TB3> INFO: valid events with pixels: 11
[16:44:22.752] <TB3> INFO: valid pixel hits: 11
[16:44:22.752] <TB3> INFO: Event errors: 0
[16:44:22.752] <TB3> INFO: start marker: 0
[16:44:22.752] <TB3> INFO: stop marker: 0
[16:44:22.752] <TB3> INFO: overflow: 0
[16:44:22.752] <TB3> INFO: invalid 5bit words: 0
[16:44:22.752] <TB3> INFO: invalid XOR eye diagram: 0
[16:44:22.752] <TB3> INFO: frame (failed synchr.): 0
[16:44:22.752] <TB3> INFO: idle data (no TBM trl): 0
[16:44:22.752] <TB3> INFO: no data (only TBM hdr): 0
[16:44:22.752] <TB3> INFO: TBM errors: 0
[16:44:22.752] <TB3> INFO: flawed TBM headers: 0
[16:44:22.752] <TB3> INFO: flawed TBM trailers: 0
[16:44:22.752] <TB3> INFO: event ID mismatches: 0
[16:44:22.752] <TB3> INFO: ROC errors: 0
[16:44:22.752] <TB3> INFO: missing ROC header(s): 0
[16:44:22.752] <TB3> INFO: misplaced readback start: 0
[16:44:22.752] <TB3> INFO: Pixel decoding errors: 0
[16:44:22.752] <TB3> INFO: pixel data incomplete: 0
[16:44:22.752] <TB3> INFO: pixel address: 0
[16:44:22.752] <TB3> INFO: pulse height fill bit: 0
[16:44:22.752] <TB3> INFO: buffer corruption: 0
[16:44:22.801] <TB3> INFO: ######################################################################
[16:44:22.801] <TB3> INFO: PixTestBBMap::doTest() Ntrig = 5, VcalS = 250 (high range)
[16:44:22.801] <TB3> INFO: ######################################################################
[16:44:22.803] <TB3> INFO: ---> dac: VthrComp name: calSMap ntrig: 5 dacrange: 0 .. 149 (-1/-1) hits flags = 514 (plus default)
[16:44:22.817] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[16:44:22.817] <TB3> INFO: run 1 of 1
[16:44:23.053] <TB3> INFO: Expecting 3120000 events.
[16:44:54.205] <TB3> INFO: 672430 events read in total (30560ms).





















[16:45:24.676] <TB3> INFO: 1337175 events read in total (61031ms).











[16:45:54.804] <TB3> INFO: 1998030 events read in total (91160ms).





















[16:46:24.597] <TB3> INFO: 2657765 events read in total (120952ms).











[16:46:46.186] <TB3> INFO: 3120000 events read in total (142541ms).
[16:46:46.263] <TB3> INFO: Test took 143447ms.
[16:47:13.412] <TB3> INFO: PixTestBBMap::doTest() done with 3 decoding errors: , duration: 170 seconds
[16:47:13.412] <TB3> INFO: number of dead bumps (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 2 0 0 0
[16:47:13.412] <TB3> INFO: separation cut (per ROC): 108 128 101 104 107 109 111 109 112 107 117 109 104 111 104 109
[16:47:13.413] <TB3> INFO: Decoding statistics:
[16:47:13.413] <TB3> INFO: General information:
[16:47:13.413] <TB3> INFO: 16bit words read: 0
[16:47:13.413] <TB3> INFO: valid events total: 0
[16:47:13.413] <TB3> INFO: empty events: 0
[16:47:13.413] <TB3> INFO: valid events with pixels: 0
[16:47:13.413] <TB3> INFO: valid pixel hits: 0
[16:47:13.413] <TB3> INFO: Event errors: 0
[16:47:13.413] <TB3> INFO: start marker: 0
[16:47:13.413] <TB3> INFO: stop marker: 0
[16:47:13.413] <TB3> INFO: overflow: 0
[16:47:13.413] <TB3> INFO: invalid 5bit words: 0
[16:47:13.413] <TB3> INFO: invalid XOR eye diagram: 0
[16:47:13.413] <TB3> INFO: frame (failed synchr.): 0
[16:47:13.413] <TB3> INFO: idle data (no TBM trl): 0
[16:47:13.413] <TB3> INFO: no data (only TBM hdr): 0
[16:47:13.413] <TB3> INFO: TBM errors: 0
[16:47:13.413] <TB3> INFO: flawed TBM headers: 0
[16:47:13.413] <TB3> INFO: flawed TBM trailers: 0
[16:47:13.413] <TB3> INFO: event ID mismatches: 0
[16:47:13.413] <TB3> INFO: ROC errors: 0
[16:47:13.413] <TB3> INFO: missing ROC header(s): 0
[16:47:13.413] <TB3> INFO: misplaced readback start: 0
[16:47:13.413] <TB3> INFO: Pixel decoding errors: 0
[16:47:13.413] <TB3> INFO: pixel data incomplete: 0
[16:47:13.413] <TB3> INFO: pixel address: 0
[16:47:13.413] <TB3> INFO: pulse height fill bit: 0
[16:47:13.413] <TB3> INFO: buffer corruption: 0
[16:47:13.451] <TB3> INFO: ######################################################################
[16:47:13.451] <TB3> INFO: PixTestScurves::fullTest() ntrig = 50, dacs/step = -1, ntrig/step = -1
[16:47:13.451] <TB3> INFO: ######################################################################
[16:47:13.451] <TB3> INFO: ----------------------------------------------------------------------
[16:47:13.451] <TB3> INFO: PixTestScurves::scurves(Vcal), ntrig = 50, dacs/step = -1, ntrig/step = -1
[16:47:13.451] <TB3> INFO: ----------------------------------------------------------------------
[16:47:13.451] <TB3> INFO: ---> dac: Vcal name: scurveVcal ntrig: 50 dacrange: 25 .. 200 (-1/-1) hits flags = 528 (plus default)
[16:47:13.465] <TB3> INFO: dacScan split into 1 runs with ntrig = 50
[16:47:13.465] <TB3> INFO: run 1 of 1
[16:47:13.709] <TB3> INFO: Expecting 36608000 events.
[16:47:37.436] <TB3> INFO: 689050 events read in total (23136ms).
[16:48:00.258] <TB3> INFO: 1364200 events read in total (45958ms).
[16:48:23.187] <TB3> INFO: 2038200 events read in total (68887ms).
[16:48:46.066] <TB3> INFO: 2712250 events read in total (91766ms).
[16:49:09.077] <TB3> INFO: 3386900 events read in total (114777ms).
[16:49:32.026] <TB3> INFO: 4062450 events read in total (137726ms).
[16:49:55.259] <TB3> INFO: 4736900 events read in total (160959ms).
[16:50:18.679] <TB3> INFO: 5410700 events read in total (184379ms).
[16:50:41.940] <TB3> INFO: 6085150 events read in total (207640ms).
[16:51:05.267] <TB3> INFO: 6756600 events read in total (230967ms).
[16:51:28.246] <TB3> INFO: 7428900 events read in total (253946ms).
[16:51:50.923] <TB3> INFO: 8100150 events read in total (276623ms).
[16:52:14.134] <TB3> INFO: 8771850 events read in total (299834ms).
[16:52:37.313] <TB3> INFO: 9444550 events read in total (323013ms).
[16:53:00.321] <TB3> INFO: 10116500 events read in total (346021ms).
[16:53:23.540] <TB3> INFO: 10787150 events read in total (369240ms).
[16:53:46.389] <TB3> INFO: 11456450 events read in total (392089ms).
[16:54:09.383] <TB3> INFO: 12128300 events read in total (415083ms).
[16:54:32.162] <TB3> INFO: 12799400 events read in total (437862ms).
[16:54:55.083] <TB3> INFO: 13469150 events read in total (460783ms).
[16:55:18.087] <TB3> INFO: 14138300 events read in total (483787ms).
[16:55:41.045] <TB3> INFO: 14808250 events read in total (506745ms).
[16:56:04.060] <TB3> INFO: 15477950 events read in total (529760ms).
[16:56:27.062] <TB3> INFO: 16146500 events read in total (552762ms).
[16:56:49.001] <TB3> INFO: 16815300 events read in total (575701ms).
[16:57:12.987] <TB3> INFO: 17483850 events read in total (598687ms).
[16:57:36.017] <TB3> INFO: 18151350 events read in total (621717ms).
[16:57:58.002] <TB3> INFO: 18816800 events read in total (644702ms).
[16:58:21.836] <TB3> INFO: 19482500 events read in total (667536ms).
[16:58:44.884] <TB3> INFO: 20149150 events read in total (690584ms).
[16:59:07.770] <TB3> INFO: 20814450 events read in total (713470ms).
[16:59:30.844] <TB3> INFO: 21479850 events read in total (736544ms).
[16:59:54.012] <TB3> INFO: 22146150 events read in total (759712ms).
[17:00:16.997] <TB3> INFO: 22809500 events read in total (782697ms).
[17:00:39.803] <TB3> INFO: 23473900 events read in total (805503ms).
[17:01:02.760] <TB3> INFO: 24136850 events read in total (828460ms).
[17:01:25.708] <TB3> INFO: 24802200 events read in total (851408ms).
[17:01:48.560] <TB3> INFO: 25465950 events read in total (874260ms).
[17:02:11.694] <TB3> INFO: 26130500 events read in total (897394ms).
[17:02:34.696] <TB3> INFO: 26793200 events read in total (920396ms).
[17:02:57.634] <TB3> INFO: 27454050 events read in total (943334ms).
[17:03:20.248] <TB3> INFO: 28115050 events read in total (965948ms).
[17:03:43.306] <TB3> INFO: 28776450 events read in total (989006ms).
[17:04:06.243] <TB3> INFO: 29437400 events read in total (1011943ms).
[17:04:28.999] <TB3> INFO: 30099350 events read in total (1034699ms).
[17:04:52.198] <TB3> INFO: 30760650 events read in total (1057898ms).
[17:05:15.027] <TB3> INFO: 31421450 events read in total (1080727ms).
[17:05:37.785] <TB3> INFO: 32082800 events read in total (1103485ms).
[17:06:00.833] <TB3> INFO: 32744800 events read in total (1126533ms).
[17:06:23.587] <TB3> INFO: 33406550 events read in total (1149287ms).
[17:06:46.293] <TB3> INFO: 34068900 events read in total (1171993ms).
[17:07:08.957] <TB3> INFO: 34731800 events read in total (1194657ms).
[17:07:31.781] <TB3> INFO: 35394200 events read in total (1217481ms).
[17:07:54.988] <TB3> INFO: 36060900 events read in total (1240688ms).
[17:08:13.752] <TB3> INFO: 36608000 events read in total (1259452ms).
[17:08:13.819] <TB3> INFO: Test took 1260354ms.
[17:08:14.417] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:16.238] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:17.819] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:19.373] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:21.232] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:23.026] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:24.900] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:26.522] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:28.368] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:29.865] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:31.646] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:33.130] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:34.580] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:36.035] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:37.484] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:38.931] <TB3> INFO: dumping ASCII scurve output file: SCurveData
[17:08:40.437] <TB3> INFO: PixTestScurves::scurves() done
[17:08:40.437] <TB3> INFO: Vcal mean: 127.88 132.66 113.84 117.83 115.49 118.70 118.08 121.29 115.95 112.73 132.85 117.21 114.91 123.68 120.59 113.25
[17:08:40.437] <TB3> INFO: Vcal RMS: 6.76 6.33 5.02 5.04 5.24 5.90 6.11 5.71 5.58 5.43 6.23 5.59 5.68 6.01 5.79 5.46
[17:08:40.438] <TB3> INFO: PixTestScurves::fullTest() done, duration: 1286 seconds
[17:08:40.438] <TB3> INFO: Decoding statistics:
[17:08:40.438] <TB3> INFO: General information:
[17:08:40.438] <TB3> INFO: 16bit words read: 0
[17:08:40.438] <TB3> INFO: valid events total: 0
[17:08:40.438] <TB3> INFO: empty events: 0
[17:08:40.438] <TB3> INFO: valid events with pixels: 0
[17:08:40.438] <TB3> INFO: valid pixel hits: 0
[17:08:40.438] <TB3> INFO: Event errors: 0
[17:08:40.438] <TB3> INFO: start marker: 0
[17:08:40.438] <TB3> INFO: stop marker: 0
[17:08:40.438] <TB3> INFO: overflow: 0
[17:08:40.438] <TB3> INFO: invalid 5bit words: 0
[17:08:40.438] <TB3> INFO: invalid XOR eye diagram: 0
[17:08:40.438] <TB3> INFO: frame (failed synchr.): 0
[17:08:40.438] <TB3> INFO: idle data (no TBM trl): 0
[17:08:40.438] <TB3> INFO: no data (only TBM hdr): 0
[17:08:40.438] <TB3> INFO: TBM errors: 0
[17:08:40.438] <TB3> INFO: flawed TBM headers: 0
[17:08:40.438] <TB3> INFO: flawed TBM trailers: 0
[17:08:40.438] <TB3> INFO: event ID mismatches: 0
[17:08:40.438] <TB3> INFO: ROC errors: 0
[17:08:40.438] <TB3> INFO: missing ROC header(s): 0
[17:08:40.438] <TB3> INFO: misplaced readback start: 0
[17:08:40.438] <TB3> INFO: Pixel decoding errors: 0
[17:08:40.438] <TB3> INFO: pixel data incomplete: 0
[17:08:40.439] <TB3> INFO: pixel address: 0
[17:08:40.439] <TB3> INFO: pulse height fill bit: 0
[17:08:40.439] <TB3> INFO: buffer corruption: 0
[17:08:40.516] <TB3> INFO: ######################################################################
[17:08:40.516] <TB3> INFO: PixTestTrim::doTest()
[17:08:40.516] <TB3> INFO: ######################################################################
[17:08:40.517] <TB3> INFO: ----------------------------------------------------------------------
[17:08:40.517] <TB3> INFO: PixTestTrim::trimTest() ntrig = 8, vcal = 35
[17:08:40.517] <TB3> INFO: ----------------------------------------------------------------------
[17:08:40.558] <TB3> INFO: ---> VthrComp thr map (minimal VthrComp)
[17:08:40.558] <TB3> INFO: ---> dac: vthrcomp name: TrimThr0 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[17:08:40.570] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[17:08:40.570] <TB3> INFO: run 1 of 1
[17:08:40.806] <TB3> INFO: Expecting 5025280 events.
[17:09:12.332] <TB3> INFO: 830184 events read in total (30925ms).
[17:09:43.043] <TB3> INFO: 1657072 events read in total (61636ms).
[17:10:13.670] <TB3> INFO: 2481096 events read in total (92263ms).
[17:10:44.784] <TB3> INFO: 3300488 events read in total (123377ms).
[17:11:14.718] <TB3> INFO: 4114896 events read in total (153311ms).
[17:11:45.389] <TB3> INFO: 4928344 events read in total (183982ms).
[17:11:49.568] <TB3> INFO: 5025280 events read in total (188161ms).
[17:11:49.631] <TB3> INFO: Test took 189061ms.
[17:12:04.488] <TB3> INFO: ROC 0 VthrComp = 131
[17:12:04.488] <TB3> INFO: ROC 1 VthrComp = 135
[17:12:04.488] <TB3> INFO: ROC 2 VthrComp = 114
[17:12:04.489] <TB3> INFO: ROC 3 VthrComp = 120
[17:12:04.489] <TB3> INFO: ROC 4 VthrComp = 119
[17:12:04.489] <TB3> INFO: ROC 5 VthrComp = 127
[17:12:04.489] <TB3> INFO: ROC 6 VthrComp = 117
[17:12:04.489] <TB3> INFO: ROC 7 VthrComp = 129
[17:12:04.489] <TB3> INFO: ROC 8 VthrComp = 126
[17:12:04.489] <TB3> INFO: ROC 9 VthrComp = 122
[17:12:04.489] <TB3> INFO: ROC 10 VthrComp = 131
[17:12:04.490] <TB3> INFO: ROC 11 VthrComp = 130
[17:12:04.490] <TB3> INFO: ROC 12 VthrComp = 124
[17:12:04.490] <TB3> INFO: ROC 13 VthrComp = 131
[17:12:04.490] <TB3> INFO: ROC 14 VthrComp = 128
[17:12:04.490] <TB3> INFO: ROC 15 VthrComp = 121
[17:12:04.749] <TB3> INFO: Expecting 41600 events.
[17:12:08.217] <TB3> INFO: 41600 events read in total (2876ms).
[17:12:08.218] <TB3> INFO: Test took 3726ms.
[17:12:08.227] <TB3> INFO: ---> Vcal thr map (pixel with maximum Vcal thr)
[17:12:08.227] <TB3> INFO: ---> dac: vcal name: TrimThr1 ntrig: 8 dacrange: 10 .. 160 (-1/-1) hits flags = 528 (plus default)
[17:12:08.238] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[17:12:08.238] <TB3> INFO: run 1 of 1
[17:12:08.516] <TB3> INFO: Expecting 5025280 events.
[17:12:35.797] <TB3> INFO: 589736 events read in total (26689ms).
[17:13:01.794] <TB3> INFO: 1178608 events read in total (52686ms).
[17:13:27.683] <TB3> INFO: 1768096 events read in total (78575ms).
[17:13:53.527] <TB3> INFO: 2356424 events read in total (104419ms).
[17:14:19.810] <TB3> INFO: 2942688 events read in total (130702ms).
[17:14:45.684] <TB3> INFO: 3527944 events read in total (156576ms).
[17:15:11.397] <TB3> INFO: 4111720 events read in total (182289ms).
[17:15:37.421] <TB3> INFO: 4695224 events read in total (208313ms).
[17:15:52.517] <TB3> INFO: 5025280 events read in total (223409ms).
[17:15:52.592] <TB3> INFO: Test took 224354ms.
[17:16:18.668] <TB3> INFO: roc 0 with ID = 0 has maximal Vcal 62.106 for pixel 6/79 mean/min/max = 47.1178/32.0768/62.1588
[17:16:18.668] <TB3> INFO: roc 1 with ID = 1 has maximal Vcal 63.5847 for pixel 23/8 mean/min/max = 49.7403/35.6512/63.8294
[17:16:18.669] <TB3> INFO: roc 2 with ID = 2 has maximal Vcal 58.0622 for pixel 30/1 mean/min/max = 45.9376/33.5276/58.3477
[17:16:18.669] <TB3> INFO: roc 3 with ID = 3 has maximal Vcal 59.5937 for pixel 51/24 mean/min/max = 46.6281/33.4648/59.7913
[17:16:18.670] <TB3> INFO: roc 4 with ID = 4 has maximal Vcal 57.4884 for pixel 11/11 mean/min/max = 44.9422/32.3919/57.4926
[17:16:18.670] <TB3> INFO: roc 5 with ID = 5 has maximal Vcal 57.7479 for pixel 0/57 mean/min/max = 45.1616/32.3163/58.0069
[17:16:18.670] <TB3> INFO: roc 6 with ID = 6 has maximal Vcal 64.4863 for pixel 10/3 mean/min/max = 47.9901/31.4244/64.5558
[17:16:18.671] <TB3> INFO: roc 7 with ID = 7 has maximal Vcal 59.1934 for pixel 12/2 mean/min/max = 45.4131/31.5996/59.2266
[17:16:18.671] <TB3> INFO: roc 8 with ID = 8 has maximal Vcal 57.5702 for pixel 48/61 mean/min/max = 44.7328/31.8729/57.5928
[17:16:18.672] <TB3> INFO: roc 9 with ID = 9 has maximal Vcal 59.0204 for pixel 0/9 mean/min/max = 46.1868/33.2022/59.1714
[17:16:18.672] <TB3> INFO: roc 10 with ID = 10 has maximal Vcal 63.7049 for pixel 11/60 mean/min/max = 49.3099/34.7441/63.8756
[17:16:18.672] <TB3> INFO: roc 11 with ID = 11 has maximal Vcal 56.5752 for pixel 2/63 mean/min/max = 44.5416/32.4659/56.6174
[17:16:18.673] <TB3> INFO: roc 12 with ID = 12 has maximal Vcal 58.2778 for pixel 19/63 mean/min/max = 45.5779/32.8341/58.3217
[17:16:18.673] <TB3> INFO: roc 13 with ID = 13 has maximal Vcal 58.4125 for pixel 3/18 mean/min/max = 45.9968/33.3122/58.6813
[17:16:18.673] <TB3> INFO: roc 14 with ID = 14 has maximal Vcal 59.7105 for pixel 5/76 mean/min/max = 46.3579/32.9986/59.7173
[17:16:18.674] <TB3> INFO: roc 15 with ID = 15 has maximal Vcal 59.2262 for pixel 0/8 mean/min/max = 45.8958/32.3438/59.4478
[17:16:18.674] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:16:18.763] <TB3> INFO: Expecting 411648 events.
[17:16:28.412] <TB3> INFO: 411648 events read in total (9058ms).
[17:16:28.422] <TB3> INFO: Expecting 411648 events.
[17:16:37.883] <TB3> INFO: 411648 events read in total (9046ms).
[17:16:37.897] <TB3> INFO: Expecting 411648 events.
[17:16:47.430] <TB3> INFO: 411648 events read in total (9125ms).
[17:16:47.445] <TB3> INFO: Expecting 411648 events.
[17:16:56.950] <TB3> INFO: 411648 events read in total (9103ms).
[17:16:56.974] <TB3> INFO: Expecting 411648 events.
[17:17:06.412] <TB3> INFO: 411648 events read in total (9035ms).
[17:17:06.431] <TB3> INFO: Expecting 411648 events.
[17:17:15.826] <TB3> INFO: 411648 events read in total (8991ms).
[17:17:15.853] <TB3> INFO: Expecting 411648 events.
[17:17:25.326] <TB3> INFO: 411648 events read in total (9070ms).
[17:17:25.351] <TB3> INFO: Expecting 411648 events.
[17:17:34.838] <TB3> INFO: 411648 events read in total (9084ms).
[17:17:34.867] <TB3> INFO: Expecting 411648 events.
[17:17:44.447] <TB3> INFO: 411648 events read in total (9174ms).
[17:17:44.477] <TB3> INFO: Expecting 411648 events.
[17:17:53.892] <TB3> INFO: 411648 events read in total (9012ms).
[17:17:53.926] <TB3> INFO: Expecting 411648 events.
[17:18:03.308] <TB3> INFO: 411648 events read in total (8979ms).
[17:18:03.345] <TB3> INFO: Expecting 411648 events.
[17:18:12.693] <TB3> INFO: 411648 events read in total (8945ms).
[17:18:12.743] <TB3> INFO: Expecting 411648 events.
[17:18:22.099] <TB3> INFO: 411648 events read in total (8953ms).
[17:18:22.141] <TB3> INFO: Expecting 411648 events.
[17:18:31.415] <TB3> INFO: 411648 events read in total (8871ms).
[17:18:31.461] <TB3> INFO: Expecting 411648 events.
[17:18:40.870] <TB3> INFO: 411648 events read in total (9006ms).
[17:18:40.917] <TB3> INFO: Expecting 411648 events.
[17:18:50.245] <TB3> INFO: 411648 events read in total (8925ms).
[17:18:50.310] <TB3> INFO: Test took 151636ms.
[17:18:51.116] <TB3> INFO: ---> dac: vcal name: TrimThr2 ntrig: 8 dacrange: 0 .. 150 (-1/-1) hits flags = 528 (plus default)
[17:18:51.129] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[17:18:51.129] <TB3> INFO: run 1 of 1
[17:18:51.367] <TB3> INFO: Expecting 5025280 events.
[17:19:17.762] <TB3> INFO: 586280 events read in total (25803ms).
[17:19:43.729] <TB3> INFO: 1170896 events read in total (51770ms).
[17:20:09.745] <TB3> INFO: 1755528 events read in total (77786ms).
[17:20:35.952] <TB3> INFO: 2338672 events read in total (103993ms).
[17:21:01.996] <TB3> INFO: 2921872 events read in total (130038ms).
[17:21:28.027] <TB3> INFO: 3505616 events read in total (156068ms).
[17:21:54.266] <TB3> INFO: 4087536 events read in total (182307ms).
[17:22:19.874] <TB3> INFO: 4671056 events read in total (207915ms).
[17:22:36.344] <TB3> INFO: 5025280 events read in total (224385ms).
[17:22:36.521] <TB3> INFO: Test took 225393ms.
[17:23:04.087] <TB3> INFO: ---> TrimStepCorr4 extremal thresholds: 2.105747 .. 145.071255
[17:23:04.326] <TB3> INFO: Expecting 208000 events.
[17:23:14.127] <TB3> INFO: 208000 events read in total (9209ms).
[17:23:14.128] <TB3> INFO: Test took 10040ms.
[17:23:14.178] <TB3> INFO: ---> dac: vcal name: trimStepCorr4 ntrig: 8 dacrange: 2 .. 155 (-1/-1) hits flags = 528 (plus default)
[17:23:14.193] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[17:23:14.193] <TB3> INFO: run 1 of 1
[17:23:14.472] <TB3> INFO: Expecting 5125120 events.
[17:23:40.507] <TB3> INFO: 583576 events read in total (25444ms).
[17:24:05.934] <TB3> INFO: 1166912 events read in total (50871ms).
[17:24:31.628] <TB3> INFO: 1750232 events read in total (76565ms).
[17:24:56.957] <TB3> INFO: 2333752 events read in total (101894ms).
[17:25:22.647] <TB3> INFO: 2916984 events read in total (127584ms).
[17:25:48.389] <TB3> INFO: 3499736 events read in total (153326ms).
[17:26:13.742] <TB3> INFO: 4081976 events read in total (178679ms).
[17:26:39.477] <TB3> INFO: 4663728 events read in total (204414ms).
[17:27:00.093] <TB3> INFO: 5125120 events read in total (225030ms).
[17:27:00.216] <TB3> INFO: Test took 226024ms.
[17:27:30.006] <TB3> INFO: ---> TrimStepCorr2 extremal thresholds: 28.455869 .. 44.195955
[17:27:30.290] <TB3> INFO: Expecting 208000 events.
[17:27:40.038] <TB3> INFO: 208000 events read in total (9156ms).
[17:27:40.039] <TB3> INFO: Test took 10032ms.
[17:27:40.121] <TB3> INFO: ---> dac: vcal name: trimStepCorr2 ntrig: 8 dacrange: 18 .. 54 (-1/-1) hits flags = 528 (plus default)
[17:27:40.135] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[17:27:40.135] <TB3> INFO: run 1 of 1
[17:27:40.420] <TB3> INFO: Expecting 1231360 events.
[17:28:09.100] <TB3> INFO: 660296 events read in total (28089ms).
[17:28:33.344] <TB3> INFO: 1231360 events read in total (52333ms).
[17:28:33.384] <TB3> INFO: Test took 53250ms.
[17:28:48.541] <TB3> INFO: ---> TrimStepCorr1a extremal thresholds: 27.261153 .. 46.851066
[17:28:48.783] <TB3> INFO: Expecting 208000 events.
[17:28:59.309] <TB3> INFO: 208000 events read in total (9935ms).
[17:28:59.310] <TB3> INFO: Test took 10767ms.
[17:28:59.357] <TB3> INFO: ---> dac: vcal name: trimStepCorr1a ntrig: 8 dacrange: 17 .. 56 (-1/-1) hits flags = 528 (plus default)
[17:28:59.371] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[17:28:59.371] <TB3> INFO: run 1 of 1
[17:28:59.649] <TB3> INFO: Expecting 1331200 events.
[17:29:27.338] <TB3> INFO: 655936 events read in total (27097ms).
[17:29:54.809] <TB3> INFO: 1310672 events read in total (54569ms).
[17:29:56.124] <TB3> INFO: 1331200 events read in total (55884ms).
[17:29:56.153] <TB3> INFO: Test took 56783ms.
[17:30:08.668] <TB3> INFO: ---> TrimStepCorr1b extremal thresholds: 25.888010 .. 46.422275
[17:30:08.906] <TB3> INFO: Expecting 208000 events.
[17:30:18.667] <TB3> INFO: 208000 events read in total (9170ms).
[17:30:18.668] <TB3> INFO: Test took 9998ms.
[17:30:18.734] <TB3> INFO: ---> dac: vcal name: trimStepCorr1b ntrig: 8 dacrange: 15 .. 56 (-1/-1) hits flags = 528 (plus default)
[17:30:18.748] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[17:30:18.748] <TB3> INFO: run 1 of 1
[17:30:19.026] <TB3> INFO: Expecting 1397760 events.
[17:30:47.741] <TB3> INFO: 663984 events read in total (28124ms).
[17:31:15.591] <TB3> INFO: 1327992 events read in total (55974ms).
[17:31:18.905] <TB3> INFO: 1397760 events read in total (59288ms).
[17:31:18.933] <TB3> INFO: Test took 60186ms.
[17:31:32.236] <TB3> INFO: ---> TrimThrFinal extremal thresholds: 15 .. 55
[17:31:32.236] <TB3> INFO: ---> dac: vcal name: TrimThrFinal ntrig: 8 dacrange: 15 .. 55 (-1/-1) hits flags = 528 (plus default)
[17:31:32.250] <TB3> INFO: dacScan split into 1 runs with ntrig = 8
[17:31:32.250] <TB3> INFO: run 1 of 1
[17:31:32.524] <TB3> INFO: Expecting 1364480 events.
[17:32:00.767] <TB3> INFO: 668424 events read in total (27651ms).
[17:32:28.621] <TB3> INFO: 1336856 events read in total (55505ms).
[17:32:30.155] <TB3> INFO: 1364480 events read in total (57040ms).
[17:32:30.192] <TB3> INFO: Test took 57942ms.
[17:32:42.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C0.dat
[17:32:42.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C1.dat
[17:32:42.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C2.dat
[17:32:42.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C3.dat
[17:32:42.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C4.dat
[17:32:42.845] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C5.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C6.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C7.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C8.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C9.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C10.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C11.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C12.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C13.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C14.dat
[17:32:42.846] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C15.dat
[17:32:42.846] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C0.dat
[17:32:42.853] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C1.dat
[17:32:42.859] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C2.dat
[17:32:42.865] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C3.dat
[17:32:42.871] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C4.dat
[17:32:42.878] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C5.dat
[17:32:42.884] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C6.dat
[17:32:42.890] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C7.dat
[17:32:42.896] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C8.dat
[17:32:42.902] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C9.dat
[17:32:42.907] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C10.dat
[17:32:42.911] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C11.dat
[17:32:42.916] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C12.dat
[17:32:42.921] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C13.dat
[17:32:42.926] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C14.dat
[17:32:42.930] <TB3> INFO: write trim parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//trimParameters35_C15.dat
[17:32:42.935] <TB3> INFO: PixTestTrim::trimTest() done
[17:32:42.935] <TB3> INFO: vtrim: 132 164 124 120 114 119 144 130 142 117 154 125 122 129 129 120
[17:32:42.935] <TB3> INFO: vthrcomp: 131 135 114 120 119 127 117 129 126 122 131 130 124 131 128 121
[17:32:42.935] <TB3> INFO: vcal mean: 35.08 35.02 35.08 35.07 35.01 34.98 35.00 35.00 35.00 35.03 35.16 34.90 35.00 34.95 35.04 34.98
[17:32:42.935] <TB3> INFO: vcal RMS: 1.18 1.05 1.17 1.03 1.01 0.98 1.13 1.06 0.94 0.94 1.18 0.98 1.11 0.99 1.02 0.93
[17:32:42.935] <TB3> INFO: bits mean: 9.15 8.53 9.48 8.92 9.58 9.38 9.49 9.79 10.11 8.92 8.40 9.89 9.36 9.28 9.11 9.11
[17:32:42.935] <TB3> INFO: bits RMS: 2.81 2.31 2.59 2.76 2.68 2.78 2.68 2.68 2.53 2.81 2.63 2.53 2.66 2.65 2.74 2.86
[17:32:42.943] <TB3> INFO: ----------------------------------------------------------------------
[17:32:42.943] <TB3> INFO: PixTestTrim::trimBitTest() ntrig = 5, vtrims = 254 126 63 32
[17:32:42.943] <TB3> INFO: ----------------------------------------------------------------------
[17:32:42.945] <TB3> INFO: ---> dac: Vcal name: TrimBitsThr0 ntrig: 5 dacrange: 0 .. 199 (-1/-1) hits flags = 528 (plus default)
[17:32:42.959] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[17:32:42.959] <TB3> INFO: run 1 of 1
[17:32:43.282] <TB3> INFO: Expecting 4160000 events.
[17:33:15.966] <TB3> INFO: 761125 events read in total (32092ms).
[17:33:48.497] <TB3> INFO: 1515545 events read in total (64623ms).
[17:34:21.110] <TB3> INFO: 2264040 events read in total (97236ms).
[17:34:53.279] <TB3> INFO: 3007675 events read in total (129405ms).
[17:35:24.529] <TB3> INFO: 3747520 events read in total (160655ms).
[17:35:42.303] <TB3> INFO: 4160000 events read in total (178429ms).
[17:35:42.394] <TB3> INFO: Test took 179435ms.
[17:36:10.754] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim14 ntrig: 5 dacrange: 0 .. 207 (-1/-1) hits flags = 528 (plus default)
[17:36:10.768] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[17:36:10.768] <TB3> INFO: run 1 of 1
[17:36:11.028] <TB3> INFO: Expecting 4326400 events.
[17:36:42.618] <TB3> INFO: 726220 events read in total (30999ms).
[17:37:14.307] <TB3> INFO: 1447435 events read in total (62688ms).
[17:37:45.928] <TB3> INFO: 2163965 events read in total (94309ms).
[17:38:17.440] <TB3> INFO: 2874885 events read in total (125821ms).
[17:38:48.062] <TB3> INFO: 3583395 events read in total (156443ms).
[17:39:19.238] <TB3> INFO: 4292120 events read in total (187619ms).
[17:39:21.077] <TB3> INFO: 4326400 events read in total (189458ms).
[17:39:21.154] <TB3> INFO: Test took 190386ms.
[17:39:50.931] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim13 ntrig: 5 dacrange: 0 .. 195 (-1/-1) hits flags = 528 (plus default)
[17:39:50.944] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[17:39:50.944] <TB3> INFO: run 1 of 1
[17:39:51.203] <TB3> INFO: Expecting 4076800 events.
[17:40:23.527] <TB3> INFO: 742335 events read in total (31732ms).
[17:40:55.217] <TB3> INFO: 1478905 events read in total (63422ms).
[17:41:26.713] <TB3> INFO: 2210190 events read in total (94918ms).
[17:41:58.055] <TB3> INFO: 2936025 events read in total (126260ms).
[17:42:29.097] <TB3> INFO: 3658145 events read in total (157302ms).
[17:42:47.394] <TB3> INFO: 4076800 events read in total (175599ms).
[17:42:47.483] <TB3> INFO: Test took 176538ms.
[17:43:12.595] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim11 ntrig: 5 dacrange: 0 .. 194 (-1/-1) hits flags = 528 (plus default)
[17:43:12.608] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[17:43:12.608] <TB3> INFO: run 1 of 1
[17:43:12.850] <TB3> INFO: Expecting 4056000 events.
[17:43:44.642] <TB3> INFO: 744780 events read in total (31200ms).
[17:44:16.827] <TB3> INFO: 1483600 events read in total (63385ms).
[17:44:48.884] <TB3> INFO: 2216080 events read in total (95442ms).
[17:45:21.050] <TB3> INFO: 2943940 events read in total (127608ms).
[17:45:52.344] <TB3> INFO: 3667890 events read in total (158902ms).
[17:46:09.367] <TB3> INFO: 4056000 events read in total (175925ms).
[17:46:09.482] <TB3> INFO: Test took 176874ms.
[17:46:34.459] <TB3> INFO: ---> dac: Vcal name: TrimThr_trim7 ntrig: 5 dacrange: 0 .. 193 (-1/-1) hits flags = 528 (plus default)
[17:46:34.472] <TB3> INFO: dacScan split into 1 runs with ntrig = 5
[17:46:34.472] <TB3> INFO: run 1 of 1
[17:46:34.737] <TB3> INFO: Expecting 4035200 events.
[17:47:08.238] <TB3> INFO: 746210 events read in total (32909ms).
[17:47:40.212] <TB3> INFO: 1485660 events read in total (64883ms).
[17:48:11.713] <TB3> INFO: 2219715 events read in total (96384ms).
[17:48:43.061] <TB3> INFO: 2949175 events read in total (127732ms).
[17:49:15.017] <TB3> INFO: 3673980 events read in total (159688ms).
[17:49:30.678] <TB3> INFO: 4035200 events read in total (175349ms).
[17:49:30.765] <TB3> INFO: Test took 176293ms.
[17:49:55.448] <TB3> INFO: PixTestTrim::trimBitTest() done
[17:49:55.449] <TB3> INFO: PixTestTrim::doTest() done, duration: 2474 seconds
[17:49:55.449] <TB3> INFO: Decoding statistics:
[17:49:55.449] <TB3> INFO: General information:
[17:49:55.449] <TB3> INFO: 16bit words read: 0
[17:49:55.449] <TB3> INFO: valid events total: 0
[17:49:55.449] <TB3> INFO: empty events: 0
[17:49:55.449] <TB3> INFO: valid events with pixels: 0
[17:49:55.449] <TB3> INFO: valid pixel hits: 0
[17:49:55.449] <TB3> INFO: Event errors: 0
[17:49:55.449] <TB3> INFO: start marker: 0
[17:49:55.449] <TB3> INFO: stop marker: 0
[17:49:55.449] <TB3> INFO: overflow: 0
[17:49:55.449] <TB3> INFO: invalid 5bit words: 0
[17:49:55.449] <TB3> INFO: invalid XOR eye diagram: 0
[17:49:55.449] <TB3> INFO: frame (failed synchr.): 0
[17:49:55.449] <TB3> INFO: idle data (no TBM trl): 0
[17:49:55.449] <TB3> INFO: no data (only TBM hdr): 0
[17:49:55.449] <TB3> INFO: TBM errors: 0
[17:49:55.449] <TB3> INFO: flawed TBM headers: 0
[17:49:55.449] <TB3> INFO: flawed TBM trailers: 0
[17:49:55.449] <TB3> INFO: event ID mismatches: 0
[17:49:55.449] <TB3> INFO: ROC errors: 0
[17:49:55.449] <TB3> INFO: missing ROC header(s): 0
[17:49:55.449] <TB3> INFO: misplaced readback start: 0
[17:49:55.449] <TB3> INFO: Pixel decoding errors: 0
[17:49:55.449] <TB3> INFO: pixel data incomplete: 0
[17:49:55.449] <TB3> INFO: pixel address: 0
[17:49:55.449] <TB3> INFO: pulse height fill bit: 0
[17:49:55.449] <TB3> INFO: buffer corruption: 0
[17:49:56.048] <TB3> INFO: ######################################################################
[17:49:56.048] <TB3> INFO: PixTestPhOptimization::doTest() Ntrig = 10
[17:49:56.048] <TB3> INFO: ######################################################################
[17:49:56.287] <TB3> INFO: Expecting 41600 events.
[17:49:59.738] <TB3> INFO: 41600 events read in total (2859ms).
[17:49:59.739] <TB3> INFO: Test took 3689ms.
[17:50:00.181] <TB3> INFO: Expecting 41600 events.
[17:50:03.691] <TB3> INFO: 41600 events read in total (2919ms).
[17:50:03.692] <TB3> INFO: Test took 3750ms.
[17:50:03.980] <TB3> INFO: Expecting 41600 events.
[17:50:07.448] <TB3> INFO: 41600 events read in total (2876ms).
[17:50:07.448] <TB3> INFO: Test took 3732ms.
[17:50:07.737] <TB3> INFO: Expecting 41600 events.
[17:50:11.222] <TB3> INFO: 41600 events read in total (2893ms).
[17:50:11.223] <TB3> INFO: Test took 3751ms.
[17:50:11.515] <TB3> INFO: Expecting 41600 events.
[17:50:15.008] <TB3> INFO: 41600 events read in total (2893ms).
[17:50:15.009] <TB3> INFO: Test took 3759ms.
[17:50:15.300] <TB3> INFO: Expecting 41600 events.
[17:50:18.788] <TB3> INFO: 41600 events read in total (2897ms).
[17:50:18.789] <TB3> INFO: Test took 3754ms.
[17:50:19.091] <TB3> INFO: Expecting 41600 events.
[17:50:22.574] <TB3> INFO: 41600 events read in total (2891ms).
[17:50:22.575] <TB3> INFO: Test took 3762ms.
[17:50:22.863] <TB3> INFO: Expecting 41600 events.
[17:50:26.475] <TB3> INFO: 41600 events read in total (3020ms).
[17:50:26.476] <TB3> INFO: Test took 3877ms.
[17:50:26.778] <TB3> INFO: Expecting 41600 events.
[17:50:30.357] <TB3> INFO: 41600 events read in total (2988ms).
[17:50:30.358] <TB3> INFO: Test took 3853ms.
[17:50:30.647] <TB3> INFO: Expecting 41600 events.
[17:50:34.178] <TB3> INFO: 41600 events read in total (2940ms).
[17:50:34.178] <TB3> INFO: Test took 3797ms.
[17:50:34.468] <TB3> INFO: Expecting 41600 events.
[17:50:37.939] <TB3> INFO: 41600 events read in total (2880ms).
[17:50:37.940] <TB3> INFO: Test took 3737ms.
[17:50:38.229] <TB3> INFO: Expecting 41600 events.
[17:50:41.858] <TB3> INFO: 41600 events read in total (3037ms).
[17:50:41.859] <TB3> INFO: Test took 3894ms.
[17:50:42.148] <TB3> INFO: Expecting 41600 events.
[17:50:45.702] <TB3> INFO: 41600 events read in total (2962ms).
[17:50:45.703] <TB3> INFO: Test took 3820ms.
[17:50:45.991] <TB3> INFO: Expecting 41600 events.
[17:50:49.592] <TB3> INFO: 41600 events read in total (3009ms).
[17:50:49.593] <TB3> INFO: Test took 3866ms.
[17:50:49.881] <TB3> INFO: Expecting 41600 events.
[17:50:53.370] <TB3> INFO: 41600 events read in total (2897ms).
[17:50:53.371] <TB3> INFO: Test took 3755ms.
[17:50:53.664] <TB3> INFO: Expecting 41600 events.
[17:50:57.250] <TB3> INFO: 41600 events read in total (2995ms).
[17:50:57.251] <TB3> INFO: Test took 3853ms.
[17:50:57.540] <TB3> INFO: Expecting 41600 events.
[17:51:01.058] <TB3> INFO: 41600 events read in total (2927ms).
[17:51:01.059] <TB3> INFO: Test took 3784ms.
[17:51:01.348] <TB3> INFO: Expecting 41600 events.
[17:51:04.858] <TB3> INFO: 41600 events read in total (2918ms).
[17:51:04.860] <TB3> INFO: Test took 3776ms.
[17:51:05.162] <TB3> INFO: Expecting 41600 events.
[17:51:08.686] <TB3> INFO: 41600 events read in total (2932ms).
[17:51:08.687] <TB3> INFO: Test took 3803ms.
[17:51:08.976] <TB3> INFO: Expecting 41600 events.
[17:51:12.522] <TB3> INFO: 41600 events read in total (2955ms).
[17:51:12.523] <TB3> INFO: Test took 3812ms.
[17:51:12.812] <TB3> INFO: Expecting 41600 events.
[17:51:16.357] <TB3> INFO: 41600 events read in total (2953ms).
[17:51:16.358] <TB3> INFO: Test took 3811ms.
[17:51:16.649] <TB3> INFO: Expecting 41600 events.
[17:51:20.164] <TB3> INFO: 41600 events read in total (2923ms).
[17:51:20.164] <TB3> INFO: Test took 3780ms.
[17:51:20.465] <TB3> INFO: Expecting 41600 events.
[17:51:23.976] <TB3> INFO: 41600 events read in total (2919ms).
[17:51:23.977] <TB3> INFO: Test took 3789ms.
[17:51:24.266] <TB3> INFO: Expecting 41600 events.
[17:51:27.764] <TB3> INFO: 41600 events read in total (2906ms).
[17:51:27.765] <TB3> INFO: Test took 3764ms.
[17:51:28.080] <TB3> INFO: Expecting 41600 events.
[17:51:31.601] <TB3> INFO: 41600 events read in total (2930ms).
[17:51:31.602] <TB3> INFO: Test took 3810ms.
[17:51:31.890] <TB3> INFO: Expecting 41600 events.
[17:51:35.377] <TB3> INFO: 41600 events read in total (2895ms).
[17:51:35.378] <TB3> INFO: Test took 3752ms.
[17:51:35.667] <TB3> INFO: Expecting 41600 events.
[17:51:39.183] <TB3> INFO: 41600 events read in total (2924ms).
[17:51:39.184] <TB3> INFO: Test took 3782ms.
[17:51:39.474] <TB3> INFO: Expecting 41600 events.
[17:51:43.024] <TB3> INFO: 41600 events read in total (2959ms).
[17:51:43.024] <TB3> INFO: Test took 3815ms.
[17:51:43.313] <TB3> INFO: Expecting 41600 events.
[17:51:46.918] <TB3> INFO: 41600 events read in total (3013ms).
[17:51:46.919] <TB3> INFO: Test took 3870ms.
[17:51:47.212] <TB3> INFO: Expecting 41600 events.
[17:51:50.783] <TB3> INFO: 41600 events read in total (2980ms).
[17:51:50.784] <TB3> INFO: Test took 3837ms.
[17:51:51.074] <TB3> INFO: Expecting 2560 events.
[17:51:51.963] <TB3> INFO: 2560 events read in total (297ms).
[17:51:51.963] <TB3> INFO: Test took 1166ms.
[17:51:52.271] <TB3> INFO: Expecting 2560 events.
[17:51:53.158] <TB3> INFO: 2560 events read in total (295ms).
[17:51:53.159] <TB3> INFO: Test took 1195ms.
[17:51:53.467] <TB3> INFO: Expecting 2560 events.
[17:51:54.352] <TB3> INFO: 2560 events read in total (294ms).
[17:51:54.353] <TB3> INFO: Test took 1194ms.
[17:51:54.659] <TB3> INFO: Expecting 2560 events.
[17:51:55.544] <TB3> INFO: 2560 events read in total (293ms).
[17:51:55.544] <TB3> INFO: Test took 1190ms.
[17:51:55.852] <TB3> INFO: Expecting 2560 events.
[17:51:56.742] <TB3> INFO: 2560 events read in total (299ms).
[17:51:56.742] <TB3> INFO: Test took 1197ms.
[17:51:57.049] <TB3> INFO: Expecting 2560 events.
[17:51:57.929] <TB3> INFO: 2560 events read in total (288ms).
[17:51:57.929] <TB3> INFO: Test took 1186ms.
[17:51:58.236] <TB3> INFO: Expecting 2560 events.
[17:51:59.114] <TB3> INFO: 2560 events read in total (286ms).
[17:51:59.115] <TB3> INFO: Test took 1185ms.
[17:51:59.423] <TB3> INFO: Expecting 2560 events.
[17:52:00.307] <TB3> INFO: 2560 events read in total (292ms).
[17:52:00.308] <TB3> INFO: Test took 1193ms.
[17:52:00.615] <TB3> INFO: Expecting 2560 events.
[17:52:01.502] <TB3> INFO: 2560 events read in total (295ms).
[17:52:01.502] <TB3> INFO: Test took 1193ms.
[17:52:01.811] <TB3> INFO: Expecting 2560 events.
[17:52:02.692] <TB3> INFO: 2560 events read in total (289ms).
[17:52:02.692] <TB3> INFO: Test took 1189ms.
[17:52:02.000] <TB3> INFO: Expecting 2560 events.
[17:52:03.889] <TB3> INFO: 2560 events read in total (299ms).
[17:52:03.890] <TB3> INFO: Test took 1197ms.
[17:52:04.196] <TB3> INFO: Expecting 2560 events.
[17:52:05.080] <TB3> INFO: 2560 events read in total (292ms).
[17:52:05.081] <TB3> INFO: Test took 1190ms.
[17:52:05.387] <TB3> INFO: Expecting 2560 events.
[17:52:06.278] <TB3> INFO: 2560 events read in total (299ms).
[17:52:06.278] <TB3> INFO: Test took 1196ms.
[17:52:06.586] <TB3> INFO: Expecting 2560 events.
[17:52:07.471] <TB3> INFO: 2560 events read in total (293ms).
[17:52:07.471] <TB3> INFO: Test took 1193ms.
[17:52:07.778] <TB3> INFO: Expecting 2560 events.
[17:52:08.669] <TB3> INFO: 2560 events read in total (299ms).
[17:52:08.669] <TB3> INFO: Test took 1197ms.
[17:52:08.976] <TB3> INFO: Expecting 2560 events.
[17:52:09.860] <TB3> INFO: 2560 events read in total (292ms).
[17:52:09.861] <TB3> INFO: Test took 1191ms.
[17:52:09.865] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:52:10.169] <TB3> INFO: Expecting 655360 events.
[17:52:25.205] <TB3> INFO: 655360 events read in total (14444ms).
[17:52:25.216] <TB3> INFO: Expecting 655360 events.
[17:52:39.698] <TB3> INFO: 655360 events read in total (14079ms).
[17:52:39.714] <TB3> INFO: Expecting 655360 events.
[17:52:54.352] <TB3> INFO: 655360 events read in total (14235ms).
[17:52:54.378] <TB3> INFO: Expecting 655360 events.
[17:53:08.994] <TB3> INFO: 655360 events read in total (14213ms).
[17:53:09.026] <TB3> INFO: Expecting 655360 events.
[17:53:23.562] <TB3> INFO: 655360 events read in total (14133ms).
[17:53:23.600] <TB3> INFO: Expecting 655360 events.
[17:53:38.161] <TB3> INFO: 655360 events read in total (14158ms).
[17:53:38.195] <TB3> INFO: Expecting 655360 events.
[17:53:52.689] <TB3> INFO: 655360 events read in total (14091ms).
[17:53:52.726] <TB3> INFO: Expecting 655360 events.
[17:54:07.319] <TB3> INFO: 655360 events read in total (14190ms).
[17:54:07.361] <TB3> INFO: Expecting 655360 events.
[17:54:21.819] <TB3> INFO: 655360 events read in total (14055ms).
[17:54:21.866] <TB3> INFO: Expecting 655360 events.
[17:54:36.394] <TB3> INFO: 655360 events read in total (14125ms).
[17:54:36.445] <TB3> INFO: Expecting 655360 events.
[17:54:51.046] <TB3> INFO: 655360 events read in total (14198ms).
[17:54:51.128] <TB3> INFO: Expecting 655360 events.
[17:55:05.639] <TB3> INFO: 655360 events read in total (14108ms).
[17:55:05.713] <TB3> INFO: Expecting 655360 events.
[17:55:20.304] <TB3> INFO: 655360 events read in total (14188ms).
[17:55:20.457] <TB3> INFO: Expecting 655360 events.
[17:55:34.979] <TB3> INFO: 655360 events read in total (14120ms).
[17:55:35.063] <TB3> INFO: Expecting 655360 events.
[17:55:49.701] <TB3> INFO: 655360 events read in total (14235ms).
[17:55:49.827] <TB3> INFO: Expecting 655360 events.
[17:56:04.439] <TB3> INFO: 655360 events read in total (14209ms).
[17:56:04.587] <TB3> INFO: Test took 234722ms.
[17:56:04.684] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[17:56:04.941] <TB3> INFO: Expecting 655360 events.
[17:56:19.527] <TB3> INFO: 655360 events read in total (13994ms).
[17:56:19.539] <TB3> INFO: Expecting 655360 events.
[17:56:34.031] <TB3> INFO: 655360 events read in total (14089ms).
[17:56:34.049] <TB3> INFO: Expecting 655360 events.
[17:56:48.430] <TB3> INFO: 655360 events read in total (13978ms).
[17:56:48.451] <TB3> INFO: Expecting 655360 events.
[17:57:02.826] <TB3> INFO: 655360 events read in total (13972ms).
[17:57:02.850] <TB3> INFO: Expecting 655360 events.
[17:57:17.153] <TB3> INFO: 655360 events read in total (13899ms).
[17:57:17.183] <TB3> INFO: Expecting 655360 events.
[17:57:31.623] <TB3> INFO: 655360 events read in total (14036ms).
[17:57:31.662] <TB3> INFO: Expecting 655360 events.
[17:57:45.889] <TB3> INFO: 655360 events read in total (13824ms).
[17:57:45.925] <TB3> INFO: Expecting 655360 events.
[17:58:00.157] <TB3> INFO: 655360 events read in total (13828ms).
[17:58:00.201] <TB3> INFO: Expecting 655360 events.
[17:58:14.740] <TB3> INFO: 655360 events read in total (14136ms).
[17:58:14.786] <TB3> INFO: Expecting 655360 events.
[17:58:29.265] <TB3> INFO: 655360 events read in total (14075ms).
[17:58:29.314] <TB3> INFO: Expecting 655360 events.
[17:58:43.477] <TB3> INFO: 655360 events read in total (13760ms).
[17:58:43.544] <TB3> INFO: Expecting 655360 events.
[17:58:57.966] <TB3> INFO: 655360 events read in total (14019ms).
[17:58:58.043] <TB3> INFO: Expecting 655360 events.
[17:59:12.482] <TB3> INFO: 655360 events read in total (14035ms).
[17:59:12.561] <TB3> INFO: Expecting 655360 events.
[17:59:27.238] <TB3> INFO: 655360 events read in total (14274ms).
[17:59:27.414] <TB3> INFO: Expecting 655360 events.
[17:59:41.873] <TB3> INFO: 655360 events read in total (14056ms).
[17:59:41.964] <TB3> INFO: Expecting 655360 events.
[17:59:56.534] <TB3> INFO: 655360 events read in total (14166ms).
[17:59:56.638] <TB3> INFO: Test took 231954ms.
[17:59:56.813] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.819] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.824] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.830] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[17:59:56.836] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[17:59:56.842] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[17:59:56.847] <TB3> INFO: safety margin for low PH: adding 4, margin is now 24
[17:59:56.853] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.859] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[17:59:56.865] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.870] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.876] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.882] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[17:59:56.887] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[17:59:56.893] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[17:59:56.899] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.904] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.910] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.915] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.921] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[17:59:56.927] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[17:59:56.933] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.939] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[17:59:56.944] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.950] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[17:59:56.956] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.962] <TB3> INFO: safety margin for low PH: adding 1, margin is now 21
[17:59:56.968] <TB3> INFO: safety margin for low PH: adding 2, margin is now 22
[17:59:56.973] <TB3> INFO: safety margin for low PH: adding 3, margin is now 23
[17:59:56.979] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:56.985] <TB3> INFO: safety margin for low PH: adding 0, margin is now 20
[17:59:57.020] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C0.dat
[17:59:57.020] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C1.dat
[17:59:57.020] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C2.dat
[17:59:57.020] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C3.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C4.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C5.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C6.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C7.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C8.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C9.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C10.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C11.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C12.dat
[17:59:57.021] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C13.dat
[17:59:57.022] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C14.dat
[17:59:57.022] <TB3> INFO: write dac parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//dacParameters35_C15.dat
[17:59:57.265] <TB3> INFO: Expecting 41600 events.
[18:00:00.433] <TB3> INFO: 41600 events read in total (2576ms).
[18:00:00.434] <TB3> INFO: Test took 3409ms.
[18:00:00.906] <TB3> INFO: Expecting 41600 events.
[18:00:03.945] <TB3> INFO: 41600 events read in total (2447ms).
[18:00:03.946] <TB3> INFO: Test took 3298ms.
[18:00:04.402] <TB3> INFO: Expecting 41600 events.
[18:00:07.561] <TB3> INFO: 41600 events read in total (2567ms).
[18:00:07.562] <TB3> INFO: Test took 3405ms.
[18:00:07.785] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:07.874] <TB3> INFO: Expecting 2560 events.
[18:00:08.766] <TB3> INFO: 2560 events read in total (300ms).
[18:00:08.767] <TB3> INFO: Test took 982ms.
[18:00:08.771] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:09.075] <TB3> INFO: Expecting 2560 events.
[18:00:09.972] <TB3> INFO: 2560 events read in total (305ms).
[18:00:09.973] <TB3> INFO: Test took 1202ms.
[18:00:09.976] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:10.280] <TB3> INFO: Expecting 2560 events.
[18:00:11.163] <TB3> INFO: 2560 events read in total (291ms).
[18:00:11.164] <TB3> INFO: Test took 1188ms.
[18:00:11.166] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:11.472] <TB3> INFO: Expecting 2560 events.
[18:00:12.366] <TB3> INFO: 2560 events read in total (302ms).
[18:00:12.366] <TB3> INFO: Test took 1200ms.
[18:00:12.368] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:12.675] <TB3> INFO: Expecting 2560 events.
[18:00:13.562] <TB3> INFO: 2560 events read in total (295ms).
[18:00:13.562] <TB3> INFO: Test took 1194ms.
[18:00:13.564] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:13.871] <TB3> INFO: Expecting 2560 events.
[18:00:14.757] <TB3> INFO: 2560 events read in total (293ms).
[18:00:14.758] <TB3> INFO: Test took 1194ms.
[18:00:14.761] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:15.065] <TB3> INFO: Expecting 2560 events.
[18:00:15.956] <TB3> INFO: 2560 events read in total (299ms).
[18:00:15.956] <TB3> INFO: Test took 1195ms.
[18:00:15.959] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:16.263] <TB3> INFO: Expecting 2560 events.
[18:00:17.147] <TB3> INFO: 2560 events read in total (292ms).
[18:00:17.148] <TB3> INFO: Test took 1189ms.
[18:00:17.150] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:17.457] <TB3> INFO: Expecting 2560 events.
[18:00:18.345] <TB3> INFO: 2560 events read in total (296ms).
[18:00:18.346] <TB3> INFO: Test took 1196ms.
[18:00:18.350] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:18.653] <TB3> INFO: Expecting 2560 events.
[18:00:19.541] <TB3> INFO: 2560 events read in total (296ms).
[18:00:19.541] <TB3> INFO: Test took 1191ms.
[18:00:19.544] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:19.849] <TB3> INFO: Expecting 2560 events.
[18:00:20.728] <TB3> INFO: 2560 events read in total (287ms).
[18:00:20.728] <TB3> INFO: Test took 1184ms.
[18:00:20.731] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:21.038] <TB3> INFO: Expecting 2560 events.
[18:00:21.921] <TB3> INFO: 2560 events read in total (291ms).
[18:00:21.923] <TB3> INFO: Test took 1192ms.
[18:00:21.925] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:22.229] <TB3> INFO: Expecting 2560 events.
[18:00:23.121] <TB3> INFO: 2560 events read in total (300ms).
[18:00:23.121] <TB3> INFO: Test took 1196ms.
[18:00:23.124] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:23.429] <TB3> INFO: Expecting 2560 events.
[18:00:24.311] <TB3> INFO: 2560 events read in total (290ms).
[18:00:24.311] <TB3> INFO: Test took 1187ms.
[18:00:24.315] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:24.619] <TB3> INFO: Expecting 2560 events.
[18:00:25.506] <TB3> INFO: 2560 events read in total (295ms).
[18:00:25.507] <TB3> INFO: Test took 1193ms.
[18:00:25.510] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:25.815] <TB3> INFO: Expecting 2560 events.
[18:00:26.704] <TB3> INFO: 2560 events read in total (297ms).
[18:00:26.705] <TB3> INFO: Test took 1195ms.
[18:00:26.707] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:27.013] <TB3> INFO: Expecting 2560 events.
[18:00:27.904] <TB3> INFO: 2560 events read in total (299ms).
[18:00:27.904] <TB3> INFO: Test took 1197ms.
[18:00:27.907] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:28.212] <TB3> INFO: Expecting 2560 events.
[18:00:29.104] <TB3> INFO: 2560 events read in total (300ms).
[18:00:29.105] <TB3> INFO: Test took 1198ms.
[18:00:29.106] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:29.414] <TB3> INFO: Expecting 2560 events.
[18:00:30.306] <TB3> INFO: 2560 events read in total (300ms).
[18:00:30.306] <TB3> INFO: Test took 1200ms.
[18:00:30.310] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:30.613] <TB3> INFO: Expecting 2560 events.
[18:00:31.505] <TB3> INFO: 2560 events read in total (300ms).
[18:00:31.505] <TB3> INFO: Test took 1196ms.
[18:00:31.508] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:31.813] <TB3> INFO: Expecting 2560 events.
[18:00:32.694] <TB3> INFO: 2560 events read in total (289ms).
[18:00:32.695] <TB3> INFO: Test took 1187ms.
[18:00:32.697] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:33.003] <TB3> INFO: Expecting 2560 events.
[18:00:33.890] <TB3> INFO: 2560 events read in total (295ms).
[18:00:33.891] <TB3> INFO: Test took 1194ms.
[18:00:33.894] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:34.200] <TB3> INFO: Expecting 2560 events.
[18:00:35.081] <TB3> INFO: 2560 events read in total (290ms).
[18:00:35.081] <TB3> INFO: Test took 1187ms.
[18:00:35.084] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:35.390] <TB3> INFO: Expecting 2560 events.
[18:00:36.280] <TB3> INFO: 2560 events read in total (298ms).
[18:00:36.281] <TB3> INFO: Test took 1197ms.
[18:00:36.284] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:36.589] <TB3> INFO: Expecting 2560 events.
[18:00:37.474] <TB3> INFO: 2560 events read in total (294ms).
[18:00:37.474] <TB3> INFO: Test took 1190ms.
[18:00:37.477] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:37.782] <TB3> INFO: Expecting 2560 events.
[18:00:38.680] <TB3> INFO: 2560 events read in total (306ms).
[18:00:38.680] <TB3> INFO: Test took 1204ms.
[18:00:38.684] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:38.988] <TB3> INFO: Expecting 2560 events.
[18:00:39.881] <TB3> INFO: 2560 events read in total (301ms).
[18:00:39.882] <TB3> INFO: Test took 1198ms.
[18:00:39.885] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:40.190] <TB3> INFO: Expecting 2560 events.
[18:00:41.081] <TB3> INFO: 2560 events read in total (299ms).
[18:00:41.081] <TB3> INFO: Test took 1197ms.
[18:00:41.086] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:41.390] <TB3> INFO: Expecting 2560 events.
[18:00:42.275] <TB3> INFO: 2560 events read in total (293ms).
[18:00:42.276] <TB3> INFO: Test took 1191ms.
[18:00:42.279] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:42.584] <TB3> INFO: Expecting 2560 events.
[18:00:43.478] <TB3> INFO: 2560 events read in total (302ms).
[18:00:43.479] <TB3> INFO: Test took 1200ms.
[18:00:43.482] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:43.786] <TB3> INFO: Expecting 2560 events.
[18:00:44.678] <TB3> INFO: 2560 events read in total (300ms).
[18:00:44.679] <TB3> INFO: Test took 1197ms.
[18:00:44.681] <TB3> INFO: Not all ROCs have their pixels configured the same way. Running in FLAG_FORCE_SERIAL mode.
[18:00:44.987] <TB3> INFO: Expecting 2560 events.
[18:00:45.871] <TB3> INFO: 2560 events read in total (292ms).
[18:00:45.872] <TB3> INFO: Test took 1191ms.
[18:00:46.341] <TB3> INFO: PixTestPhOptimization::doTest() done, duration: 650 seconds
[18:00:46.341] <TB3> INFO: PH scale (per ROC): 51 44 64 40 36 35 48 42 52 57 37 48 56 37 32 36
[18:00:46.341] <TB3> INFO: PH offset (per ROC): 124 107 122 91 97 87 110 100 99 124 98 109 123 103 112 89
[18:00:46.348] <TB3> INFO: Decoding statistics:
[18:00:46.348] <TB3> INFO: General information:
[18:00:46.348] <TB3> INFO: 16bit words read: 127892
[18:00:46.348] <TB3> INFO: valid events total: 20480
[18:00:46.348] <TB3> INFO: empty events: 17974
[18:00:46.348] <TB3> INFO: valid events with pixels: 2506
[18:00:46.348] <TB3> INFO: valid pixel hits: 2506
[18:00:46.348] <TB3> INFO: Event errors: 0
[18:00:46.348] <TB3> INFO: start marker: 0
[18:00:46.348] <TB3> INFO: stop marker: 0
[18:00:46.348] <TB3> INFO: overflow: 0
[18:00:46.348] <TB3> INFO: invalid 5bit words: 0
[18:00:46.348] <TB3> INFO: invalid XOR eye diagram: 0
[18:00:46.348] <TB3> INFO: frame (failed synchr.): 0
[18:00:46.348] <TB3> INFO: idle data (no TBM trl): 0
[18:00:46.348] <TB3> INFO: no data (only TBM hdr): 0
[18:00:46.348] <TB3> INFO: TBM errors: 0
[18:00:46.348] <TB3> INFO: flawed TBM headers: 0
[18:00:46.348] <TB3> INFO: flawed TBM trailers: 0
[18:00:46.348] <TB3> INFO: event ID mismatches: 0
[18:00:46.348] <TB3> INFO: ROC errors: 0
[18:00:46.348] <TB3> INFO: missing ROC header(s): 0
[18:00:46.348] <TB3> INFO: misplaced readback start: 0
[18:00:46.348] <TB3> INFO: Pixel decoding errors: 0
[18:00:46.348] <TB3> INFO: pixel data incomplete: 0
[18:00:46.348] <TB3> INFO: pixel address: 0
[18:00:46.348] <TB3> INFO: pulse height fill bit: 0
[18:00:46.348] <TB3> INFO: buffer corruption: 0
[18:00:46.508] <TB3> INFO: ######################################################################
[18:00:46.508] <TB3> INFO: PixTestGainPedestal::fullTest() ntrig = 10
[18:00:46.508] <TB3> INFO: ######################################################################
[18:00:46.523] <TB3> INFO: scanning low vcal = 10
[18:00:46.758] <TB3> INFO: Expecting 41600 events.
[18:00:50.361] <TB3> INFO: 41600 events read in total (3011ms).
[18:00:50.361] <TB3> INFO: Test took 3838ms.
[18:00:50.363] <TB3> INFO: scanning low vcal = 20
[18:00:50.657] <TB3> INFO: Expecting 41600 events.
[18:00:54.299] <TB3> INFO: 41600 events read in total (3051ms).
[18:00:54.299] <TB3> INFO: Test took 3936ms.
[18:00:54.301] <TB3> INFO: scanning low vcal = 30
[18:00:54.593] <TB3> INFO: Expecting 41600 events.
[18:00:58.274] <TB3> INFO: 41600 events read in total (3089ms).
[18:00:58.275] <TB3> INFO: Test took 3974ms.
[18:00:58.278] <TB3> INFO: scanning low vcal = 40
[18:00:58.555] <TB3> INFO: Expecting 41600 events.
[18:01:02.580] <TB3> INFO: 41600 events read in total (3433ms).
[18:01:02.581] <TB3> INFO: Test took 4303ms.
[18:01:02.584] <TB3> INFO: scanning low vcal = 50
[18:01:02.860] <TB3> INFO: Expecting 41600 events.
[18:01:06.893] <TB3> INFO: 41600 events read in total (3441ms).
[18:01:06.893] <TB3> INFO: Test took 4309ms.
[18:01:06.897] <TB3> INFO: scanning low vcal = 60
[18:01:07.173] <TB3> INFO: Expecting 41600 events.
[18:01:11.178] <TB3> INFO: 41600 events read in total (3413ms).
[18:01:11.179] <TB3> INFO: Test took 4282ms.
[18:01:11.182] <TB3> INFO: scanning low vcal = 70
[18:01:11.460] <TB3> INFO: Expecting 41600 events.
[18:01:15.455] <TB3> INFO: 41600 events read in total (3404ms).
[18:01:15.456] <TB3> INFO: Test took 4274ms.
[18:01:15.459] <TB3> INFO: scanning low vcal = 80
[18:01:15.736] <TB3> INFO: Expecting 41600 events.
[18:01:19.724] <TB3> INFO: 41600 events read in total (3396ms).
[18:01:19.726] <TB3> INFO: Test took 4267ms.
[18:01:19.729] <TB3> INFO: scanning low vcal = 90
[18:01:20.006] <TB3> INFO: Expecting 41600 events.
[18:01:24.008] <TB3> INFO: 41600 events read in total (3410ms).
[18:01:24.008] <TB3> INFO: Test took 4279ms.
[18:01:24.012] <TB3> INFO: scanning low vcal = 100
[18:01:24.289] <TB3> INFO: Expecting 41600 events.
[18:01:28.306] <TB3> INFO: 41600 events read in total (3426ms).
[18:01:28.307] <TB3> INFO: Test took 4294ms.
[18:01:28.311] <TB3> INFO: scanning low vcal = 110
[18:01:28.588] <TB3> INFO: Expecting 41600 events.
[18:01:32.583] <TB3> INFO: 41600 events read in total (3403ms).
[18:01:32.583] <TB3> INFO: Test took 4272ms.
[18:01:32.586] <TB3> INFO: scanning low vcal = 120
[18:01:32.866] <TB3> INFO: Expecting 41600 events.
[18:01:36.886] <TB3> INFO: 41600 events read in total (3428ms).
[18:01:36.887] <TB3> INFO: Test took 4300ms.
[18:01:36.890] <TB3> INFO: scanning low vcal = 130
[18:01:37.167] <TB3> INFO: Expecting 41600 events.
[18:01:41.154] <TB3> INFO: 41600 events read in total (3395ms).
[18:01:41.155] <TB3> INFO: Test took 4265ms.
[18:01:41.158] <TB3> INFO: scanning low vcal = 140
[18:01:41.436] <TB3> INFO: Expecting 41600 events.
[18:01:45.494] <TB3> INFO: 41600 events read in total (3466ms).
[18:01:45.495] <TB3> INFO: Test took 4337ms.
[18:01:45.498] <TB3> INFO: scanning low vcal = 150
[18:01:45.779] <TB3> INFO: Expecting 41600 events.
[18:01:49.723] <TB3> INFO: 41600 events read in total (3353ms).
[18:01:49.724] <TB3> INFO: Test took 4226ms.
[18:01:49.728] <TB3> INFO: scanning low vcal = 160
[18:01:50.004] <TB3> INFO: Expecting 41600 events.
[18:01:53.968] <TB3> INFO: 41600 events read in total (3372ms).
[18:01:53.968] <TB3> INFO: Test took 4240ms.
[18:01:53.971] <TB3> INFO: scanning low vcal = 170
[18:01:54.248] <TB3> INFO: Expecting 41600 events.
[18:01:58.197] <TB3> INFO: 41600 events read in total (3357ms).
[18:01:58.197] <TB3> INFO: Test took 4225ms.
[18:01:58.202] <TB3> INFO: scanning low vcal = 180
[18:01:58.477] <TB3> INFO: Expecting 41600 events.
[18:02:02.440] <TB3> INFO: 41600 events read in total (3372ms).
[18:02:02.441] <TB3> INFO: Test took 4239ms.
[18:02:02.445] <TB3> INFO: scanning low vcal = 190
[18:02:02.721] <TB3> INFO: Expecting 41600 events.
[18:02:06.696] <TB3> INFO: 41600 events read in total (3383ms).
[18:02:06.697] <TB3> INFO: Test took 4252ms.
[18:02:06.700] <TB3> INFO: scanning low vcal = 200
[18:02:06.977] <TB3> INFO: Expecting 41600 events.
[18:02:10.954] <TB3> INFO: 41600 events read in total (3385ms).
[18:02:10.955] <TB3> INFO: Test took 4255ms.
[18:02:10.958] <TB3> INFO: scanning low vcal = 210
[18:02:11.235] <TB3> INFO: Expecting 41600 events.
[18:02:15.192] <TB3> INFO: 41600 events read in total (3366ms).
[18:02:15.193] <TB3> INFO: Test took 4235ms.
[18:02:15.196] <TB3> INFO: scanning low vcal = 220
[18:02:15.472] <TB3> INFO: Expecting 41600 events.
[18:02:19.405] <TB3> INFO: 41600 events read in total (3341ms).
[18:02:19.407] <TB3> INFO: Test took 4211ms.
[18:02:19.410] <TB3> INFO: scanning low vcal = 230
[18:02:19.686] <TB3> INFO: Expecting 41600 events.
[18:02:23.736] <TB3> INFO: 41600 events read in total (3458ms).
[18:02:23.736] <TB3> INFO: Test took 4326ms.
[18:02:23.739] <TB3> INFO: scanning low vcal = 240
[18:02:24.016] <TB3> INFO: Expecting 41600 events.
[18:02:28.043] <TB3> INFO: 41600 events read in total (3435ms).
[18:02:28.044] <TB3> INFO: Test took 4305ms.
[18:02:28.047] <TB3> INFO: scanning low vcal = 250
[18:02:28.324] <TB3> INFO: Expecting 41600 events.
[18:02:32.308] <TB3> INFO: 41600 events read in total (3392ms).
[18:02:32.308] <TB3> INFO: Test took 4261ms.
[18:02:32.312] <TB3> INFO: scanning high vcal = 30 (= 210 in low range)
[18:02:32.589] <TB3> INFO: Expecting 41600 events.
[18:02:36.590] <TB3> INFO: 41600 events read in total (3408ms).
[18:02:36.591] <TB3> INFO: Test took 4278ms.
[18:02:36.593] <TB3> INFO: scanning high vcal = 50 (= 350 in low range)
[18:02:36.870] <TB3> INFO: Expecting 41600 events.
[18:02:40.879] <TB3> INFO: 41600 events read in total (3417ms).
[18:02:40.880] <TB3> INFO: Test took 4286ms.
[18:02:40.883] <TB3> INFO: scanning high vcal = 70 (= 490 in low range)
[18:02:41.160] <TB3> INFO: Expecting 41600 events.
[18:02:45.218] <TB3> INFO: 41600 events read in total (3467ms).
[18:02:45.219] <TB3> INFO: Test took 4336ms.
[18:02:45.222] <TB3> INFO: scanning high vcal = 90 (= 630 in low range)
[18:02:45.520] <TB3> INFO: Expecting 41600 events.
[18:02:49.507] <TB3> INFO: 41600 events read in total (3395ms).
[18:02:49.508] <TB3> INFO: Test took 4286ms.
[18:02:49.511] <TB3> INFO: scanning high vcal = 200 (= 1400 in low range)
[18:02:49.788] <TB3> INFO: Expecting 41600 events.
[18:02:53.763] <TB3> INFO: 41600 events read in total (3383ms).
[18:02:53.764] <TB3> INFO: Test took 4253ms.
[18:02:54.181] <TB3> INFO: PixTestGainPedestal::measure() done
[18:03:27.707] <TB3> INFO: PixTestGainPedestal::fit() done
[18:03:27.707] <TB3> INFO: non-linearity mean: 0.980 0.918 0.988 0.928 0.941 0.953 0.976 0.938 0.961 0.983 0.903 0.968 0.979 0.932 0.927 0.875
[18:03:27.707] <TB3> INFO: non-linearity RMS: 0.003 0.117 0.002 0.123 0.174 0.180 0.008 0.057 0.029 0.004 0.131 0.009 0.006 0.121 0.182 0.169
[18:03:27.707] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C0.dat
[18:03:27.720] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C1.dat
[18:03:27.733] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C2.dat
[18:03:27.746] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C3.dat
[18:03:27.764] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C4.dat
[18:03:27.784] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C5.dat
[18:03:27.804] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C6.dat
[18:03:27.824] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C7.dat
[18:03:27.844] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C8.dat
[18:03:27.864] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C9.dat
[18:03:27.884] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C10.dat
[18:03:27.904] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C11.dat
[18:03:27.925] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C12.dat
[18:03:27.945] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C13.dat
[18:03:27.965] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C14.dat
[18:03:27.985] <TB3> INFO: write gain/ped parameters into /home/l_tester/david/FullQualification/data/M1018_FullQualification_2016-10-19_14h13m_1476879208//003_Fulltest_p17//phCalibrationFitErr35_C15.dat
[18:03:28.005] <TB3> INFO: PixTestGainPedestal::fullTest() done, duration: 161 seconds
[18:03:28.005] <TB3> INFO: Decoding statistics:
[18:03:28.005] <TB3> INFO: General information:
[18:03:28.005] <TB3> INFO: 16bit words read: 3310078
[18:03:28.005] <TB3> INFO: valid events total: 332800
[18:03:28.005] <TB3> INFO: empty events: 299
[18:03:28.005] <TB3> INFO: valid events with pixels: 332501
[18:03:28.005] <TB3> INFO: valid pixel hits: 656639
[18:03:28.005] <TB3> INFO: Event errors: 0
[18:03:28.005] <TB3> INFO: start marker: 0
[18:03:28.005] <TB3> INFO: stop marker: 0
[18:03:28.005] <TB3> INFO: overflow: 0
[18:03:28.005] <TB3> INFO: invalid 5bit words: 0
[18:03:28.005] <TB3> INFO: invalid XOR eye diagram: 0
[18:03:28.005] <TB3> INFO: frame (failed synchr.): 0
[18:03:28.005] <TB3> INFO: idle data (no TBM trl): 0
[18:03:28.005] <TB3> INFO: no data (only TBM hdr): 0
[18:03:28.005] <TB3> INFO: TBM errors: 0
[18:03:28.005] <TB3> INFO: flawed TBM headers: 0
[18:03:28.005] <TB3> INFO: flawed TBM trailers: 0
[18:03:28.005] <TB3> INFO: event ID mismatches: 0
[18:03:28.005] <TB3> INFO: ROC errors: 0
[18:03:28.005] <TB3> INFO: missing ROC header(s): 0
[18:03:28.005] <TB3> INFO: misplaced readback start: 0
[18:03:28.005] <TB3> INFO: Pixel decoding errors: 0
[18:03:28.005] <TB3> INFO: pixel data incomplete: 0
[18:03:28.005] <TB3> INFO: pixel address: 0
[18:03:28.005] <TB3> INFO: pulse height fill bit: 0
[18:03:28.005] <TB3> INFO: buffer corruption: 0
[18:03:28.026] <TB3> INFO: Decoding statistics:
[18:03:28.026] <TB3> INFO: General information:
[18:03:28.027] <TB3> INFO: 16bit words read: 3439528
[18:03:28.027] <TB3> INFO: valid events total: 353536
[18:03:28.027] <TB3> INFO: empty events: 18518
[18:03:28.027] <TB3> INFO: valid events with pixels: 335018
[18:03:28.027] <TB3> INFO: valid pixel hits: 659156
[18:03:28.027] <TB3> INFO: Event errors: 0
[18:03:28.027] <TB3> INFO: start marker: 0
[18:03:28.027] <TB3> INFO: stop marker: 0
[18:03:28.027] <TB3> INFO: overflow: 0
[18:03:28.027] <TB3> INFO: invalid 5bit words: 0
[18:03:28.027] <TB3> INFO: invalid XOR eye diagram: 0
[18:03:28.027] <TB3> INFO: frame (failed synchr.): 0
[18:03:28.027] <TB3> INFO: idle data (no TBM trl): 0
[18:03:28.027] <TB3> INFO: no data (only TBM hdr): 0
[18:03:28.027] <TB3> INFO: TBM errors: 0
[18:03:28.027] <TB3> INFO: flawed TBM headers: 0
[18:03:28.027] <TB3> INFO: flawed TBM trailers: 0
[18:03:28.027] <TB3> INFO: event ID mismatches: 0
[18:03:28.027] <TB3> INFO: ROC errors: 0
[18:03:28.027] <TB3> INFO: missing ROC header(s): 0
[18:03:28.027] <TB3> INFO: misplaced readback start: 0
[18:03:28.027] <TB3> INFO: Pixel decoding errors: 0
[18:03:28.027] <TB3> INFO: pixel data incomplete: 0
[18:03:28.027] <TB3> INFO: pixel address: 0
[18:03:28.027] <TB3> INFO: pulse height fill bit: 0
[18:03:28.027] <TB3> INFO: buffer corruption: 0
[18:03:28.027] <TB3> INFO: enter test to run
[18:03:28.027] <TB3> INFO: test: exit no parameter change
[18:03:28.168] <TB3> QUIET: Connection to board 126 closed.
[18:03:28.169] <TB3> INFO: pXar: this is the end, my friend