[16:45:09.389] INFO: *** Welcome to pxar ***
[16:45:09.389] INFO: *** Today: 2016/07/06
[16:45:11.432] INFO: *** Version: v1.9.0-814-g7497
[16:45:11.433] INFO: readRocDacs: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//dacParameters35_C15.dat
[16:45:11.498] INFO: readTbmDacs: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:45:11.498] INFO: readMaskFile: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//defaultMaskFile.dat
[16:45:11.498] INFO: readTrimFile: /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C15.dat
[16:45:11.641] INFO: clk: 4
[16:45:11.641] INFO: ctr: 4
[16:45:11.641] INFO: sda: 19
[16:45:11.641] INFO: tin: 9
[16:45:11.641] INFO: level: 15
[16:45:11.641] INFO: triggerdelay: 0
[16:45:11.641] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:45:11.641] INFO: Log level: INFO
[16:45:11.661] QUIET: Connection to board DTB_WREKRL opened.
[16:45:11.664] 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:45:11.667] INFO: RPC call hashes of host and DTB match: 398089610
[16:45:13.241] INFO: DUT info:
[16:45:13.241] INFO: The DUT currently contains the following objects:
[16:45:13.241] INFO: 2 TBM Cores tbm08c (2 ON)
[16:45:13.264] INFO: TBM Core alpha (0): 7 registers set
[16:45:13.264] INFO: TBM Core beta (1): 7 registers set
[16:45:13.264] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:45:13.264] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.264] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:45:13.725] INFO: enter 'restricted' command line mode
[16:45:13.725] INFO: enter test to run
[16:45:15.459] INFO: test: PixelAlive no parameter change
[16:45:15.459] INFO: running: pixelalive
[16:45:16.336] INFO: ----------------------------------------------------------------------
[16:45:16.336] 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:45:16.336] INFO: ----------------------------------------------------------------------
[16:45:16.651] INFO: Expecting 41600 events.
[16:45:20.000] INFO: 41600 events read in total (3631ms).
[16:45:21.155] INFO: Test took 4816ms.
[16:45:21.172] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:45:21.666] INFO: PixTestAlive::aliveTest() done
[16:45:21.666] INFO: number of dead pixels (per ROC): 3 1 1 0 0 0 0 0 0 0 0 1 0 0 0 0
[16:45:21.821] INFO: enter test to run
[16:45:57.610] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:45:57.610] INFO: running: highrate
[16:45:57.631] INFO: readGainPedestalParameters /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:45:58.186] INFO: ----------------------------------------------------------------------
[16:45:58.186] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:45:58.186] INFO: ----------------------------------------------------------------------
[16:45:58.186] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:45:58.186] INFO: edge/corner pixel THR is adjusted
[16:45:58.186] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:45:59.169] INFO: Collecting data for 5 seconds...
[16:46:04.190] INFO: Done with hot pixel readout
[16:46:15.790] INFO: PixTest:: pg_setup set to default.
[16:46:15.791] INFO: 12 hot pixels found in step 0
[16:46:16.796] INFO: Collecting data for 5 seconds...
[16:46:21.817] INFO: Done with hot pixel readout
[16:46:33.289] INFO: PixTest:: pg_setup set to default.
[16:46:33.290] INFO: 8 hot pixels found in step 1
[16:46:34.275] INFO: Collecting data for 5 seconds...
[16:46:39.294] INFO: Done with hot pixel readout
[16:46:50.781] INFO: PixTest:: pg_setup set to default.
[16:46:50.782] INFO: 9 hot pixels found in step 2
[16:46:51.766] INFO: Collecting data for 5 seconds...
[16:46:56.785] INFO: Done with hot pixel readout
[16:47:08.581] INFO: PixTest:: pg_setup set to default.
[16:47:08.582] INFO: 11 hot pixels found in step 3
[16:47:09.565] INFO: Collecting data for 5 seconds...
[16:47:14.585] INFO: Done with hot pixel readout
[16:47:25.887] INFO: PixTest:: pg_setup set to default.
[16:47:25.888] INFO: 7 hot pixels found in step 4
[16:47:26.872] INFO: Collecting data for 5 seconds...
[16:47:31.889] INFO: Done with hot pixel readout
[16:47:43.178] INFO: PixTest:: pg_setup set to default.
[16:47:43.179] INFO: 6 hot pixels found in step 5
[16:47:44.164] INFO: Collecting data for 5 seconds...
[16:47:49.181] INFO: Done with hot pixel readout
[16:48:00.422] INFO: PixTest:: pg_setup set to default.
[16:48:00.423] INFO: 2 hot pixels found in step 6
[16:48:01.408] INFO: Collecting data for 5 seconds...
[16:48:06.425] INFO: Done with hot pixel readout
[16:48:17.703] INFO: PixTest:: pg_setup set to default.
[16:48:17.704] INFO: 3 hot pixels found in step 7
[16:48:18.690] INFO: Collecting data for 5 seconds...
[16:48:23.706] INFO: Done with hot pixel readout
[16:48:34.950] INFO: PixTest:: pg_setup set to default.
[16:48:34.951] INFO: 3 hot pixels found in step 8
[16:48:35.936] INFO: Collecting data for 5 seconds...
[16:48:40.952] INFO: Done with hot pixel readout
[16:48:52.261] INFO: PixTest:: pg_setup set to default.
[16:48:52.262] INFO: 3 hot pixels found in step 9
[16:48:53.246] INFO: Collecting data for 5 seconds...
[16:48:58.263] INFO: Done with hot pixel readout
[16:49:09.553] INFO: PixTest:: pg_setup set to default.
[16:49:09.554] INFO: 2 hot pixels found in step 10
[16:49:10.539] INFO: Collecting data for 5 seconds...
[16:49:15.555] INFO: Done with hot pixel readout
[16:49:26.785] INFO: PixTest:: pg_setup set to default.
[16:49:26.786] INFO: 2 hot pixels found in step 11
[16:49:27.771] INFO: Collecting data for 5 seconds...
[16:49:32.789] INFO: Done with hot pixel readout
[16:49:44.064] INFO: PixTest:: pg_setup set to default.
[16:49:44.065] INFO: 3 hot pixels found in step 12
[16:49:45.051] INFO: Collecting data for 5 seconds...
[16:49:50.067] INFO: Done with hot pixel readout
[16:50:01.299] INFO: PixTest:: pg_setup set to default.
[16:50:01.300] INFO: 1 hot pixels found in step 13
[16:50:02.285] INFO: Collecting data for 5 seconds...
[16:50:07.301] INFO: Done with hot pixel readout
[16:50:18.544] INFO: PixTest:: pg_setup set to default.
[16:50:18.545] INFO: 0 hot pixels found in step 14
[16:50:18.573] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:50:18.576] INFO: PixTest::trimHotPixels() done
[16:50:18.576] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C0.dat
[16:50:18.599] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C1.dat
[16:50:18.611] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C2.dat
[16:50:18.618] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C3.dat
[16:50:18.623] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C4.dat
[16:50:18.628] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C5.dat
[16:50:18.634] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C6.dat
[16:50:18.639] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C7.dat
[16:50:18.644] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C8.dat
[16:50:18.650] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C9.dat
[16:50:18.655] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C10.dat
[16:50:18.660] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C11.dat
[16:50:18.666] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C12.dat
[16:50:18.671] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C13.dat
[16:50:18.676] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C14.dat
[16:50:18.682] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C15.dat
[16:50:18.687] INFO: write masked pixels into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//defaultMaskFile.dat
[16:50:18.704] INFO: enter test to run
[16:54:51.655] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:54:51.655] INFO: running: highrate
[16:54:51.660] INFO: ----------------------------------------------------------------------
[16:54:51.660] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:54:51.660] INFO: ----------------------------------------------------------------------
[16:54:51.660] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:54:51.660] INFO: edge/corner pixel THR is adjusted
[16:54:51.660] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:54:52.625] INFO: Collecting data for 1 seconds...
[16:54:53.629] INFO: Done with hot pixel readout
[16:54:57.362] INFO: PixTest:: pg_setup set to default.
[16:54:57.363] INFO: 0 hot pixels found in step 0
[16:54:57.370] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:54:57.467] INFO: PixTest::trimHotPixels() done
[16:54:57.467] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C0.dat
[16:54:57.479] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C1.dat
[16:54:57.486] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C2.dat
[16:54:57.491] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C3.dat
[16:54:57.498] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C4.dat
[16:54:57.503] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C5.dat
[16:54:57.509] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C6.dat
[16:54:57.514] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C7.dat
[16:54:57.519] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C8.dat
[16:54:57.525] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C9.dat
[16:54:57.530] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C10.dat
[16:54:57.535] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C11.dat
[16:54:57.541] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C12.dat
[16:54:57.546] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C13.dat
[16:54:57.551] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C14.dat
[16:54:57.557] INFO: write trim parameters into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//trimParameters35_C15.dat
[16:54:57.562] INFO: write masked pixels into /home/uicpirepix2/UNL-KU-FPIX-Module-Testing/M-N-2-36_FPIXTest-17C-Nebraska-160623-1221_2016-06-23_12h21m_1466702496/000_FPIXTest_p17//defaultMaskFile.dat
[16:54:57.572] INFO: enter test to run
[16:58:03.397] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:58:03.398] INFO: running: xray
[16:58:03.399] INFO: ----------------------------------------------------------------------
[16:58:03.399] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:58:03.399] INFO: ----------------------------------------------------------------------
[16:58:04.362] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:58:16.426] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[16:58:46.253] INFO: Resuming triggers.
[16:58:58.318] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[16:59:27.658] INFO: Resuming triggers.
[16:59:39.720] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[17:00:08.633] INFO: Resuming triggers.
[17:00:20.696] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[17:00:49.885] INFO: Resuming triggers.
[17:01:01.944] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[17:01:31.226] INFO: Resuming triggers.
[17:01:43.291] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[17:02:12.511] INFO: Resuming triggers.
[17:02:24.570] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[17:02:53.843] INFO: Resuming triggers.
[17:03:05.904] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[17:03:35.155] INFO: Resuming triggers.
[17:03:39.006] INFO: data taking finished, elapsed time: 100 seconds.
[17:03:48.678] INFO: PixTest:: pg_setup set to default.
[17:03:48.682] INFO: PixTestXray::doPhRun() done
[17:03:48.852] INFO: enter test to run
[17:05:40.506] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:05:40.506] INFO: running: xray
[17:05:40.507] INFO: ----------------------------------------------------------------------
[17:05:40.508] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:05:40.508] INFO: ----------------------------------------------------------------------
[17:05:41.471] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:05:48.912] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[17:06:19.066] INFO: Resuming triggers.
[17:06:26.504] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[17:06:56.837] INFO: Resuming triggers.
[17:07:04.278] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[17:07:34.824] INFO: Resuming triggers.
[17:07:42.264] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[17:08:13.338] INFO: Resuming triggers.
[17:08:20.776] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[17:08:51.558] INFO: Resuming triggers.
[17:08:58.997] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[17:09:30.648] INFO: Resuming triggers.
[17:09:38.085] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[17:10:09.351] INFO: Resuming triggers.
[17:10:16.789] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[17:10:47.314] INFO: Resuming triggers.
[17:10:54.752] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[17:11:25.005] INFO: Resuming triggers.
[17:11:32.445] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[17:12:02.580] INFO: Resuming triggers.
[17:12:10.018] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[17:12:40.211] INFO: Resuming triggers.
[17:12:47.649] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[17:13:17.774] INFO: Resuming triggers.
[17:13:25.214] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[17:13:55.430] INFO: Resuming triggers.
[17:13:59.084] INFO: data taking finished, elapsed time: 100 seconds.
[17:14:14.115] INFO: PixTest:: pg_setup set to default.
[17:14:14.118] INFO: PixTestXray::doPhRun() done
[17:14:14.266] INFO: enter test to run
[17:16:22.182] INFO: test: HighRate no parameter change
[17:16:22.182] INFO: running: highrate
[17:16:22.204] INFO: ----------------------------------------------------------------------
[17:16:22.204] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:16:22.204] INFO: ----------------------------------------------------------------------
[17:16:22.371] INFO: Expecting 768 events.
[17:16:23.512] INFO: 768 events read in total (418ms).
[17:16:23.512] INFO: Test took 1287ms.
[17:16:24.315] INFO: Expecting 41600 events.
[17:16:27.402] INFO: 41600 events read in total (2560ms).
[17:16:27.403] INFO: Test took 3865ms.
[17:16:27.433] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:28.168] INFO: Expecting 41600 events.
[17:16:31.337] INFO: 41600 events read in total (2642ms).
[17:16:31.338] INFO: Test took 3888ms.
[17:16:31.369] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:32.097] INFO: Expecting 41600 events.
[17:16:35.267] INFO: 41600 events read in total (2643ms).
[17:16:35.268] INFO: Test took 3882ms.
[17:16:35.298] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:36.033] INFO: Expecting 41600 events.
[17:16:39.225] INFO: 41600 events read in total (2665ms).
[17:16:39.226] INFO: Test took 3912ms.
[17:16:39.256] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:39.989] INFO: Expecting 41600 events.
[17:16:43.194] INFO: 41600 events read in total (2678ms).
[17:16:43.195] INFO: Test took 3922ms.
[17:16:43.225] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:43.954] INFO: Expecting 41600 events.
[17:16:47.156] INFO: 41600 events read in total (2675ms).
[17:16:47.157] INFO: Test took 3914ms.
[17:16:47.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:47.919] INFO: Expecting 41600 events.
[17:16:51.117] INFO: 41600 events read in total (2671ms).
[17:16:51.117] INFO: Test took 3912ms.
[17:16:51.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:51.879] INFO: Expecting 41600 events.
[17:16:55.074] INFO: 41600 events read in total (2668ms).
[17:16:55.075] INFO: Test took 3911ms.
[17:16:55.105] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:55.835] INFO: Expecting 41600 events.
[17:16:59.022] INFO: 41600 events read in total (2660ms).
[17:16:59.023] INFO: Test took 3900ms.
[17:16:59.053] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:16:59.782] INFO: Expecting 41600 events.
[17:17:02.973] INFO: 41600 events read in total (2664ms).
[17:17:02.974] INFO: Test took 3904ms.
[17:17:03.004] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:03.737] INFO: Expecting 41600 events.
[17:17:06.956] INFO: 41600 events read in total (2693ms).
[17:17:06.957] INFO: Test took 3936ms.
[17:17:06.987] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:07.718] INFO: Expecting 41600 events.
[17:17:10.915] INFO: 41600 events read in total (2670ms).
[17:17:10.916] INFO: Test took 3913ms.
[17:17:10.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:11.676] INFO: Expecting 41600 events.
[17:17:14.875] INFO: 41600 events read in total (2672ms).
[17:17:14.876] INFO: Test took 3911ms.
[17:17:14.906] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:15.635] INFO: Expecting 41600 events.
[17:17:18.838] INFO: 41600 events read in total (2676ms).
[17:17:18.839] INFO: Test took 3916ms.
[17:17:18.869] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:19.603] INFO: Expecting 41600 events.
[17:17:22.829] INFO: 41600 events read in total (2700ms).
[17:17:22.830] INFO: Test took 3944ms.
[17:17:22.860] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:23.589] INFO: Expecting 41600 events.
[17:17:26.778] INFO: 41600 events read in total (2662ms).
[17:17:26.779] INFO: Test took 3903ms.
[17:17:26.808] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:27.538] INFO: Expecting 41600 events.
[17:17:30.751] INFO: 41600 events read in total (2686ms).
[17:17:30.752] INFO: Test took 3927ms.
[17:17:30.782] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:31.511] INFO: Expecting 41600 events.
[17:17:34.701] INFO: 41600 events read in total (2663ms).
[17:17:34.701] INFO: Test took 3903ms.
[17:17:34.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:35.464] INFO: Expecting 41600 events.
[17:17:38.614] INFO: 41600 events read in total (2623ms).
[17:17:38.615] INFO: Test took 3866ms.
[17:17:38.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:39.379] INFO: Expecting 41600 events.
[17:17:42.385] INFO: 41600 events read in total (2479ms).
[17:17:42.386] INFO: Test took 3724ms.
[17:17:42.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:17:42.780] INFO: enter test to run
[17:18:11.349] INFO: test: HighRate no parameter change
[17:18:11.349] INFO: running: highrate
[17:18:11.350] INFO: ----------------------------------------------------------------------
[17:18:11.350] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:18:11.350] INFO: ----------------------------------------------------------------------
[17:18:11.972] INFO: Expecting 208000 events.
[17:18:23.613] INFO: 208000 events read in total (11114ms).
[17:18:23.615] INFO: Test took 12253ms.
[17:18:23.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:23.985] INFO: number of dead pixels (per ROC): 3 0 1 0 0 0 0 0 0 0 0 1 0 0 0 0
[17:18:23.985] INFO: number of red-efficiency pixels: 79 37 65 96 110 114 110 96 76 85 98 82 80 49 16 24
[17:18:23.985] INFO: number of X-ray hits detected: 59228 37012 56111 89550 97733 96304 88608 72639 66005 85657 83288 73368 70061 42134 17729 21413
[17:18:23.985] 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:18:23.985] INFO: number of Vcal hits detected: 207772 207961 207884 207899 207885 207884 207890 207889 207923 207913 207898 207869 207919 207951 207984 207976
[17:18:23.985] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[17:18:23.985] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0
[17:18:23.985] INFO: X-ray hit rate [MHz/cm2]: 17.4 10.8 16.4 26.2 28.6 28.2 26.0 21.3 19.3 25.1 24.4 21.5 20.5 12.3 5.2 6.3
[17:18:23.985] INFO: PixTestHighRate::doXPixelAlive() done
[17:18:24.034] INFO: PixTest:: pg_setup set to default.
[17:18:24.043] INFO: enter test to run
[17:18:35.085] INFO: test: HighRate no parameter change
[17:18:35.085] INFO: running: highrate
[17:18:35.086] INFO: ----------------------------------------------------------------------
[17:18:35.086] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:18:35.086] INFO: ----------------------------------------------------------------------
[17:18:35.704] INFO: Expecting 208000 events.
[17:18:48.866] INFO: 208000 events read in total (12635ms).
[17:18:48.871] INFO: Test took 13775ms.
[17:18:49.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:18:49.405] INFO: number of dead pixels (per ROC): 3 0 1 0 0 0 0 0 0 0 0 1 0 0 0 0
[17:18:49.405] INFO: number of red-efficiency pixels: 208 105 153 260 309 324 317 206 181 233 249 176 214 111 45 46
[17:18:49.405] INFO: number of X-ray hits detected: 118362 73721 113644 179036 196927 193448 176643 146109 133974 172287 166747 147912 141887 84131 35752 43506
[17:18:49.405] 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:18:49.405] INFO: number of Vcal hits detected: 207633 207890 207790 207722 207673 207664 207672 207769 207818 207757 207736 207767 207779 207886 207954 207954
[17:18:49.405] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[17:18:49.405] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[17:18:49.405] INFO: X-ray hit rate [MHz/cm2]: 34.7 21.6 33.3 52.5 57.7 56.7 51.8 42.8 39.3 50.5 48.9 43.4 41.6 24.7 10.5 12.8
[17:18:49.405] INFO: PixTestHighRate::doXPixelAlive() done
[17:18:49.451] INFO: PixTest:: pg_setup set to default.
[17:18:49.465] INFO: enter test to run
[17:19:55.076] INFO: test: HighRate no parameter change
[17:19:55.077] INFO: running: highrate
[17:19:55.078] INFO: ----------------------------------------------------------------------
[17:19:55.078] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:19:55.078] INFO: ----------------------------------------------------------------------
[17:19:55.700] INFO: Expecting 208000 events.
[17:20:10.259] INFO: 208000 events read in total (14032ms).
[17:20:10.265] INFO: Test took 15178ms.
[17:20:10.656] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:20:10.985] INFO: number of dead pixels (per ROC): 3 0 1 0 0 0 0 0 0 0 0 1 0 0 0 0
[17:20:10.985] INFO: number of red-efficiency pixels: 382 202 350 569 709 715 730 450 415 523 609 429 454 284 70 87
[17:20:10.985] INFO: number of X-ray hits detected: 179887 113454 173900 274864 300142 295030 269920 222794 203941 263637 254343 226047 215210 129036 55058 66610
[17:20:10.985] 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:20:10.985] INFO: number of Vcal hits detected: 207418 207789 207561 207358 207179 207183 207168 207480 207535 207427 207306 207489 207502 207686 207927 207912
[17:20:10.985] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.6 99.6 99.8 99.8 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[17:20:10.985] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.8 99.7 99.6 99.6 99.6 99.8 99.8 99.7 99.7 99.8 99.8 99.8 100.0 100.0
[17:20:10.985] INFO: X-ray hit rate [MHz/cm2]: 52.7 33.3 51.0 80.6 88.0 86.5 79.1 65.3 59.8 77.3 74.5 66.3 63.1 37.8 16.1 19.5
[17:20:10.985] INFO: PixTestHighRate::doXPixelAlive() done
[17:20:11.032] INFO: PixTest:: pg_setup set to default.
[17:20:11.047] INFO: enter test to run
[17:20:43.188] INFO: test: exit no parameter change
[17:20:43.580] QUIET: Connection to board 33 closed.
[17:20:43.632] INFO: pXar: this is the end, my friend