Test Date: 2016-09-28 13:59
Analysis date: 2016-09-30 15:33
Logfile
hrData_40.log
[13:51:01.763] INFO: *** Welcome to pxar ***
[13:51:01.763] INFO: *** Today: 2016/09/30
[13:51:03.486] INFO: *** Version: v1.9.0-818-g96727
[13:51:03.486] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//dacParameters35_C15.dat
[13:51:03.661] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:51:03.661] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//defaultMaskFile.dat
[13:51:03.666] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C15.dat
[13:51:03.895] INFO: clk: 4
[13:51:03.895] INFO: ctr: 4
[13:51:03.895] INFO: sda: 19
[13:51:03.895] INFO: tin: 9
[13:51:03.895] INFO: level: 15
[13:51:03.895] INFO: triggerdelay: 0
[13:51:03.895] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:51:03.895] INFO: Log level: INFO
[13:51:03.929] QUIET: Connection to board DTB_WREKRL opened.
[13:51:03.933] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[13:51:03.935] INFO: RPC call hashes of host and DTB match: 398089610
[13:51:05.481] INFO: DUT info:
[13:51:05.481] INFO: The DUT currently contains the following objects:
[13:51:05.481] INFO: 2 TBM Cores tbm08c (2 ON)
[13:51:05.495] INFO: TBM Core alpha (0): 7 registers set
[13:51:05.495] INFO: TBM Core beta (1): 7 registers set
[13:51:05.495] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:51:05.495] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.495] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.495] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.495] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.496] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:51:05.948] INFO: enter 'restricted' command line mode
[13:51:05.948] INFO: enter test to run
[13:51:16.507] INFO: test: PixelAlive no parameter change
[13:51:16.507] INFO: running: pixelalive
[13:51:16.545] INFO: ----------------------------------------------------------------------
[13:51:16.545] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:51:16.545] INFO: ----------------------------------------------------------------------
[13:51:16.869] INFO: Expecting 41600 events.
[13:51:21.337] INFO: 41600 events read in total (3750ms).
[13:51:21.503] INFO: Test took 4955ms.
[13:51:21.511] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:21.783] INFO: PixTestAlive::aliveTest() done
[13:51:21.783] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 1
[13:51:21.815] INFO: enter test to run
[13:51:30.139] INFO: test: timing no parameter change
[13:51:30.140] INFO: running: timing
[13:51:30.143] INFO: ######################################################################
[13:51:30.143] INFO: PixTestTiming::doTest()
[13:51:30.143] INFO: ######################################################################
[13:51:30.143] INFO: ----------------------------------------------------------------------
[13:51:30.143] INFO: PixTestTiming::TBMPhaseScan()
[13:51:30.143] INFO: ----------------------------------------------------------------------
[13:55:59.388] INFO: TBM Phase Settings: 236
[13:55:59.388] INFO: 400MHz Phase: 3
[13:55:59.388] INFO: 160MHz Phase: 7
[13:55:59.388] INFO: Functional Phase Area: 5
[13:55:59.399] INFO: Test took 269256 ms.
[13:55:59.399] INFO: PixTestTiming::TBMPhaseScan() done.
[13:55:59.399] INFO: ----------------------------------------------------------------------
[13:55:59.399] INFO: PixTestTiming::ROCDelayScan()
[13:55:59.399] INFO: ----------------------------------------------------------------------
[13:57:51.308] INFO: ROC Delay Settings: 228
[13:57:51.308] INFO: ROC Header-Trailer/Token Delay: 11
[13:57:51.308] INFO: ROC Port 0 Delay: 4
[13:57:51.308] INFO: ROC Port 1 Delay: 4
[13:57:51.308] INFO: Functional ROC Area: 3
[13:57:51.311] INFO: Test took 111912 ms.
[13:57:51.311] INFO: PixTestTiming::ROCDelayScan() done.
[13:57:51.311] INFO: ----------------------------------------------------------------------
[13:57:51.311] INFO: PixTestTiming::TimingTest()
[13:57:51.311] INFO: ----------------------------------------------------------------------
[13:58:07.440] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:22.375] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:37.342] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:52.307] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:07.290] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:22.246] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:37.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:52.171] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:07.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:22.137] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:22.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:00:22.536] INFO: ----------------------------------------------------------------------
[14:00:22.536] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[14:00:22.536] INFO: ----------------------------------------------------------------------
[14:00:22.536] INFO: ----------------------------------------------------------------------
[14:00:22.536] INFO: Read back bit status: 1
[14:00:22.536] INFO: ----------------------------------------------------------------------
[14:00:22.536] INFO: ----------------------------------------------------------------------
[14:00:22.536] INFO: Timings are good!
[14:00:22.536] INFO: ----------------------------------------------------------------------
[14:00:22.536] INFO: Test took 151225 ms.
[14:00:22.536] INFO: PixTestTiming::TimingTest() done.
[14:00:22.536] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0a.dat
[14:00:22.536] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:00:22.536] INFO: PixTestTiming::doTest took 532396 ms.
[14:00:22.536] INFO: PixTestTiming::doTest() done
[14:00:22.536] INFO: Write out TBMPhaseScan_0_V0
[14:00:22.536] INFO: Write out TBMPhaseScan_1_V0
[14:00:22.536] INFO: Write out CombinedTBMPhaseScan_V0
[14:00:22.545] INFO: Write out ROCDelayScan3_V0
[14:00:22.546] INFO: enter test to run
[14:01:24.280] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:01:24.280] INFO: running: highrate
[14:01:24.297] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:01:24.632] INFO: ----------------------------------------------------------------------
[14:01:24.632] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:01:24.632] INFO: ----------------------------------------------------------------------
[14:01:24.632] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:01:24.632] INFO: edge/corner pixel THR is adjusted
[14:01:24.632] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:01:25.608] INFO: Collecting data for 5 seconds...
[14:01:30.628] INFO: Done with hot pixel readout
[14:01:42.955] INFO: PixTest:: pg_setup set to default.
[14:01:42.956] INFO: 45 hot pixels found in step 0
[14:01:43.951] INFO: Collecting data for 5 seconds...
[14:01:48.971] INFO: Done with hot pixel readout
[14:02:01.030] INFO: PixTest:: pg_setup set to default.
[14:02:01.031] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:02:01.031] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:02:01.031] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:02:01.031] INFO: 41 hot pixels found in step 1
[14:02:02.026] INFO: Collecting data for 5 seconds...
[14:02:07.044] INFO: Done with hot pixel readout
[14:02:19.276] INFO: PixTest:: pg_setup set to default.
[14:02:19.276] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:02:19.277] INFO: 48 hot pixels found in step 2
[14:02:20.272] INFO: Collecting data for 5 seconds...
[14:02:25.291] INFO: Done with hot pixel readout
[14:02:37.266] INFO: PixTest:: pg_setup set to default.
[14:02:37.267] INFO: 37 hot pixels found in step 3
[14:02:38.262] INFO: Collecting data for 5 seconds...
[14:02:43.280] INFO: Done with hot pixel readout
[14:02:55.407] INFO: PixTest:: pg_setup set to default.
[14:02:55.407] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:02:55.407] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:02:55.408] INFO: 44 hot pixels found in step 4
[14:02:56.402] INFO: Collecting data for 5 seconds...
[14:03:01.420] INFO: Done with hot pixel readout
[14:03:13.575] INFO: PixTest:: pg_setup set to default.
[14:03:13.575] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:03:13.577] INFO: 26 hot pixels found in step 5
[14:03:14.576] INFO: Collecting data for 5 seconds...
[14:03:19.595] INFO: Done with hot pixel readout
[14:03:31.680] INFO: PixTest:: pg_setup set to default.
[14:03:31.681] INFO: 26 hot pixels found in step 6
[14:03:32.676] INFO: Collecting data for 5 seconds...
[14:03:37.694] INFO: Done with hot pixel readout
[14:03:49.912] INFO: PixTest:: pg_setup set to default.
[14:03:49.913] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:03:49.913] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:03:49.913] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:03:49.913] INFO: 28 hot pixels found in step 7
[14:03:50.907] INFO: Collecting data for 5 seconds...
[14:03:55.926] INFO: Done with hot pixel readout
[14:04:07.961] INFO: PixTest:: pg_setup set to default.
[14:04:07.962] INFO: 20 hot pixels found in step 8
[14:04:08.957] INFO: Collecting data for 5 seconds...
[14:04:13.975] INFO: Done with hot pixel readout
[14:04:25.780] INFO: PixTest:: pg_setup set to default.
[14:04:25.780] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:04:25.780] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:04:25.780] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:04:25.781] INFO: 25 hot pixels found in step 9
[14:04:26.776] INFO: Collecting data for 5 seconds...
[14:04:31.795] INFO: Done with hot pixel readout
[14:04:43.332] INFO: PixTest:: pg_setup set to default.
[14:04:43.332] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:04:43.333] INFO: 20 hot pixels found in step 10
[14:04:44.327] INFO: Collecting data for 5 seconds...
[14:04:49.346] INFO: Done with hot pixel readout
[14:05:01.586] INFO: PixTest:: pg_setup set to default.
[14:05:01.587] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:05:01.587] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:05:01.587] INFO: 20 hot pixels found in step 11
[14:05:02.581] INFO: Collecting data for 5 seconds...
[14:05:07.600] INFO: Done with hot pixel readout
[14:05:20.103] INFO: PixTest:: pg_setup set to default.
[14:05:20.103] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:05:20.104] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:05:20.104] INFO: 21 hot pixels found in step 12
[14:05:21.099] INFO: Collecting data for 5 seconds...
[14:05:26.117] INFO: Done with hot pixel readout
[14:05:38.354] INFO: PixTest:: pg_setup set to default.
[14:05:38.354] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:05:38.355] INFO: 15 hot pixels found in step 13
[14:05:39.349] INFO: Collecting data for 5 seconds...
[14:05:44.370] INFO: Done with hot pixel readout
[14:05:56.649] INFO: PixTest:: pg_setup set to default.
[14:05:56.650] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:05:56.650] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:05:56.650] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found

