[16:30:42.592] INFO: *** Welcome to pxar ***
[16:30:42.592] INFO: *** Today: 2016/04/14
[16:30:42.612] INFO: *** Version: v1.9.0-796-gef167-dirty
[16:30:42.612] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//dacParameters35_C15.dat
[16:30:42.613] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:30:42.614] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//defaultMaskFile.dat
[16:30:42.614] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C15.dat
[16:30:42.683] INFO: clk: 4
[16:30:42.683] INFO: ctr: 4
[16:30:42.683] INFO: sda: 19
[16:30:42.683] INFO: tin: 9
[16:30:42.683] INFO: level: 15
[16:30:42.683] INFO: triggerdelay: 0
[16:30:42.683] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[16:30:42.683] INFO: Log level: INFO
[16:30:42.701] QUIET: Connection to board DTB_WREKRL opened.
[16:30:42.704] 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:
------------------------------------------------------
[16:30:42.707] INFO: RPC call hashes of host and DTB match: 398089610
[16:30:44.239] INFO: DUT info:
[16:30:44.239] INFO: The DUT currently contains the following objects:
[16:30:44.239] INFO: 2 TBM Cores tbm08c (2 ON)
[16:30:44.239] INFO: TBM Core alpha (0): 7 registers set
[16:30:44.239] INFO: TBM Core beta (1): 7 registers set
[16:30:44.239] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:30:44.239] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.239] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.240] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:30:44.643] INFO: enter 'restricted' command line mode
[16:30:44.643] INFO: enter test to run
[16:31:28.651] INFO: test: timing no parameter change
[16:31:28.651] INFO: running: timing
[16:31:28.660] INFO: ######################################################################
[16:31:28.660] INFO: PixTestTiming::doTest()
[16:31:28.677] INFO: ######################################################################
[16:31:28.677] INFO: ----------------------------------------------------------------------
[16:31:28.677] INFO: PixTestTiming::TBMPhaseScan()
[16:31:28.677] INFO: ----------------------------------------------------------------------
[16:36:03.066] INFO: TBM Phase Settings: 236
[16:36:03.066] INFO: 400MHz Phase: 3
[16:36:03.067] INFO: 160MHz Phase: 7
[16:36:03.067] INFO: Functional Phase Area: 3
[16:36:03.070] INFO: Test took 274393 ms.
[16:36:03.070] INFO: PixTestTiming::TBMPhaseScan() done.
[16:36:03.070] INFO: ----------------------------------------------------------------------
[16:36:03.070] INFO: PixTestTiming::ROCDelayScan()
[16:36:03.070] INFO: ----------------------------------------------------------------------
[16:37:58.210] INFO: ROC Delay Settings: 228
[16:37:58.210] INFO: ROC Header-Trailer/Token Delay: 11
[16:37:58.210] INFO: ROC Port 0 Delay: 4
[16:37:58.210] INFO: ROC Port 1 Delay: 4
[16:37:58.210] INFO: Functional ROC Area: 3
[16:37:58.213] INFO: Test took 115143 ms.
[16:37:58.213] INFO: PixTestTiming::ROCDelayScan() done.
[16:37:58.214] INFO: ----------------------------------------------------------------------
[16:37:58.214] INFO: PixTestTiming::TimingTest()
[16:37:58.214] INFO: ----------------------------------------------------------------------
[16:38:14.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:38:29.340] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:38:44.304] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:38:59.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:39:14.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:39:29.220] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:39:44.203] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:39:59.158] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:40:14.145] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:40:29.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:40:29.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:40:29.524] INFO: ----------------------------------------------------------------------
[16:40:29.524] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[16:40:29.524] INFO: ----------------------------------------------------------------------
[16:40:29.524] INFO: ----------------------------------------------------------------------
[16:40:29.524] INFO: Read back bit status: 1
[16:40:29.524] INFO: ----------------------------------------------------------------------
[16:40:29.524] INFO: ----------------------------------------------------------------------
[16:40:29.524] INFO: Timings are good!
[16:40:29.524] INFO: ----------------------------------------------------------------------
[16:40:29.524] INFO: Test took 151310 ms.
[16:40:29.524] INFO: PixTestTiming::TimingTest() done.
[16:40:29.538] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//tbmParameters_C0a.dat
[16:40:29.538] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:40:29.538] INFO: PixTestTiming::doTest took 540883 ms.
[16:40:29.538] INFO: PixTestTiming::doTest() done
[16:40:29.538] INFO: Write out TBMPhaseScan_0_V0
[16:40:29.563] INFO: Write out TBMPhaseScan_1_V0
[16:40:29.563] INFO: Write out CombinedTBMPhaseScan_V0
[16:40:29.564] INFO: Write out ROCDelayScan3_V0
[16:40:29.564] INFO: enter test to run
[16:42:46.030] INFO: test: PixelAlive no parameter change
[16:42:46.030] INFO: running: pixelalive
[16:42:46.035] INFO: ----------------------------------------------------------------------
[16:42:46.035] 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:42:46.035] INFO: ----------------------------------------------------------------------
[16:42:46.350] INFO: Expecting 41600 events.
[16:42:50.683] INFO: 41600 events read in total (3618ms).
[16:42:50.684] INFO: Test took 4647ms.
[16:42:50.690] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:42:51.093] INFO: PixTestAlive::aliveTest() done
[16:42:51.093] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:42:51.096] INFO: enter test to run
[16:43:31.630] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:43:31.630] INFO: running: highrate
[16:43:31.630] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:43:31.780] INFO: ----------------------------------------------------------------------
[16:43:31.780] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:43:31.780] INFO: ----------------------------------------------------------------------
[16:43:31.780] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:43:31.780] INFO: edge/corner pixel THR is adjusted
[16:43:31.780] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:43:32.738] INFO: Collecting data for 5 seconds...
[16:43:37.755] INFO: Done with hot pixel readout
[16:43:49.759] INFO: PixTest:: pg_setup set to default.
[16:43:49.760] INFO: 4 hot pixels found in step 0
[16:43:50.754] INFO: Collecting data for 5 seconds...
[16:43:55.771] INFO: Done with hot pixel readout
[16:44:07.060] INFO: PixTest:: pg_setup set to default.
[16:44:07.061] INFO: 5 hot pixels found in step 1
[16:44:08.056] INFO: Collecting data for 5 seconds...
[16:44:13.066] INFO: Done with hot pixel readout
[16:44:23.834] INFO: PixTest:: pg_setup set to default.

