[13:50:35.177] INFO: *** Welcome to pxar ***
[13:50:35.177] INFO: *** Today: 2016/07/01
[13:50:35.956] INFO: *** Version: v1.9.0-814-g7497
[13:50:35.956] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//dacParameters35_C15.dat
[13:50:36.013] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:50:36.013] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[13:50:36.018] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[13:50:36.113] INFO: clk: 4
[13:50:36.114] INFO: ctr: 4
[13:50:36.114] INFO: sda: 19
[13:50:36.114] INFO: tin: 9
[13:50:36.114] INFO: level: 15
[13:50:36.114] INFO: triggerdelay: 0
[13:50:36.114] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:50:36.114] INFO: Log level: INFO
[13:50:36.130] QUIET: Connection to board DTB_WREKRL opened.
[13:50:36.133] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[13:50:36.136] INFO: RPC call hashes of host and DTB match: 398089610
[13:50:37.673] INFO: DUT info:
[13:50:37.693] INFO: The DUT currently contains the following objects:
[13:50:37.693] INFO: 2 TBM Cores tbm08c (2 ON)
[13:50:37.693] INFO: TBM Core alpha (0): 7 registers set
[13:50:37.693] INFO: TBM Core beta (1): 7 registers set
[13:50:37.694] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:50:37.694] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.694] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.695] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.695] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.695] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.695] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:37.695] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:50:38.098] INFO: enter 'restricted' command line mode
[13:50:38.099] INFO: enter test to run
[13:51:31.222] INFO: test: PixelAlive no parameter change
[13:51:31.222] INFO: running: pixelalive
[13:51:31.282] INFO: ----------------------------------------------------------------------
[13:51:31.282] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:51:31.282] INFO: ----------------------------------------------------------------------
[13:51:31.604] INFO: Expecting 41600 events.
[13:51:35.952] INFO: 41600 events read in total (3630ms).
[13:51:36.117] INFO: Test took 4833ms.
[13:51:36.126] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:51:36.476] INFO: PixTestAlive::aliveTest() done
[13:51:36.477] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 160 1 2 0 0 0 0
[13:51:36.504] INFO: enter test to run
[13:52:20.261] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:52:20.261] INFO: running: highrate
[13:52:20.262] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:52:20.483] INFO: ----------------------------------------------------------------------
[13:52:20.483] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:52:20.483] INFO: ----------------------------------------------------------------------
[13:52:20.483] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:52:20.483] INFO: edge/corner pixel THR is adjusted
[13:52:20.484] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:52:21.443] INFO: Collecting data for 5 seconds...
[13:52:26.459] INFO: Done with hot pixel readout
[13:52:37.620] INFO: PixTest:: pg_setup set to default.
[13:52:37.621] INFO: 11 hot pixels found in step 0
[13:52:38.605] INFO: Collecting data for 5 seconds...
[13:52:43.621] INFO: Done with hot pixel readout
[13:52:54.773] INFO: PixTest:: pg_setup set to default.
[13:52:54.774] INFO: 10 hot pixels found in step 1
[13:52:55.763] INFO: Collecting data for 5 seconds...
[13:53:00.780] INFO: Done with hot pixel readout
[13:53:11.995] INFO: PixTest:: pg_setup set to default.
[13:53:11.996] INFO: 9 hot pixels found in step 2
[13:53:12.983] INFO: Collecting data for 5 seconds...
[13:53:17.002] INFO: Done with hot pixel readout
[13:53:29.191] INFO: PixTest:: pg_setup set to default.

[13:53:29.191] INFO: 8 hot pixels found in step 3
[13:53:30.179] INFO: Collecting data for 5 seconds...
[13:53:35.196] INFO: Done with hot pixel readout
[13:53:46.392] INFO: PixTest:: pg_setup set to default.