[14:05:56.650] INFO: 26 hot pixels found in step 14
[14:05:56.690] INFO: 26 hot pixels could not be trimmed and have been masked.
[14:05:56.693] INFO: PixTest::trimHotPixels() done
[14:05:56.693] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C0.dat
[14:05:56.699] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C1.dat
[14:05:56.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C2.dat
[14:05:56.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C3.dat
[14:05:56.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C4.dat
[14:05:56.723] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C5.dat
[14:05:56.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C6.dat
[14:05:56.734] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C7.dat
[14:05:56.739] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C8.dat
[14:05:56.745] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C9.dat
[14:05:56.750] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C10.dat
[14:05:56.755] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C11.dat
[14:05:56.761] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C12.dat
[14:05:56.766] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C13.dat
[14:05:56.772] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C14.dat
[14:05:56.777] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//trimParameters35_C15.dat
[14:05:56.782] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-2-26_FPIXTest-17C-FNAL-160928-1256-150V_2016-09-28_12h56m_1475085375/000_FPIXTest_p17//defaultMaskFile.dat
[14:05:56.793] INFO: enter test to run
[14:06:19.053] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:06:19.054] INFO: running: xray
[14:06:19.055] INFO: ----------------------------------------------------------------------
[14:06:19.055] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:06:19.055] INFO: ----------------------------------------------------------------------
[14:06:20.018] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:06:31.108] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:07:01.201] INFO: Resuming triggers.
[14:07:12.291] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:07:41.823] INFO: Resuming triggers.
[14:07:52.910] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:08:22.314] INFO: Resuming triggers.
[14:08:33.404] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:09:02.787] INFO: Resuming triggers.
[14:09:13.876] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:09:43.328] INFO: Resuming triggers.
[14:09:54.419] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:10:23.934] INFO: Resuming triggers.
[14:10:35.023] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:11:04.574] INFO: Resuming triggers.
[14:11:15.667] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[14:11:45.145] INFO: Resuming triggers.
[14:11:56.238] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:12:25.724] INFO: Resuming triggers.
[14:12:26.243] INFO: data taking finished, elapsed time: 100 seconds.
[14:12:27.997] INFO: PixTest:: pg_setup set to default.
[14:12:27.000] INFO: PixTestXray::doPhRun() done
[14:12:28.152] INFO: enter test to run
[14:12:50.667] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:12:50.667] INFO: running: xray
[14:12:50.669] INFO: ----------------------------------------------------------------------
[14:12:50.669] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:12:50.669] INFO: ----------------------------------------------------------------------
[14:12:51.652] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:12:58.424] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:13:28.783] INFO: Resuming triggers.
[14:13:35.563] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:14:05.743] INFO: Resuming triggers.
[14:14:12.524] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:14:42.972] INFO: Resuming triggers.
[14:14:49.749] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:15:20.664] INFO: Resuming triggers.
[14:15:27.447] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:15:58.519] INFO: Resuming triggers.
[14:16:05.300] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[14:16:36.220] INFO: Resuming triggers.
[14:16:42.003] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:17:13.959] INFO: Resuming triggers.
[14:17:20.740] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:17:51.030] INFO: Resuming triggers.
[14:17:57.803] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[14:18:29.247] INFO: Resuming triggers.
[14:18:36.027] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:19:07.855] INFO: Resuming triggers.
[14:19:14.633] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:19:45.859] INFO: Resuming triggers.
[14:19:52.630] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:20:22.845] INFO: Resuming triggers.
[14:20:29.621] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[14:20:59.763] INFO: Resuming triggers.
[14:21:06.536] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:21:36.613] INFO: Resuming triggers.
[14:21:42.075] INFO: data taking finished, elapsed time: 100 seconds.
[14:22:06.710] INFO: PixTest:: pg_setup set to default.
[14:22:06.713] INFO: PixTestXray::doPhRun() done
[14:22:06.861] INFO: enter test to run
[14:22:34.223] INFO: test: HighRate no parameter change
[14:22:34.223] INFO: running: highrate
[14:22:34.244] INFO: ----------------------------------------------------------------------
[14:22:34.244] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:22:34.245] INFO: ----------------------------------------------------------------------
[14:22:34.400] INFO: Expecting 768 events.
[14:22:35.533] INFO: 768 events read in total (418ms).
[14:22:35.534] INFO: Test took 1269ms.
[14:22:36.337] INFO: Expecting 41600 events.
[14:22:39.455] INFO: 41600 events read in total (2591ms).
[14:22:39.456] INFO: Test took 3915ms.
[14:22:39.497] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:40.217] INFO: Expecting 41600 events.
[14:22:43.426] INFO: 41600 events read in total (2682ms).
[14:22:43.427] INFO: Test took 3913ms.
[14:22:43.461] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:44.183] INFO: Expecting 41600 events.
[14:22:47.373] INFO: 41600 events read in total (2663ms).
[14:22:47.374] INFO: Test took 3895ms.
[14:22:47.408] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:48.130] INFO: Expecting 41600 events.
[14:22:51.349] INFO: 41600 events read in total (2692ms).
[14:22:51.349] INFO: Test took 3924ms.
[14:22:51.383] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:52.110] INFO: Expecting 41600 events.
[14:22:55.334] INFO: 41600 events read in total (2697ms).
[14:22:55.335] INFO: Test took 3935ms.
[14:22:55.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:56.096] INFO: Expecting 41600 events.
[14:22:59.329] INFO: 41600 events read in total (2707ms).
[14:22:59.330] INFO: Test took 3943ms.
[14:22:59.364] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:00.090] INFO: Expecting 41600 events.
[14:23:03.324] INFO: 41600 events read in total (2707ms).
[14:23:03.325] INFO: Test took 3943ms.
[14:23:03.358] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:04.085] INFO: Expecting 41600 events.
[14:23:07.318] INFO: 41600 events read in total (2707ms).
[14:23:07.319] INFO: Test took 3943ms.
[14:23:07.352] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:08.076] INFO: Expecting 41600 events.
[14:23:11.330] INFO: 41600 events read in total (2727ms).
[14:23:11.331] INFO: Test took 3960ms.
[14:23:11.364] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:12.091] INFO: Expecting 41600 events.
[14:23:15.311] INFO: 41600 events read in total (2693ms).
[14:23:15.312] INFO: Test took 3930ms.
[14:23:15.346] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:16.069] INFO: Expecting 41600 events.
[14:23:19.305] INFO: 41600 events read in total (2710ms).
[14:23:19.307] INFO: Test took 3944ms.
[14:23:19.341] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:20.062] INFO: Expecting 41600 events.
[14:23:23.302] INFO: 41600 events read in total (2713ms).
[14:23:23.303] INFO: Test took 3943ms.
[14:23:23.337] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:24.061] INFO: Expecting 41600 events.
[14:23:27.300] INFO: 41600 events read in total (2713ms).
[14:23:27.301] INFO: Test took 3946ms.
[14:23:27.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:28.058] INFO: Expecting 41600 events.
[14:23:31.286] INFO: 41600 events read in total (2701ms).
[14:23:31.287] INFO: Test took 3936ms.
[14:23:31.320] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:32.047] INFO: Expecting 41600 events.
[14:23:35.278] INFO: 41600 events read in total (2705ms).
[14:23:35.279] INFO: Test took 3941ms.
[14:23:35.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:36.036] INFO: Expecting 41600 events.
[14:23:39.277] INFO: 41600 events read in total (2714ms).
[14:23:39.278] INFO: Test took 3946ms.
[14:23:39.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:40.038] INFO: Expecting 41600 events.
[14:23:43.281] INFO: 41600 events read in total (2716ms).
[14:23:43.282] INFO: Test took 3951ms.
[14:23:43.316] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:44.037] INFO: Expecting 41600 events.
[14:23:47.277] INFO: 41600 events read in total (2713ms).
[14:23:47.278] INFO: Test took 3945ms.
[14:23:47.312] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:48.033] INFO: Expecting 41600 events.
[14:23:51.262] INFO: 41600 events read in total (2702ms).
[14:23:51.263] INFO: Test took 3932ms.
[14:23:51.296] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:52.021] INFO: Expecting 41600 events.
[14:23:55.113] INFO: 41600 events read in total (2565ms).
[14:23:55.114] INFO: Test took 3799ms.
[14:23:55.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:55.512] INFO: enter test to run
[14:24:18.950] INFO: test: HighRate no parameter change
[14:24:18.950] INFO: running: highrate
[14:24:18.951] INFO: ----------------------------------------------------------------------
[14:24:18.952] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:24:18.952] INFO: ----------------------------------------------------------------------
[14:24:19.569] INFO: Expecting 208000 events.
[14:24:31.423] INFO: 208000 events read in total (11327ms).
[14:24:31.426] INFO: Test took 12465ms.
[14:24:31.566] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:31.820] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 1
[14:24:31.820] INFO: number of red-efficiency pixels: 78 34 71 137 113 121 134 105 96 139 114 104 108 53 24 29
[14:24:31.820] INFO: number of X-ray hits detected: 61274 40050 64424 100492 108476 106837 106256 82222 82808 105933 97226 80571 82353 48334 19637 26438
[14:24:31.820] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:24:31.820] INFO: number of Vcal hits detected: 207921 207966 207926 207860 207886 207873 207859 207892 207903 207860 207884 207894 207887 207898 207970 207922
[14:24:31.820] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:24:31.820] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[14:24:31.820] INFO: X-ray hit rate [MHz/cm2]: 18.0 11.7 18.9 29.5 31.8 31.3 31.1 24.1 24.3 31.0 28.5 23.6 24.1 14.2 5.8 7.7
[14:24:31.820] INFO: PixTestHighRate::doXPixelAlive() done
[14:24:31.866] INFO: PixTest:: pg_setup set to default.
[14:24:31.878] INFO: enter test to run
[14:24:45.534] INFO: test: HighRate no parameter change
[14:24:45.534] INFO: running: highrate
[14:24:45.536] INFO: ----------------------------------------------------------------------
[14:24:45.536] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:24:45.536] INFO: ----------------------------------------------------------------------
[14:24:46.149] INFO: Expecting 208000 events.
[14:24:59.668] INFO: 208000 events read in total (12992ms).
[14:24:59.673] INFO: Test took 14129ms.
[14:24:59.957] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:00.255] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 1
[14:25:00.255] INFO: number of red-efficiency pixels: 219 105 219 438 384 403 468 343 276 422 326 312 308 162 36 58
[14:25:00.255] INFO: number of X-ray hits detected: 126850 83930 134098 207207 223612 220858 220099 171067 171754 219591 200190 166022 170262 100579 41771 55029
[14:25:00.255] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:25:00.255] INFO: number of Vcal hits detected: 207766 207889 207759 207530 207589 207566 207488 207629 207710 207549 207658 207668 207677 207780 207963 207893
[14:25:00.255] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:25:00.255] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 99.9
[14:25:00.255] INFO: X-ray hit rate [MHz/cm2]: 37.2 24.6 39.3 60.7 65.5 64.7 64.5 50.1 50.3 64.4 58.7 48.7 49.9 29.5 12.2 16.1
[14:25:00.255] INFO: PixTestHighRate::doXPixelAlive() done
[14:25:00.301] INFO: PixTest:: pg_setup set to default.
[14:25:00.317] INFO: enter test to run
[14:25:13.606] INFO: test: HighRate no parameter change
[14:25:13.606] INFO: running: highrate
[14:25:13.607] INFO: ----------------------------------------------------------------------
[14:25:13.607] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:25:13.607] INFO: ----------------------------------------------------------------------
[14:25:14.222] INFO: Expecting 208000 events.
[14:25:29.664] INFO: 208000 events read in total (14915ms).
[14:25:29.671] INFO: Test took 16053ms.
[14:25:30.097] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:25:30.445] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 1
[14:25:30.445] INFO: number of red-efficiency pixels: 489 209 510 1139 955 907 1257 837 576 941 712 744 800 309 90 103
[14:25:30.445] INFO: number of X-ray hits detected: 196454 130257 207053 322975 347262 342476 341810 266174 267635 341036 311367 259175 265481 156285 64974 86288
[14:25:30.445] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:25:30.445] INFO: number of Vcal hits detected: 207417 207778 207352 206552 206825 206860 206334 206981 207344 206845 207188 207135 207069 207611 207907 207845
[14:25:30.445] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.4 99.5 99.5 99.3 99.5 99.7 99.5 99.6 99.6 99.6 99.9 100.0 100.0
[14:25:30.445] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.3 99.4 99.5 99.2 99.5 99.7 99.4 99.6 99.6 99.6 99.8 100.0 99.9
[14:25:30.445] INFO: X-ray hit rate [MHz/cm2]: 57.6 38.2 60.7 94.7 101.8 100.4 100.2 78.0 78.4 100.0 91.3 76.0 77.8 45.8 19.0 25.3
[14:25:30.445] INFO: PixTestHighRate::doXPixelAlive() done
[14:25:30.492] INFO: PixTest:: pg_setup set to default.
[14:25:30.509] INFO: enter test to run
[14:25:37.062] INFO: test: exit no parameter change
[14:25:37.620] QUIET: Connection to board 33 closed.
[14:25:37.632] INFO: pXar: this is the end, my friend
MoReWeb-v0.5.1-904-gd94b9f2 on branch master