[15:22:33.032] INFO: *** Welcome to pxar ***
[15:22:33.032] INFO: *** Today: 2016/05/03
[15:22:33.047] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:22:33.047] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//dacParameters35_C15.dat
[15:22:33.048] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:22:33.048] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//defaultMaskFile.dat
[15:22:33.048] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C15.dat
[15:22:33.118] INFO: clk: 4
[15:22:33.118] INFO: ctr: 4
[15:22:33.118] INFO: sda: 19
[15:22:33.118] INFO: tin: 9
[15:22:33.118] INFO: level: 15
[15:22:33.118] INFO: triggerdelay: 0
[15:22:33.118] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:22:33.118] INFO: Log level: INFO
[15:22:33.136] QUIET: Connection to board DTB_WREK4U opened.
[15:22:33.139] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[15:22:33.142] INFO: RPC call hashes of host and DTB match: 398089610
[15:22:34.672] INFO: DUT info:
[15:22:34.672] INFO: The DUT currently contains the following objects:
[15:22:34.672] INFO: 2 TBM Cores tbm08c (2 ON)
[15:22:34.672] INFO: TBM Core alpha (0): 7 registers set
[15:22:34.672] INFO: TBM Core beta (1): 7 registers set
[15:22:34.672] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:22:34.672] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:34.672] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:22:35.075] INFO: enter 'restricted' command line mode
[15:22:35.076] INFO: enter test to run
[15:22:46.437] INFO: test: timing no parameter change
[15:22:46.437] INFO: running: timing
[15:22:46.446] INFO: ######################################################################
[15:22:46.446] INFO: PixTestTiming::doTest()
[15:22:46.446] INFO: ######################################################################
[15:22:46.446] INFO: ----------------------------------------------------------------------
[15:22:46.446] INFO: PixTestTiming::TBMPhaseScan()
[15:22:46.446] INFO: ----------------------------------------------------------------------
[15:29:22.089] INFO: TBM Phase Settings: 200
[15:29:22.089] INFO: 400MHz Phase: 2
[15:29:22.089] INFO: 160MHz Phase: 6
[15:29:22.089] INFO: Functional Phase Area: 3
[15:29:22.092] INFO: Test took 395646 ms.
[15:29:22.092] INFO: PixTestTiming::TBMPhaseScan() done.
[15:29:22.092] INFO: ----------------------------------------------------------------------
[15:29:22.092] INFO: PixTestTiming::ROCDelayScan()
[15:29:22.092] INFO: ----------------------------------------------------------------------
[15:31:22.090] INFO: ROC Delay Settings: 219
[15:31:22.090] INFO: ROC Header-Trailer/Token Delay: 11
[15:31:22.090] INFO: ROC Port 0 Delay: 3
[15:31:22.090] INFO: ROC Port 1 Delay: 3
[15:31:22.090] INFO: Functional ROC Area: 4
[15:31:22.094] INFO: Test took 120002 ms.
[15:31:22.094] INFO: PixTestTiming::ROCDelayScan() done.
[15:31:22.094] INFO: ----------------------------------------------------------------------
[15:31:22.094] INFO: PixTestTiming::TimingTest()
[15:31:22.094] INFO: ----------------------------------------------------------------------
[15:31:38.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:53.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:08.072] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:23.017] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:37.954] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:52.897] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:07.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:22.729] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:37.668] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:52.582] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:52.960] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:52.979] INFO: ----------------------------------------------------------------------
[15:33:52.979] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[15:33:52.979] INFO: ----------------------------------------------------------------------
[15:33:52.979] INFO: ----------------------------------------------------------------------
[15:33:52.979] INFO: Read back bit status: 1
[15:33:52.979] INFO: ----------------------------------------------------------------------
[15:33:52.979] INFO: ----------------------------------------------------------------------
[15:33:52.979] INFO: Timings are good!
[15:33:52.979] INFO: ----------------------------------------------------------------------
[15:33:52.979] INFO: Test took 150885 ms.
[15:33:52.979] INFO: PixTestTiming::TimingTest() done.
[15:33:52.979] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//tbmParameters_C0a.dat
[15:33:52.979] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:33:52.979] INFO: PixTestTiming::doTest took 666538 ms.
[15:33:52.979] INFO: PixTestTiming::doTest() done
[15:33:52.979] INFO: Write out TBMPhaseScan_0_V0
[15:33:53.007] INFO: Write out TBMPhaseScan_1_V0
[15:33:53.007] INFO: Write out CombinedTBMPhaseScan_V0
[15:33:53.027] INFO: Write out ROCDelayScan3_V0
[15:33:53.028] INFO: enter test to run
[15:34:09.600] INFO: test: PixelAlive no parameter change
[15:34:09.600] INFO: running: pixelalive
[15:34:09.604] INFO: ----------------------------------------------------------------------
[15:34:09.604] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:34:09.604] INFO: ----------------------------------------------------------------------
[15:34:09.924] INFO: Expecting 41600 events.
[15:34:14.252] INFO: 41600 events read in total (3612ms).
[15:34:14.253] INFO: Test took 4647ms.
[15:34:14.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:14.658] INFO: PixTestAlive::aliveTest() done
[15:34:14.658] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:34:14.660] INFO: enter test to run
[15:35:20.439] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:35:20.439] INFO: running: highrate
[15:35:20.453] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:35:20.607] INFO: ----------------------------------------------------------------------
[15:35:20.607] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:35:20.607] INFO: ----------------------------------------------------------------------
[15:35:20.607] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:35:20.607] INFO: edge/corner pixel THR is adjusted
[15:35:20.607] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:35:21.566] INFO: Collecting data for 5 seconds...
[15:35:26.582] INFO: Done with hot pixel readout
[15:35:38.256] INFO: PixTest:: pg_setup set to default.
[15:35:38.257] INFO: 2 hot pixels found in step 0
[15:35:39.248] INFO: Collecting data for 5 seconds...
[15:35:44.265] INFO: Done with hot pixel readout
[15:35:54.003] INFO: PixTest:: pg_setup set to default.
[15:35:54.004] INFO: 1 hot pixels found in step 1
[15:35:55.995] INFO: Collecting data for 5 seconds...
[15:36:00.004] INFO: Done with hot pixel readout
[15:36:09.807] INFO: PixTest:: pg_setup set to default.
[15:36:09.808] INFO: 2 hot pixels found in step 2
[15:36:10.799] INFO: Collecting data for 5 seconds...
[15:36:15.815] INFO: Done with hot pixel readout
[15:36:27.488] INFO: PixTest:: pg_setup set to default.
[15:36:27.489] INFO: 0 hot pixels found in step 3
[15:36:27.524] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:36:27.528] INFO: PixTest::trimHotPixels() done
[15:36:27.528] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C0.dat
[15:36:27.533] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C1.dat
[15:36:27.540] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C2.dat
[15:36:27.546] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C3.dat
[15:36:27.552] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C4.dat
[15:36:27.557] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C5.dat
[15:36:27.562] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C6.dat
[15:36:27.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C7.dat
[15:36:27.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C8.dat
[15:36:27.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C9.dat
[15:36:27.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C10.dat
[15:36:27.588] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C11.dat
[15:36:27.593] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C12.dat
[15:36:27.598] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C13.dat
[15:36:27.604] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C14.dat
[15:36:27.609] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C15.dat
[15:36:27.614] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//defaultMaskFile.dat
[15:36:27.625] INFO: enter test to run
[15:36:58.830] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:36:58.830] INFO: running: highrate
[15:36:58.835] INFO: ----------------------------------------------------------------------
[15:36:58.835] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:36:58.835] INFO: ----------------------------------------------------------------------
[15:36:58.835] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:36:58.835] INFO: edge/corner pixel THR is adjusted
[15:36:58.835] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:36:59.793] INFO: Collecting data for 1 seconds...
[15:37:00.797] INFO: Done with hot pixel readout
[15:37:04.818] INFO: PixTest:: pg_setup set to default.
[15:37:04.819] INFO: 0 hot pixels found in step 0
[15:37:04.824] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:37:04.914] INFO: PixTest::trimHotPixels() done
[15:37:04.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C0.dat
[15:37:04.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C1.dat
[15:37:04.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C2.dat
[15:37:04.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C3.dat
[15:37:04.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C4.dat
[15:37:04.947] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C5.dat
[15:37:04.952] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C6.dat
[15:37:04.957] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C7.dat
[15:37:04.962] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C8.dat
[15:37:04.967] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C9.dat
[15:37:04.972] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C10.dat
[15:37:04.978] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C11.dat
[15:37:04.983] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C12.dat
[15:37:04.988] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C13.dat
[15:37:04.993] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C14.dat
[15:37:04.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//trimParameters35_C15.dat
[15:37:04.003] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-25_FPIXTest-17C-FNAL-160502-1252_2016-05-02_12h53m_1462211591/000_FPIXTest_p17//defaultMaskFile.dat
[15:37:05.013] INFO: enter test to run
[15:37:33.622] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:37:33.622] INFO: running: xray
[15:37:33.623] INFO: ----------------------------------------------------------------------
[15:37:33.623] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:37:33.623] INFO: ----------------------------------------------------------------------
[15:37:34.587] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:37:46.109] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:38:15.702] INFO: Resuming triggers.
[15:38:27.319] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:38:56.678] INFO: Resuming triggers.
[15:39:08.200] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:39:37.734] INFO: Resuming triggers.
[15:39:49.259] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:40:18.643] INFO: Resuming triggers.
[15:40:30.164] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[15:40:59.655] INFO: Resuming triggers.
[15:41:11.176] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:41:40.414] INFO: Resuming triggers.
[15:41:51.934] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:42:21.289] INFO: Resuming triggers.
[15:42:32.811] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[15:43:02.240] INFO: Resuming triggers.
[15:43:10.387] INFO: data taking finished, elapsed time: 100 seconds.
[15:43:31.418] INFO: PixTest:: pg_setup set to default.
[15:43:31.421] INFO: PixTestXray::doPhRun() done
[15:43:31.575] INFO: enter test to run
[15:44:24.603] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:44:24.603] INFO: running: xray
[15:44:24.604] INFO: ----------------------------------------------------------------------
[15:44:24.604] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:44:24.604] INFO: ----------------------------------------------------------------------
[15:44:25.581] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:44:32.337] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:45:02.757] INFO: Resuming triggers.
[15:45:09.515] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:45:39.928] INFO: Resuming triggers.
[15:45:46.682] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:46:14.382] INFO: Resuming triggers.
[15:46:21.140] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:46:51.577] INFO: Resuming triggers.
[15:46:58.332] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:47:28.744] INFO: Resuming triggers.
[15:47:35.498] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[15:48:05.888] INFO: Resuming triggers.
[15:48:12.643] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[15:48:43.134] INFO: Resuming triggers.
[15:48:49.892] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:49:20.289] INFO: Resuming triggers.
[15:49:27.045] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[15:49:57.460] INFO: Resuming triggers.
[15:50:04.216] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:50:34.567] INFO: Resuming triggers.
[15:50:41.319] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[15:51:11.708] INFO: Resuming triggers.
[15:51:18.457] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:51:48.827] INFO: Resuming triggers.
[15:51:55.577] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[15:52:25.884] INFO: Resuming triggers.
[15:52:32.639] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[15:53:03.090] INFO: Resuming triggers.
[15:53:08.851] INFO: data taking finished, elapsed time: 100 seconds.
[15:53:34.996] INFO: PixTest:: pg_setup set to default.
[15:53:34.999] INFO: PixTestXray::doPhRun() done
[15:53:35.145] INFO: enter test to run
[15:54:27.543] INFO: test: HighRate no parameter change
[15:54:27.543] INFO: running: highrate
[15:54:27.560] INFO: ----------------------------------------------------------------------
[15:54:27.560] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:54:27.560] INFO: ----------------------------------------------------------------------
[15:54:27.724] INFO: Expecting 768 events.
[15:54:28.857] INFO: 768 events read in total (418ms).
[15:54:28.858] INFO: Test took 1269ms.
[15:54:29.661] INFO: Expecting 41600 events.
[15:54:32.758] INFO: 41600 events read in total (2570ms).
[15:54:32.759] INFO: Test took 3892ms.
[15:54:32.791] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:33.518] INFO: Expecting 41600 events.
[15:54:36.723] INFO: 41600 events read in total (2678ms).
[15:54:36.724] INFO: Test took 3917ms.
[15:54:36.758] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:37.484] INFO: Expecting 41600 events.
[15:54:40.718] INFO: 41600 events read in total (2707ms).
[15:54:40.719] INFO: Test took 3943ms.
[15:54:40.753] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:41.477] INFO: Expecting 41600 events.
[15:54:44.717] INFO: 41600 events read in total (2713ms).
[15:54:44.717] INFO: Test took 3947ms.
[15:54:44.750] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:45.477] INFO: Expecting 41600 events.
[15:54:48.714] INFO: 41600 events read in total (2710ms).
[15:54:48.715] INFO: Test took 3948ms.
[15:54:48.748] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:49.476] INFO: Expecting 41600 events.
[15:54:52.731] INFO: 41600 events read in total (2728ms).
[15:54:52.732] INFO: Test took 3966ms.
[15:54:52.765] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:53.491] INFO: Expecting 41600 events.
[15:54:56.741] INFO: 41600 events read in total (2723ms).
[15:54:56.743] INFO: Test took 3960ms.
[15:54:56.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:54:57.504] INFO: Expecting 41600 events.
[15:55:00.759] INFO: 41600 events read in total (2728ms).
[15:55:00.760] INFO: Test took 3967ms.
[15:55:00.793] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:01.519] INFO: Expecting 41600 events.
[15:55:04.767] INFO: 41600 events read in total (2722ms).
[15:55:04.768] INFO: Test took 3957ms.
[15:55:04.801] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:05.523] INFO: Expecting 41600 events.
[15:55:08.784] INFO: 41600 events read in total (2734ms).
[15:55:08.786] INFO: Test took 3966ms.
[15:55:08.819] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:09.540] INFO: Expecting 41600 events.
[15:55:12.798] INFO: 41600 events read in total (2731ms).
[15:55:12.799] INFO: Test took 3962ms.
[15:55:12.833] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:13.559] INFO: Expecting 41600 events.
[15:55:16.793] INFO: 41600 events read in total (2707ms).
[15:55:16.794] INFO: Test took 3943ms.
[15:55:16.827] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:17.555] INFO: Expecting 41600 events.
[15:55:20.801] INFO: 41600 events read in total (2719ms).
[15:55:20.802] INFO: Test took 3957ms.
[15:55:20.836] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:21.562] INFO: Expecting 41600 events.
[15:55:24.819] INFO: 41600 events read in total (2730ms).
[15:55:24.820] INFO: Test took 3968ms.
[15:55:24.853] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:25.578] INFO: Expecting 41600 events.
[15:55:28.827] INFO: 41600 events read in total (2722ms).
[15:55:28.828] INFO: Test took 3956ms.
[15:55:28.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:29.587] INFO: Expecting 41600 events.
[15:55:32.811] INFO: 41600 events read in total (2697ms).
[15:55:32.812] INFO: Test took 3931ms.
[15:55:32.846] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:33.567] INFO: Expecting 41600 events.
[15:55:36.797] INFO: 41600 events read in total (2703ms).
[15:55:36.798] INFO: Test took 3934ms.
[15:55:36.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:37.559] INFO: Expecting 41600 events.
[15:55:40.803] INFO: 41600 events read in total (2717ms).
[15:55:40.804] INFO: Test took 3953ms.
[15:55:40.837] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:41.563] INFO: Expecting 41600 events.
[15:55:44.790] INFO: 41600 events read in total (2700ms).
[15:55:44.791] INFO: Test took 3937ms.
[15:55:44.825] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:45.552] INFO: Expecting 41600 events.
[15:55:48.671] INFO: 41600 events read in total (2592ms).
[15:55:48.672] INFO: Test took 3828ms.
[15:55:48.704] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:55:49.070] INFO: enter test to run
[15:55:53.134] INFO: test: HighRate no parameter change
[15:55:53.134] INFO: running: highrate
[15:55:53.135] INFO: ----------------------------------------------------------------------
[15:55:53.135] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:55:53.135] INFO: ----------------------------------------------------------------------
[15:55:53.747] INFO: Expecting 208000 events.
[15:56:05.328] INFO: 208000 events read in total (11054ms).
[15:56:05.331] INFO: Test took 12188ms.
[15:56:05.475] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:05.727] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:56:05.727] INFO: number of red-efficiency pixels: 69 44 78 131 111 102 141 72 91 106 2681 94 111 70 20 20
[15:56:05.727] INFO: number of X-ray hits detected: 64917 45361 63495 103891 111328 105954 113083 78565 73282 97500 95851 85392 82555 51729 22347 23734
[15:56:05.727] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:56:05.727] INFO: number of Vcal hits detected: 207930 207955 207921 207865 207889 207896 207857 207927 207906 207890 204623 207904 207888 207930 207980 207980
[15:56:05.727] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0 98.4 100.0 100.0 100.0 100.0 100.0
[15:56:05.727] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 99.9 98.4 100.0 99.9 100.0 100.0 100.0
[15:56:05.727] INFO: X-ray hit rate [MHz/cm2]: 19.0 13.3 18.6 30.5 32.6 31.1 33.1 23.0 21.5 28.6 28.1 25.0 24.2 15.2 6.6 7.0
[15:56:05.727] INFO: PixTestHighRate::doXPixelAlive() done
[15:56:05.773] INFO: PixTest:: pg_setup set to default.
[15:56:05.784] INFO: enter test to run
[15:56:36.750] INFO: test: HighRate no parameter change
[15:56:36.750] INFO: running: highrate
[15:56:36.751] INFO: ----------------------------------------------------------------------
[15:56:36.751] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:56:36.751] INFO: ----------------------------------------------------------------------
[15:56:37.370] INFO: Expecting 208000 events.
[15:56:50.109] INFO: 208000 events read in total (12212ms).
[15:56:50.113] INFO: Test took 13352ms.
[15:56:50.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:56:50.595] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:56:50.595] INFO: number of red-efficiency pixels: 116 91 124 241 260 261 233 127 136 218 2658 163 200 137 37 31
[15:56:50.595] INFO: number of X-ray hits detected: 98068 69282 96303 156916 170001 160378 173606 119599 111664 148069 145984 129606 125801 78721 34236 35849
[15:56:50.595] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:56:50.595] INFO: number of Vcal hits detected: 207881 207906 207871 207754 207731 207726 207758 207872 207860 207772 204586 207833 207796 207859 207963 207969
[15:56:50.595] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 98.4 99.9 99.9 99.9 100.0 100.0
[15:56:50.595] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 98.4 99.9 99.9 99.9 100.0 100.0
[15:56:50.595] INFO: X-ray hit rate [MHz/cm2]: 28.7 20.3 28.2 46.0 49.8 47.0 50.9 35.1 32.7 43.4 42.8 38.0 36.9 23.1 10.0 10.5
[15:56:50.595] INFO: PixTestHighRate::doXPixelAlive() done
[15:56:50.647] INFO: PixTest:: pg_setup set to default.
[15:56:50.659] INFO: enter test to run
[15:57:13.829] INFO: test: HighRate no parameter change
[15:57:13.829] INFO: running: highrate
[15:57:13.831] INFO: ----------------------------------------------------------------------
[15:57:13.831] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:57:13.831] INFO: ----------------------------------------------------------------------
[15:57:14.447] INFO: Expecting 208000 events.
[15:57:28.099] INFO: 208000 events read in total (13126ms).
[15:57:28.105] INFO: Test took 14264ms.
[15:57:28.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:57:28.688] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:57:28.688] INFO: number of red-efficiency pixels: 204 136 261 362 400 407 411 230 262 389 2666 235 318 205 41 51
[15:57:28.688] INFO: number of X-ray hits detected: 133480 94717 132028 213665 231009 217954 234992 162912 151382 201681 198682 176187 170957 107511 45792 48282
[15:57:28.688] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:57:28.688] INFO: number of Vcal hits detected: 207789 207862 207723 207613 207571 207551 207557 207761 207729 207591 204419 207754 207671 207779 207959 207948
[15:57:28.689] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 98.3 99.9 99.9 99.9 100.0 100.0
[15:57:28.689] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 98.3 99.9 99.8 99.9 100.0 100.0
[15:57:28.689] INFO: X-ray hit rate [MHz/cm2]: 39.1 27.8 38.7 62.6 67.7 63.9 68.9 47.8 44.4 59.1 58.2 51.6 50.1 31.5 13.4 14.2
[15:57:28.689] INFO: PixTestHighRate::doXPixelAlive() done
[15:57:28.733] INFO: PixTest:: pg_setup set to default.
[15:57:28.749] INFO: enter test to run
[15:57:52.765] INFO: test: exit no parameter change
[15:57:53.233] QUIET: Connection to board 32 closed.
[15:57:53.248] INFO: pXar: this is the end, my friend