[13:53:46.393] INFO: 9 hot pixels found in step 4
[13:53:47.380] INFO: Collecting data for 5 seconds...
[13:53:52.397] INFO: Done with hot pixel readout
[13:54:03.571] INFO: PixTest:: pg_setup set to default.
[13:54:03.572] INFO: 10 hot pixels found in step 5
[13:54:04.561] INFO: Collecting data for 5 seconds...
[13:54:09.578] INFO: Done with hot pixel readout
[13:54:20.707] INFO: PixTest:: pg_setup set to default.
[13:54:20.708] INFO: 6 hot pixels found in step 6
[13:54:21.696] INFO: Collecting data for 5 seconds...
[13:54:26.713] INFO: Done with hot pixel readout
[13:54:37.880] INFO: PixTest:: pg_setup set to default.
[13:54:37.881] INFO: 7 hot pixels found in step 7
[13:54:38.868] INFO: Collecting data for 5 seconds...
[13:54:43.886] INFO: Done with hot pixel readout
[13:54:55.052] INFO: PixTest:: pg_setup set to default.
[13:54:55.053] INFO: 3 hot pixels found in step 8
[13:54:56.042] INFO: Collecting data for 5 seconds...
[13:55:01.060] INFO: Done with hot pixel readout
[13:55:12.234] INFO: PixTest:: pg_setup set to default.
[13:55:12.234] INFO: 4 hot pixels found in step 9
[13:55:13.222] INFO: Collecting data for 5 seconds...
[13:55:18.239] INFO: Done with hot pixel readout
[13:55:29.467] INFO: PixTest:: pg_setup set to default.
[13:55:29.468] INFO: 2 hot pixels found in step 10
[13:55:30.456] INFO: Collecting data for 5 seconds...
[13:55:35.473] INFO: Done with hot pixel readout
[13:55:46.676] INFO: PixTest:: pg_setup set to default.
[13:55:46.677] INFO: 5 hot pixels found in step 11
[13:55:47.664] INFO: Collecting data for 5 seconds...
[13:55:52.682] INFO: Done with hot pixel readout
[13:56:03.846] INFO: PixTest:: pg_setup set to default.
[13:56:03.847] INFO: 5 hot pixels found in step 12
[13:56:04.835] INFO: Collecting data for 5 seconds...
[13:56:09.853] INFO: Done with hot pixel readout
[13:56:21.007] INFO: PixTest:: pg_setup set to default.
[13:56:21.008] INFO: 1 hot pixels found in step 13
[13:56:21.996] INFO: Collecting data for 5 seconds...
[13:56:27.013] INFO: Done with hot pixel readout
[13:56:38.194] INFO: PixTest:: pg_setup set to default.
[13:56:38.194] INFO: 3 hot pixels found in step 14
[13:56:38.226] INFO: 3 hot pixels could not be trimmed and have been masked.
[13:56:38.230] INFO: PixTest::trimHotPixels() done
[13:56:38.230] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat
[13:56:38.236] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C1.dat
[13:56:38.243] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C2.dat
[13:56:38.249] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C3.dat
[13:56:38.254] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C4.dat
[13:56:38.260] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C5.dat
[13:56:38.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C6.dat
[13:56:38.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C7.dat
[13:56:38.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C8.dat
[13:56:38.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C9.dat
[13:56:38.288] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C10.dat
[13:56:38.293] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C11.dat
[13:56:38.299] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C12.dat
[13:56:38.304] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C13.dat
[13:56:38.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C14.dat
[13:56:38.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[13:56:38.321] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[13:56:38.331] INFO: enter test to run
[13:57:50.779] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:57:50.779] INFO: running: highrate
[13:57:50.784] INFO: ----------------------------------------------------------------------
[13:57:50.784] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:57:50.784] INFO: ----------------------------------------------------------------------
[13:57:50.784] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:57:50.784] INFO: edge/corner pixel THR is adjusted
[13:57:50.784] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:57:51.741] INFO: Collecting data for 1 seconds...
[13:57:52.745] INFO: Done with hot pixel readout
[13:57:56.450] INFO: PixTest:: pg_setup set to default.
[13:57:56.451] INFO: 0 hot pixels found in step 0
[13:57:56.457] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:57:56.557] INFO: PixTest::trimHotPixels() done
[13:57:56.557] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C0.dat
[13:57:56.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C1.dat
[13:57:56.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C2.dat
[13:57:56.581] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C3.dat
[13:57:56.586] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C4.dat
[13:57:56.592] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C5.dat
[13:57:56.597] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C6.dat
[13:57:56.603] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C7.dat
[13:57:56.608] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C8.dat
[13:57:56.614] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C9.dat
[13:57:56.619] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C10.dat
[13:57:56.625] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C11.dat
[13:57:56.631] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C12.dat
[13:57:56.636] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C13.dat
[13:57:56.642] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C14.dat
[13:57:56.647] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//trimParameters35_C15.dat
[13:57:56.653] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-41_FPIXTest-17C-FNAL-160624-1117_2016-06-24_11h17m_1466785062/000_FPIXTest_p17//defaultMaskFile.dat
[13:57:56.662] INFO: enter test to run
[13:58:23.539] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:58:23.539] INFO: running: xray
[13:58:23.540] INFO: ----------------------------------------------------------------------
[13:58:23.540] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:58:23.540] INFO: ----------------------------------------------------------------------
[13:58:24.505] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:58:36.584] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:59:06.400] INFO: Resuming triggers.
[13:59:18.482] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[13:59:47.326] INFO: Resuming triggers.
[13:59:59.409] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:00:28.808] INFO: Resuming triggers.
[14:00:40.887] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[14:01:11.175] INFO: Resuming triggers.
[14:01:23.259] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[14:01:53.341] INFO: Resuming triggers.
[14:02:05.423] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:02:34.912] INFO: Resuming triggers.
[14:02:46.997] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[14:03:16.316] INFO: Resuming triggers.
[14:03:28.400] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:03:57.705] INFO: Resuming triggers.
[14:04:01.414] INFO: data taking finished, elapsed time: 100 seconds.
[14:04:10.725] INFO: PixTest:: pg_setup set to default.
[14:04:10.728] INFO: PixTestXray::doPhRun() done
[14:04:10.863] INFO: enter test to run
[14:04:36.737] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:04:36.737] INFO: running: xray
[14:04:36.738] INFO: ----------------------------------------------------------------------
[14:04:36.738] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:04:36.738] INFO: ----------------------------------------------------------------------
[14:04:37.708] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:04:45.196] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:05:15.315] INFO: Resuming triggers.
[14:05:22.800] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:05:52.976] INFO: Resuming triggers.
[14:06:00.463] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:06:30.687] INFO: Resuming triggers.
[14:06:38.173] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[14:07:08.451] INFO: Resuming triggers.
[14:07:15.939] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[14:07:46.132] INFO: Resuming triggers.
[14:07:53.623] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:08:23.768] INFO: Resuming triggers.
[14:08:31.259] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:09:01.455] INFO: Resuming triggers.
[14:09:08.944] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:09:39.065] INFO: Resuming triggers.
[14:09:46.556] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:10:16.715] INFO: Resuming triggers.
[14:10:24.206] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[14:10:54.974] INFO: Resuming triggers.
[14:11:02.467] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[14:11:32.878] INFO: Resuming triggers.
[14:11:40.368] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:12:11.254] INFO: Resuming triggers.
[14:12:18.746] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[14:12:50.270] INFO: Resuming triggers.
[14:12:53.253] INFO: data taking finished, elapsed time: 100 seconds.
[14:13:06.101] INFO: PixTest:: pg_setup set to default.
[14:13:06.104] INFO: PixTestXray::doPhRun() done
[14:13:06.255] INFO: enter test to run
[14:14:07.413] INFO: test: HighRate no parameter change
[14:14:07.413] INFO: running: highrate
[14:14:07.490] INFO: ----------------------------------------------------------------------
[14:14:07.491] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:14:07.491] INFO: ----------------------------------------------------------------------
[14:14:07.655] INFO: Expecting 768 events.
[14:14:08.788] INFO: 768 events read in total (417ms).
[14:14:08.788] INFO: Test took 1268ms.
[14:14:09.591] INFO: Expecting 41600 events.
[14:14:12.651] INFO: 41600 events read in total (2533ms).
[14:14:12.652] INFO: Test took 3837ms.
[14:14:12.680] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:13.415] INFO: Expecting 41600 events.
[14:14:16.581] INFO: 41600 events read in total (2640ms).
[14:14:16.582] INFO: Test took 3885ms.
[14:14:16.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:17.344] INFO: Expecting 41600 events.
[14:14:20.527] INFO: 41600 events read in total (2656ms).
[14:14:20.528] INFO: Test took 3899ms.
[14:14:20.558] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:21.290] INFO: Expecting 41600 events.
[14:14:24.478] INFO: 41600 events read in total (2661ms).
[14:14:24.479] INFO: Test took 3904ms.
[14:14:24.509] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:25.243] INFO: Expecting 41600 events.
[14:14:28.434] INFO: 41600 events read in total (2664ms).
[14:14:28.435] INFO: Test took 3909ms.
[14:14:28.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:29.196] INFO: Expecting 41600 events.
[14:14:32.387] INFO: 41600 events read in total (2664ms).
[14:14:32.388] INFO: Test took 3907ms.
[14:14:32.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:33.152] INFO: Expecting 41600 events.
[14:14:36.369] INFO: 41600 events read in total (2690ms).
[14:14:36.370] INFO: Test took 3935ms.
[14:14:36.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:37.134] INFO: Expecting 41600 events.
[14:14:40.329] INFO: 41600 events read in total (2668ms).
[14:14:40.330] INFO: Test took 3914ms.
[14:14:40.359] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:41.092] INFO: Expecting 41600 events.
[14:14:44.287] INFO: 41600 events read in total (2668ms).
[14:14:44.288] INFO: Test took 3912ms.
[14:14:44.318] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:45.049] INFO: Expecting 41600 events.
[14:14:48.239] INFO: 41600 events read in total (2663ms).
[14:14:48.240] INFO: Test took 3906ms.
[14:14:48.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:49.004] INFO: Expecting 41600 events.
[14:14:52.197] INFO: 41600 events read in total (2666ms).
[14:14:52.198] INFO: Test took 3912ms.
[14:14:52.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:52.962] INFO: Expecting 41600 events.
[14:14:56.159] INFO: 41600 events read in total (2670ms).
[14:14:56.160] INFO: Test took 3915ms.
[14:14:56.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:56.925] INFO: Expecting 41600 events.
[14:15:00.128] INFO: 41600 events read in total (2676ms).
[14:15:00.129] INFO: Test took 3914ms.
[14:15:00.159] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:00.890] INFO: Expecting 41600 events.
[14:15:04.086] INFO: 41600 events read in total (2669ms).
[14:15:04.087] INFO: Test took 3911ms.
[14:15:04.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:04.846] INFO: Expecting 41600 events.
[14:15:08.050] INFO: 41600 events read in total (2677ms).
[14:15:08.051] INFO: Test took 3918ms.
[14:15:08.080] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:08.816] INFO: Expecting 41600 events.
[14:15:12.010] INFO: 41600 events read in total (2667ms).
[14:15:12.011] INFO: Test took 3915ms.
[14:15:12.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:12.775] INFO: Expecting 41600 events.
[14:15:15.981] INFO: 41600 events read in total (2679ms).
[14:15:15.982] INFO: Test took 3925ms.
[14:15:16.012] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:16.744] INFO: Expecting 41600 events.
[14:15:19.920] INFO: 41600 events read in total (2649ms).
[14:15:19.920] INFO: Test took 3892ms.
[14:15:19.950] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:20.684] INFO: Expecting 41600 events.
[14:15:23.864] INFO: 41600 events read in total (2653ms).
[14:15:23.865] INFO: Test took 3899ms.
[14:15:23.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:24.628] INFO: Expecting 41600 events.
[14:15:27.692] INFO: 41600 events read in total (2537ms).
[14:15:27.693] INFO: Test took 3783ms.
[14:15:27.721] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:28.094] INFO: enter test to run
[14:15:44.756] INFO: test: HighRate no parameter change
[14:15:44.756] INFO: running: highrate
[14:15:44.757] INFO: ----------------------------------------------------------------------
[14:15:44.757] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:15:44.757] INFO: ----------------------------------------------------------------------
[14:15:45.379] INFO: Expecting 208000 events.
[14:15:57.010] INFO: 208000 events read in total (11104ms).
[14:15:57.013] INFO: Test took 12246ms.
[14:15:57.133] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:57.377] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 131 1 2 0 0 0 0
[14:15:57.377] INFO: number of red-efficiency pixels: 77 51 49 102 96 106 130 106 99 264 86 65 68 37 17 29
[14:15:57.377] INFO: number of X-ray hits detected: 54115 35701 56082 88177 95378 98037 100221 75798 70471 78253 77855 66597 70504 40478 17128 20666
[14:15:57.377] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:15:57.377] INFO: number of Vcal hits detected: 207922 207948 207949 207894 207903 207892 207866 207844 207900 199936 207864 207837 207930 207962 207983 207967
[14:15:57.378] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 100.0 100.0 99.9 99.9 100.0 99.6 100.0 100.0 100.0 100.0 100.0 100.0
[14:15:57.378] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 100.0 99.9 99.9 99.9 100.0 96.1 99.9 99.9 100.0 100.0 100.0 100.0
[14:15:57.378] INFO: X-ray hit rate [MHz/cm2]: 15.9 10.5 16.4 25.8 28.0 28.7 29.4 22.2 20.7 22.9 22.8 19.5 20.7 11.9 5.0 6.1
[14:15:57.378] INFO: PixTestHighRate::doXPixelAlive() done
[14:15:57.426] INFO: PixTest:: pg_setup set to default.
[14:15:57.438] INFO: enter test to run
[14:17:16.388] INFO: test: HighRate no parameter change
[14:17:16.388] INFO: running: highrate
[14:17:16.389] INFO: ----------------------------------------------------------------------
[14:17:16.389] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:17:16.389] INFO: ----------------------------------------------------------------------
[14:17:17.008] INFO: Expecting 208000 events.
[14:17:30.046] INFO: 208000 events read in total (12511ms).
[14:17:30.050] INFO: Test took 13652ms.
[14:17:30.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:17:30.578] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 60 1 2 0 0 0 0
[14:17:30.578] INFO: number of red-efficiency pixels: 157 119 171 317 327 302 414 288 263 433 286 196 196 114 49 50
[14:17:30.578] INFO: number of X-ray hits detected: 112282 73166 115563 182154 196368 202079 205660 156613 146958 159156 161097 137276 146007 82953 35142 43070
[14:17:30.578] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:17:30.578] INFO: number of Vcal hits detected: 207833 207876 207819 207670 207652 207681 207562 207642 207729 199863 207653 207700 207796 207880 207951 207948
[14:17:30.578] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.9 99.8 99.9 99.9 98.7 99.9 99.9 99.9 99.9 100.0 100.0
[14:17:30.578] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 96.1 99.8 99.9 99.9 99.9 100.0 100.0
[14:17:30.578] INFO: X-ray hit rate [MHz/cm2]: 32.9 21.4 33.9 53.4 57.6 59.2 60.3 45.9 43.1 46.6 47.2 40.2 42.8 24.3 10.3 12.6
[14:17:30.578] INFO: PixTestHighRate::doXPixelAlive() done
[14:17:30.625] INFO: PixTest:: pg_setup set to default.
[14:17:30.640] INFO: enter test to run
[14:18:24.731] INFO: test: HighRate no parameter change
[14:18:24.731] INFO: running: highrate
[14:18:24.732] INFO: ----------------------------------------------------------------------
[14:18:24.732] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:18:24.732] INFO: ----------------------------------------------------------------------
[14:18:25.349] INFO: Expecting 208000 events.
[14:18:39.836] INFO: 208000 events read in total (13960ms).
[14:18:39.842] INFO: Test took 15099ms.
[14:18:40.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:40.533] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 0 63 1 2 0 0 0 0
[14:18:40.533] INFO: number of red-efficiency pixels: 359 204 373 729 783 657 929 616 487 758 597 349 369 263 77 65
[14:18:40.533] INFO: number of X-ray hits detected: 167659 110648 173659 271823 292762 301486 306635 235458 219529 235012 240727 205776 218791 124733 52927 63707
[14:18:40.533] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:18:40.533] INFO: number of Vcal hits detected: 207583 207777 207564 207164 207097 207248 206866 207212 207467 199489 207283 207508 207602 207715 207921 207931
[14:18:40.533] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.7 99.5 99.7 99.8 98.6 99.7 99.8 99.8 99.9 100.0 100.0
[14:18:40.534] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.6 99.6 99.5 99.6 99.7 95.9 99.7 99.8 99.8 99.9 100.0 100.0
[14:18:40.534] INFO: X-ray hit rate [MHz/cm2]: 49.1 32.4 50.9 79.7 85.8 88.4 89.9 69.0 64.3 68.9 70.6 60.3 64.1 36.6 15.5 18.7
[14:18:40.534] INFO: PixTestHighRate::doXPixelAlive() done
[14:18:40.581] INFO: PixTest:: pg_setup set to default.
[14:18:40.599] INFO: enter test to run
[14:19:33.826] INFO: test: exit no parameter change
[14:19:34.136] QUIET: Connection to board 33 closed.
[14:19:34.138] INFO: pXar: this is the end, my friend