[16:44:23.835] INFO: 3 hot pixels found in step 2
[16:44:24.830] INFO: Collecting data for 5 seconds...
[16:44:29.845] INFO: Done with hot pixel readout
[16:44:41.854] INFO: PixTest:: pg_setup set to default.
[16:44:41.855] INFO: 2 hot pixels found in step 3
[16:44:42.851] INFO: Collecting data for 5 seconds...
[16:44:47.867] INFO: Done with hot pixel readout
[16:44:59.844] INFO: PixTest:: pg_setup set to default.
[16:44:59.845] INFO: 2 hot pixels found in step 4
[16:45:00.840] INFO: Collecting data for 5 seconds...
[16:45:05.856] INFO: Done with hot pixel readout
[16:45:17.902] INFO: PixTest:: pg_setup set to default.
[16:45:17.903] INFO: 0 hot pixels found in step 5
[16:45:17.941] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:45:17.945] INFO: PixTest::trimHotPixels() done
[16:45:17.945] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C0.dat
[16:45:17.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C1.dat
[16:45:17.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C2.dat
[16:45:17.964] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C3.dat
[16:45:17.969] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C4.dat
[16:45:17.975] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C5.dat
[16:45:17.981] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C6.dat
[16:45:17.986] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C7.dat
[16:45:17.992] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C8.dat
[16:45:17.997] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C9.dat
[16:45:17.003] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C10.dat
[16:45:18.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C11.dat
[16:45:18.014] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C12.dat
[16:45:18.019] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C13.dat
[16:45:18.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C14.dat
[16:45:18.031] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C15.dat
[16:45:18.036] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//defaultMaskFile.dat
[16:45:18.047] INFO: enter test to run
[16:45:49.109] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:45:49.109] INFO: running: highrate
[16:45:49.113] INFO: ----------------------------------------------------------------------
[16:45:49.113] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:45:49.113] INFO: ----------------------------------------------------------------------
[16:45:49.113] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:45:49.113] INFO: edge/corner pixel THR is adjusted
[16:45:49.113] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:45:50.071] INFO: Collecting data for 1 seconds...
[16:45:51.075] INFO: Done with hot pixel readout
[16:45:55.236] INFO: PixTest:: pg_setup set to default.
[16:45:55.237] INFO: 0 hot pixels found in step 0
[16:45:55.242] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:45:55.328] INFO: PixTest::trimHotPixels() done
[16:45:55.328] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C0.dat
[16:45:55.339] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C1.dat
[16:45:55.345] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C2.dat
[16:45:55.350] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C3.dat
[16:45:55.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C4.dat
[16:45:55.362] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C5.dat
[16:45:55.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C6.dat
[16:45:55.373] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C7.dat
[16:45:55.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C8.dat
[16:45:55.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C9.dat
[16:45:55.390] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C10.dat
[16:45:55.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C11.dat
[16:45:55.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C12.dat
[16:45:55.407] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C13.dat
[16:45:55.412] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C14.dat
[16:45:55.418] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//trimParameters35_C15.dat
[16:45:55.424] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-49_FPIXTest-17C-FNAL-160408-0921_2016-04-08_09h21m_1460125289/000_FPIXTest_p17//defaultMaskFile.dat
[16:45:55.437] INFO: enter test to run
[16:46:22.741] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:46:22.741] INFO: running: xray
[16:46:22.742] INFO: ----------------------------------------------------------------------
[16:46:22.742] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:46:22.742] INFO: ----------------------------------------------------------------------
[16:46:23.705] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:46:34.922] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:47:04.358] INFO: Resuming triggers.
[16:47:15.575] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:47:44.925] INFO: Resuming triggers.
[16:47:56.143] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:48:25.648] INFO: Resuming triggers.
[16:48:36.865] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:49:06.237] INFO: Resuming triggers.
[16:49:17.457] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[16:49:46.860] INFO: Resuming triggers.
[16:49:58.080] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:50:27.463] INFO: Resuming triggers.
[16:50:38.684] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:51:08.126] INFO: Resuming triggers.
[16:51:19.349] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[16:51:48.654] INFO: Resuming triggers.
[16:51:59.242] INFO: data taking finished, elapsed time: 100 seconds.
[16:52:27.027] INFO: PixTest:: pg_setup set to default.
[16:52:27.030] INFO: PixTestXray::doPhRun() done
[16:52:27.212] INFO: enter test to run
[16:52:59.122] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:52:59.122] INFO: running: xray
[16:52:59.123] INFO: ----------------------------------------------------------------------
[16:52:59.123] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:52:59.123] INFO: ----------------------------------------------------------------------
[16:53:00.086] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:53:06.465] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:53:36.465] INFO: Resuming triggers.
[16:53:42.842] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[16:54:12.932] INFO: Resuming triggers.
[16:54:19.310] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[16:54:47.331] INFO: Resuming triggers.
[16:54:53.709] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[16:55:23.705] INFO: Resuming triggers.
[16:55:30.080] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[16:56:00.093] INFO: Resuming triggers.
[16:56:06.471] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[16:56:36.319] INFO: Resuming triggers.
[16:56:42.697] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:57:12.727] INFO: Resuming triggers.
[16:57:19.099] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[16:57:49.126] INFO: Resuming triggers.
[16:57:55.504] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[16:58:25.538] INFO: Resuming triggers.
[16:58:31.912] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[16:59:01.962] INFO: Resuming triggers.
[16:59:08.341] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[16:59:38.340] INFO: Resuming triggers.
[16:59:44.715] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[17:00:14.757] INFO: Resuming triggers.
[17:00:21.134] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[17:00:51.224] INFO: Resuming triggers.
[17:00:57.598] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[17:01:27.652] INFO: Resuming triggers.
[17:01:34.031] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[17:02:04.100] INFO: Resuming triggers.
[17:02:08.779] INFO: data taking finished, elapsed time: 100 seconds.
[17:02:31.106] INFO: PixTest:: pg_setup set to default.
[17:02:31.109] INFO: PixTestXray::doPhRun() done
[17:02:31.257] INFO: enter test to run
[17:07:49.771] INFO: test: HighRate no parameter change
[17:07:49.771] INFO: running: highrate
[17:07:49.772] INFO: ----------------------------------------------------------------------
[17:07:49.772] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:07:49.772] INFO: ----------------------------------------------------------------------
[17:07:49.913] INFO: Expecting 768 events.
[17:07:51.047] INFO: 768 events read in total (418ms).
[17:07:51.048] INFO: Test took 1269ms.
[17:07:51.851] INFO: Expecting 41600 events.
[17:07:54.949] INFO: 41600 events read in total (2571ms).
[17:07:54.950] INFO: Test took 3894ms.
[17:07:54.984] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:55.710] INFO: Expecting 41600 events.
[17:07:58.911] INFO: 41600 events read in total (2674ms).
[17:07:58.912] INFO: Test took 3912ms.
[17:07:58.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:07:59.669] INFO: Expecting 41600 events.
[17:08:02.897] INFO: 41600 events read in total (2701ms).
[17:08:02.898] INFO: Test took 3933ms.
[17:08:02.933] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:03.656] INFO: Expecting 41600 events.
[17:08:06.915] INFO: 41600 events read in total (2732ms).
[17:08:06.916] INFO: Test took 3964ms.
[17:08:06.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:07.671] INFO: Expecting 41600 events.
[17:08:10.924] INFO: 41600 events read in total (2726ms).
[17:08:10.925] INFO: Test took 3956ms.
[17:08:10.960] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:11.680] INFO: Expecting 41600 events.
[17:08:14.923] INFO: 41600 events read in total (2716ms).
[17:08:14.924] INFO: Test took 3946ms.
[17:08:14.959] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:15.682] INFO: Expecting 41600 events.
[17:08:18.965] INFO: 41600 events read in total (2756ms).
[17:08:18.966] INFO: Test took 3990ms.
[17:08:18.001] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:19.722] INFO: Expecting 41600 events.
[17:08:22.988] INFO: 41600 events read in total (2739ms).
[17:08:22.989] INFO: Test took 3969ms.
[17:08:23.024] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:23.747] INFO: Expecting 41600 events.
[17:08:27.016] INFO: 41600 events read in total (2742ms).
[17:08:27.017] INFO: Test took 3975ms.
[17:08:27.053] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:27.774] INFO: Expecting 41600 events.
[17:08:31.052] INFO: 41600 events read in total (2751ms).
[17:08:31.053] INFO: Test took 3981ms.
[17:08:31.089] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:31.812] INFO: Expecting 41600 events.
[17:08:35.095] INFO: 41600 events read in total (2756ms).
[17:08:35.096] INFO: Test took 3990ms.
[17:08:35.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:35.854] INFO: Expecting 41600 events.
[17:08:39.125] INFO: 41600 events read in total (2744ms).
[17:08:39.126] INFO: Test took 3976ms.
[17:08:39.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:39.884] INFO: Expecting 41600 events.
[17:08:43.156] INFO: 41600 events read in total (2746ms).
[17:08:43.157] INFO: Test took 3976ms.
[17:08:43.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:43.915] INFO: Expecting 41600 events.
[17:08:47.199] INFO: 41600 events read in total (2757ms).
[17:08:47.200] INFO: Test took 3988ms.
[17:08:47.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:47.955] INFO: Expecting 41600 events.
[17:08:51.223] INFO: 41600 events read in total (2741ms).
[17:08:51.224] INFO: Test took 3968ms.
[17:08:51.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:51.982] INFO: Expecting 41600 events.
[17:08:55.251] INFO: 41600 events read in total (2742ms).
[17:08:55.252] INFO: Test took 3975ms.
[17:08:55.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:08:55.004] INFO: Expecting 41600 events.
[17:08:59.284] INFO: 41600 events read in total (2753ms).
[17:08:59.286] INFO: Test took 3971ms.
[17:08:59.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:00.041] INFO: Expecting 41600 events.
[17:09:03.304] INFO: 41600 events read in total (2736ms).
[17:09:03.305] INFO: Test took 3965ms.
[17:09:03.340] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:04.061] INFO: Expecting 41600 events.
[17:09:07.289] INFO: 41600 events read in total (2702ms).
[17:09:07.290] INFO: Test took 3930ms.
[17:09:07.326] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:08.048] INFO: Expecting 41600 events.
[17:09:11.125] INFO: 41600 events read in total (2550ms).
[17:09:11.126] INFO: Test took 3781ms.
[17:09:11.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:09:11.522] INFO: enter test to run
[17:09:51.530] INFO: test: HighRate no parameter change
[17:09:51.530] INFO: running: highrate
[17:09:51.532] INFO: ----------------------------------------------------------------------
[17:09:51.532] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:09:51.532] INFO: ----------------------------------------------------------------------
[17:09:52.142] INFO: Expecting 208000 events.
[17:10:04.101] INFO: 208000 events read in total (11432ms).
[17:10:04.104] INFO: Test took 12565ms.
[17:10:04.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:10:04.510] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:10:04.510] INFO: number of red-efficiency pixels: 85 48 100 131 185 160 139 100 113 139 138 134 109 83 29 31
[17:10:04.510] INFO: number of X-ray hits detected: 64927 44889 72864 115838 121273 122261 119705 86568 80977 104649 103806 88920 88864 52116 24987 27190
[17:10:04.510] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:10:04.510] INFO: number of Vcal hits detected: 207914 207951 207899 207866 207811 207836 207860 207896 207885 207856 207860 207863 207887 207916 207971 207969
[17:10:04.510] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[17:10:04.510] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[17:10:04.510] INFO: X-ray hit rate [MHz/cm2]: 19.0 13.2 21.4 34.0 35.5 35.8 35.1 25.4 23.7 30.7 30.4 26.1 26.0 15.3 7.3 8.0
[17:10:04.510] INFO: PixTestHighRate::doXPixelAlive() done
[17:10:04.556] INFO: PixTest:: pg_setup set to default.
[17:10:04.573] INFO: enter test to run
[17:10:28.442] INFO: test: HighRate no parameter change
[17:10:28.442] INFO: running: highrate
[17:10:28.443] INFO: ----------------------------------------------------------------------
[17:10:28.443] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:10:28.443] INFO: ----------------------------------------------------------------------
[17:10:29.061] INFO: Expecting 208000 events.
[17:10:42.859] INFO: 208000 events read in total (13271ms).
[17:10:42.864] INFO: Test took 14412ms.
[17:10:43.170] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:10:43.476] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:10:43.476] INFO: number of red-efficiency pixels: 224 125 336 479 654 653 522 348 281 501 480 347 318 206 68 59
[17:10:43.476] INFO: number of X-ray hits detected: 135075 92137 152107 240217 251134 252176 247487 179899 168704 217295 214898 184088 185319 109216 51207 56448
[17:10:43.476] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:10:43.476] INFO: number of Vcal hits detected: 207763 207869 207637 207485 207267 207252 207413 207635 207703 207444 207478 207636 207664 207783 207932 207941
[17:10:43.476] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[17:10:43.476] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.6 99.6 99.7 99.8 99.9 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[17:10:43.476] INFO: X-ray hit rate [MHz/cm2]: 39.6 27.0 44.6 70.4 73.6 73.9 72.5 52.7 49.4 63.7 63.0 54.0 54.3 32.0 15.0 16.5
[17:10:43.476] INFO: PixTestHighRate::doXPixelAlive() done
[17:10:43.520] INFO: PixTest:: pg_setup set to default.
[17:10:43.534] INFO: enter test to run
[17:11:07.874] INFO: test: HighRate no parameter change
[17:11:07.874] INFO: running: highrate
[17:11:07.875] INFO: ----------------------------------------------------------------------
[17:11:07.875] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:11:07.875] INFO: ----------------------------------------------------------------------
[17:11:08.488] INFO: Expecting 208000 events.
[17:11:24.421] INFO: 208000 events read in total (15406ms).
[17:11:24.429] INFO: Test took 16544ms.
[17:11:24.906] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:11:25.264] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[17:11:25.264] INFO: number of red-efficiency pixels: 436 242 787 1092 1598 1558 1242 733 595 1160 1177 886 789 469 116 105
[17:11:25.264] INFO: number of X-ray hits detected: 205639 143298 234113 370334 385618 387624 379989 277698 259868 335663 331971 282338 283247 167196 78802 87222
[17:11:25.264] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:11:25.264] INFO: number of Vcal hits detected: 207495 207745 206893 206610 205777 205842 206375 207082 207312 206539 206548 206948 207066 207452 207876 207894
[17:11:25.264] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.5 99.4 99.0 99.0 99.3 99.6 99.7 99.4 99.3 99.5 99.6 99.8 99.9 100.0
[17:11:25.264] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.5 99.3 98.9 99.0 99.2 99.6 99.7 99.3 99.3 99.5 99.6 99.7 99.9 99.9
[17:11:25.264] INFO: X-ray hit rate [MHz/cm2]: 60.3 42.0 68.6 108.5 113.0 113.6 111.4 81.4 76.2 98.4 97.3 82.8 83.0 49.0 23.1 25.6
[17:11:25.265] INFO: PixTestHighRate::doXPixelAlive() done
[17:11:25.312] INFO: PixTest:: pg_setup set to default.
[17:11:25.329] INFO: enter test to run
[17:11:39.377] INFO: test: exit no parameter change
[17:11:39.783] QUIET: Connection to board 33 closed.
[17:11:39.785] INFO: pXar: this is the end, my friend