[10:26:54.259] INFO: *** Welcome to pxar ***
[10:26:54.259] INFO: *** Today: 2016/06/23
[10:26:54.828] INFO: *** Version: v1.9.0-814-g7497
[10:26:54.828] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//dacParameters35_C15.dat
[10:26:54.851] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:26:54.851] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[10:26:54.861] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[10:26:54.966] INFO: clk: 4
[10:26:54.966] INFO: ctr: 4
[10:26:54.966] INFO: sda: 19
[10:26:54.966] INFO: tin: 9
[10:26:54.966] INFO: level: 15
[10:26:54.966] INFO: triggerdelay: 0
[10:26:54.966] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[10:26:54.966] INFO: Log level: INFO
[10:26:54.984] QUIET: Connection to board DTB_WREK4U opened.
[10:26:54.987] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[10:26:54.990] INFO: RPC call hashes of host and DTB match: 398089610
[10:26:56.530] INFO: DUT info:
[10:26:56.530] INFO: The DUT currently contains the following objects:
[10:26:56.530] INFO: 2 TBM Cores tbm08c (2 ON)
[10:26:56.530] INFO: TBM Core alpha (0): 7 registers set
[10:26:56.530] INFO: TBM Core beta (1): 7 registers set
[10:26:56.530] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:26:56.530] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.530] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.530] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.530] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.531] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:26:56.934] INFO: enter 'restricted' command line mode
[10:26:56.934] INFO: enter test to run
[10:27:03.690] INFO: test: PixelAlive no parameter change
[10:27:03.691] INFO: running: pixelalive
[10:27:03.700] INFO: ----------------------------------------------------------------------
[10:27:03.700] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:27:03.700] INFO: ----------------------------------------------------------------------
[10:27:04.016] INFO: Expecting 41600 events.
[10:27:08.355] INFO: 41600 events read in total (3620ms).
[10:27:08.524] INFO: Test took 4822ms.
[10:27:08.536] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:27:08.995] INFO: PixTestAlive::aliveTest() done
[10:27:08.995] INFO: number of dead pixels (per ROC): 3 0 1 0 0 0 0 0 2 1 4 0 0 0 0 0
[10:27:09.070] INFO: enter test to run
[10:27:54.410] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:27:54.410] INFO: running: highrate
[10:27:54.452] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:27:54.694] INFO: ----------------------------------------------------------------------
[10:27:54.694] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:27:54.694] INFO: ----------------------------------------------------------------------
[10:27:54.694] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:27:54.694] INFO: edge/corner pixel THR is adjusted
[10:27:54.694] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:27:55.683] INFO: Collecting data for 5 seconds...
[10:28:00.699] INFO: Done with hot pixel readout
[10:28:12.298] INFO: PixTest:: pg_setup set to default.
[10:28:12.299] INFO: 8 hot pixels found in step 0
[10:28:13.312] INFO: Collecting data for 5 seconds...
[10:28:18.328] INFO: Done with hot pixel readout
[10:28:29.846] INFO: PixTest:: pg_setup set to default.
[10:28:29.847] INFO: 7 hot pixels found in step 1
[10:28:30.841] INFO: Collecting data for 5 seconds...
[10:28:35.856] INFO: Done with hot pixel readout
[10:28:47.486] INFO: PixTest:: pg_setup set to default.
[10:28:47.487] INFO: 7 hot pixels found in step 2
[10:28:48.481] INFO: Collecting data for 5 seconds...
[10:28:53.497] INFO: Done with hot pixel readout
[10:29:04.980] INFO: PixTest:: pg_setup set to default.
[10:29:04.981] INFO: 8 hot pixels found in step 3
[10:29:05.974] INFO: Collecting data for 5 seconds...
[10:29:10.991] INFO: Done with hot pixel readout
[10:29:22.534] INFO: PixTest:: pg_setup set to default.
[10:29:22.535] INFO: 8 hot pixels found in step 4
[10:29:23.528] INFO: Collecting data for 5 seconds...
[10:29:28.544] INFO: Done with hot pixel readout
[10:29:40.058] INFO: PixTest:: pg_setup set to default.
[10:29:40.059] INFO: 4 hot pixels found in step 5
[10:29:41.053] INFO: Collecting data for 5 seconds...
[10:29:46.069] INFO: Done with hot pixel readout
[10:29:57.644] INFO: PixTest:: pg_setup set to default.
[10:29:57.645] INFO: 5 hot pixels found in step 6
[10:29:58.638] INFO: Collecting data for 5 seconds...
[10:30:03.654] INFO: Done with hot pixel readout
[10:30:15.216] INFO: PixTest:: pg_setup set to default.
[10:30:15.217] INFO: 5 hot pixels found in step 7
[10:30:16.210] INFO: Collecting data for 5 seconds...
[10:30:21.227] INFO: Done with hot pixel readout
[10:30:32.699] INFO: PixTest:: pg_setup set to default.
[10:30:32.700] INFO: 2 hot pixels found in step 8
[10:30:33.693] INFO: Collecting data for 5 seconds...
[10:30:38.709] INFO: Done with hot pixel readout
[10:30:50.266] INFO: PixTest:: pg_setup set to default.
[10:30:50.266] INFO: 1 hot pixels found in step 9
[10:30:51.260] INFO: Collecting data for 5 seconds...
[10:30:56.276] INFO: Done with hot pixel readout
[10:31:07.811] INFO: PixTest:: pg_setup set to default.
[10:31:07.812] INFO: 0 hot pixels found in step 10
[10:31:07.849] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:31:07.853] INFO: PixTest::trimHotPixels() done
[10:31:07.853] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat
[10:31:07.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C1.dat
[10:31:07.864] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C2.dat
[10:31:07.870] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C3.dat
[10:31:07.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C4.dat
[10:31:07.880] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C5.dat
[10:31:07.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C6.dat
[10:31:07.890] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C7.dat
[10:31:07.895] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C8.dat
[10:31:07.901] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C9.dat
[10:31:07.906] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C10.dat
[10:31:07.911] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C11.dat
[10:31:07.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C12.dat
[10:31:07.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C13.dat
[10:31:07.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C14.dat
[10:31:07.932] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[10:31:07.937] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[10:31:07.955] INFO: enter test to run
[10:31:36.473] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:31:36.473] INFO: running: highrate
[10:31:36.477] INFO: ----------------------------------------------------------------------
[10:31:36.477] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:31:36.477] INFO: ----------------------------------------------------------------------
[10:31:36.477] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:31:36.477] INFO: edge/corner pixel THR is adjusted
[10:31:36.478] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:31:37.435] INFO: Collecting data for 1 seconds...
[10:31:38.439] INFO: Done with hot pixel readout
[10:31:42.347] INFO: PixTest:: pg_setup set to default.
[10:31:42.348] INFO: 0 hot pixels found in step 0
[10:31:42.353] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:31:42.447] INFO: PixTest::trimHotPixels() done
[10:31:42.447] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat
[10:31:42.456] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C1.dat
[10:31:42.462] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C2.dat
[10:31:42.467] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C3.dat
[10:31:42.473] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C4.dat
[10:31:42.478] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C5.dat
[10:31:42.483] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C6.dat
[10:31:42.488] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C7.dat
[10:31:42.493] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C8.dat
[10:31:42.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C9.dat
[10:31:42.504] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C10.dat
[10:31:42.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C11.dat
[10:31:42.515] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C12.dat
[10:31:42.520] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C13.dat
[10:31:42.525] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C14.dat
[10:31:42.531] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[10:31:42.536] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-09_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[10:31:42.546] INFO: enter test to run
[10:32:14.248] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:32:14.248] INFO: running: xray
[10:32:14.250] INFO: ----------------------------------------------------------------------
[10:32:14.250] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:32:14.250] INFO: ----------------------------------------------------------------------
[10:32:15.235] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:32:26.987] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:32:56.249] INFO: Resuming triggers.
[10:33:08.008] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[10:33:37.354] INFO: Resuming triggers.
[10:33:49.109] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[10:34:18.546] INFO: Resuming triggers.
[10:34:30.302] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[10:34:59.843] INFO: Resuming triggers.
[10:35:11.600] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[10:35:41.225] INFO: Resuming triggers.
[10:35:52.981] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[10:36:23.134] INFO: Resuming triggers.
[10:36:34.895] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[10:37:04.828] INFO: Resuming triggers.
[10:37:16.586] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[10:37:45.955] INFO: Resuming triggers.
[10:37:52.249] INFO: data taking finished, elapsed time: 100 seconds.
[10:38:08.145] INFO: PixTest:: pg_setup set to default.
[10:38:08.148] INFO: PixTestXray::doPhRun() done
[10:38:08.369] INFO: enter test to run
[10:38:52.014] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:38:52.014] INFO: running: xray
[10:38:52.015] INFO: ----------------------------------------------------------------------
[10:38:52.015] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:38:52.015] INFO: ----------------------------------------------------------------------
[10:38:52.979] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:38:59.994] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:39:29.934] INFO: Resuming triggers.
[10:39:36.952] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:40:07.061] INFO: Resuming triggers.
[10:40:14.076] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[10:40:44.134] INFO: Resuming triggers.
[10:40:51.152] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[10:41:21.186] INFO: Resuming triggers.
[10:41:28.201] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[10:41:58.337] INFO: Resuming triggers.
[10:42:05.352] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[10:42:35.429] INFO: Resuming triggers.
[10:42:42.440] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[10:43:12.567] INFO: Resuming triggers.
[10:43:19.581] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[10:43:49.577] INFO: Resuming triggers.
[10:43:56.592] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[10:44:26.632] INFO: Resuming triggers.
[10:44:33.647] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[10:45:03.779] INFO: Resuming triggers.
[10:45:10.797] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[10:45:40.001] INFO: Resuming triggers.
[10:45:48.019] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[10:46:18.838] INFO: Resuming triggers.
[10:46:25.856] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[10:46:56.598] INFO: Resuming triggers.
[10:47:03.617] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[10:47:33.853] INFO: Resuming triggers.
[10:47:35.959] INFO: data taking finished, elapsed time: 100 seconds.
[10:47:45.516] INFO: PixTest:: pg_setup set to default.
[10:47:45.519] INFO: PixTestXray::doPhRun() done
[10:47:45.669] INFO: enter test to run
[10:50:13.361] INFO: test: HighRate no parameter change
[10:50:13.361] INFO: running: highrate
[10:50:13.362] INFO: ----------------------------------------------------------------------
[10:50:13.362] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:50:13.363] INFO: ----------------------------------------------------------------------
[10:50:13.514] INFO: Expecting 768 events.
[10:50:14.648] INFO: 768 events read in total (418ms).
[10:50:14.648] INFO: Test took 1269ms.
[10:50:15.451] INFO: Expecting 41600 events.
[10:50:18.535] INFO: 41600 events read in total (2557ms).
[10:50:18.536] INFO: Test took 3881ms.
[10:50:18.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:19.301] INFO: Expecting 41600 events.
[10:50:22.458] INFO: 41600 events read in total (2630ms).
[10:50:22.459] INFO: Test took 3876ms.
[10:50:22.490] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:23.214] INFO: Expecting 41600 events.
[10:50:26.444] INFO: 41600 events read in total (2703ms).
[10:50:26.445] INFO: Test took 3939ms.
[10:50:26.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:27.202] INFO: Expecting 41600 events.
[10:50:30.417] INFO: 41600 events read in total (2688ms).
[10:50:30.418] INFO: Test took 3925ms.
[10:50:30.450] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:31.178] INFO: Expecting 41600 events.
[10:50:34.379] INFO: 41600 events read in total (2674ms).
[10:50:34.380] INFO: Test took 3913ms.
[10:50:34.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:35.141] INFO: Expecting 41600 events.
[10:50:38.364] INFO: 41600 events read in total (2696ms).
[10:50:38.365] INFO: Test took 3935ms.
[10:50:38.397] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:39.127] INFO: Expecting 41600 events.
[10:50:42.333] INFO: 41600 events read in total (2679ms).
[10:50:42.334] INFO: Test took 3920ms.
[10:50:42.366] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:43.094] INFO: Expecting 41600 events.
[10:50:46.316] INFO: 41600 events read in total (2695ms).
[10:50:46.317] INFO: Test took 3933ms.
[10:50:46.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:47.073] INFO: Expecting 41600 events.
[10:50:50.286] INFO: 41600 events read in total (2686ms).
[10:50:50.287] INFO: Test took 3920ms.
[10:50:50.319] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:51.042] INFO: Expecting 41600 events.
[10:50:54.215] INFO: 41600 events read in total (2646ms).
[10:50:54.216] INFO: Test took 3879ms.
[10:50:54.248] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:54.978] INFO: Expecting 41600 events.
[10:50:58.188] INFO: 41600 events read in total (2684ms).
[10:50:58.189] INFO: Test took 3924ms.
[10:50:58.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:50:58.952] INFO: Expecting 41600 events.
[10:51:02.145] INFO: 41600 events read in total (2667ms).
[10:51:02.146] INFO: Test took 3907ms.
[10:51:02.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:02.901] INFO: Expecting 41600 events.
[10:51:06.116] INFO: 41600 events read in total (2688ms).
[10:51:06.117] INFO: Test took 3922ms.
[10:51:06.149] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:06.874] INFO: Expecting 41600 events.
[10:51:10.077] INFO: 41600 events read in total (2676ms).
[10:51:10.078] INFO: Test took 3911ms.
[10:51:10.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:10.838] INFO: Expecting 41600 events.
[10:51:14.027] INFO: 41600 events read in total (2662ms).
[10:51:14.028] INFO: Test took 3900ms.
[10:51:14.059] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:14.789] INFO: Expecting 41600 events.
[10:51:18.008] INFO: 41600 events read in total (2692ms).
[10:51:18.008] INFO: Test took 3931ms.
[10:51:18.041] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:18.766] INFO: Expecting 41600 events.
[10:51:21.985] INFO: 41600 events read in total (2692ms).
[10:51:21.986] INFO: Test took 3928ms.
[10:51:22.017] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:22.748] INFO: Expecting 41600 events.
[10:51:25.964] INFO: 41600 events read in total (2689ms).
[10:51:25.965] INFO: Test took 3930ms.
[10:51:25.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:26.722] INFO: Expecting 41600 events.
[10:51:29.923] INFO: 41600 events read in total (2675ms).
[10:51:29.924] INFO: Test took 3909ms.
[10:51:29.955] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:30.682] INFO: Expecting 41600 events.
[10:51:33.766] INFO: 41600 events read in total (2557ms).
[10:51:33.767] INFO: Test took 3795ms.
[10:51:33.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:34.172] INFO: enter test to run
[10:51:37.777] INFO: test: HighRate no parameter change
[10:51:37.777] INFO: running: highrate
[10:51:37.778] INFO: ----------------------------------------------------------------------
[10:51:37.778] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:51:37.778] INFO: ----------------------------------------------------------------------
[10:51:38.394] INFO: Expecting 208000 events.
[10:51:50.130] INFO: 208000 events read in total (11209ms).
[10:51:50.133] INFO: Test took 12349ms.
[10:51:50.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:51:50.516] INFO: number of dead pixels (per ROC): 3 0 1 0 0 0 0 0 2 1 4 0 0 0 0 0
[10:51:50.516] INFO: number of red-efficiency pixels: 85 39 71 94 109 139 129 112 79 102 103 83 114 49 16 26
[10:51:50.516] INFO: number of X-ray hits detected: 57692 37955 59636 92126 98751 102536 102342 73139 74731 99062 93713 80225 85324 49881 18900 22398
[10:51:50.516] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:51:50.516] INFO: number of Vcal hits detected: 207766 207961 207879 207905 207888 207859 207866 207886 207822 207848 207698 207915 207885 207949 207982 207974
[10:51:50.516] 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 99.9 100.0 100.0 100.0
[10:51:50.516] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[10:51:50.516] INFO: X-ray hit rate [MHz/cm2]: 16.9 11.1 17.5 27.0 28.9 30.1 30.0 21.4 21.9 29.0 27.5 23.5 25.0 14.6 5.5 6.6
[10:51:50.516] INFO: PixTestHighRate::doXPixelAlive() done
[10:51:50.565] INFO: PixTest:: pg_setup set to default.
[10:51:50.575] INFO: enter test to run
[10:52:12.784] INFO: test: HighRate no parameter change
[10:52:12.784] INFO: running: highrate
[10:52:12.785] INFO: ----------------------------------------------------------------------
[10:52:12.785] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:52:12.786] INFO: ----------------------------------------------------------------------
[10:52:13.401] INFO: Expecting 208000 events.
[10:52:26.736] INFO: 208000 events read in total (12809ms).
[10:52:26.740] INFO: Test took 13944ms.
[10:52:27.007] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:52:27.299] INFO: number of dead pixels (per ROC): 3 0 1 0 0 0 0 0 2 1 4 0 0 0 0 0
[10:52:27.300] INFO: number of red-efficiency pixels: 186 87 227 296 326 455 330 289 181 287 288 295 319 176 48 54
[10:52:27.300] INFO: number of X-ray hits detected: 119672 78299 124827 190663 205398 211033 212582 151958 154641 204667 196193 167080 177351 103705 38958 45905
[10:52:27.300] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:52:27.300] INFO: number of Vcal hits detected: 207649 207909 207710 207688 207656 207496 207649 207688 207715 207652 207504 207689 207662 207808 207951 207946
[10:52:27.300] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.8 99.9 100.0 100.0
[10:52:27.300] INFO: Vcal hit overall efficiency (%): 99.8 100.0 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[10:52:27.300] INFO: X-ray hit rate [MHz/cm2]: 35.1 23.0 36.6 55.9 60.2 61.9 62.3 44.5 45.3 60.0 57.5 49.0 52.0 30.4 11.4 13.5
[10:52:27.300] INFO: PixTestHighRate::doXPixelAlive() done
[10:52:27.351] INFO: PixTest:: pg_setup set to default.
[10:52:27.365] INFO: enter test to run
[10:52:48.888] INFO: test: HighRate no parameter change
[10:52:48.888] INFO: running: highrate
[10:52:48.889] INFO: ----------------------------------------------------------------------
[10:52:48.889] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:52:48.889] INFO: ----------------------------------------------------------------------
[10:52:49.506] INFO: Expecting 208000 events.
[10:53:04.608] INFO: 208000 events read in total (14575ms).
[10:53:04.615] INFO: Test took 15716ms.
[10:53:05.024] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:53:05.362] INFO: number of dead pixels (per ROC): 3 0 1 0 0 0 0 0 2 1 4 0 0 0 0 0
[10:53:05.362] INFO: number of red-efficiency pixels: 445 217 474 665 697 1073 835 610 436 727 695 697 706 395 79 87
[10:53:05.362] INFO: number of X-ray hits detected: 181641 119232 189005 288496 310800 319013 321936 231322 235305 311291 297766 252832 269542 158157 59157 70932
[10:53:05.362] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:53:05.362] INFO: number of Vcal hits detected: 207340 207770 207384 207246 207211 206655 207009 207267 207425 207139 207025 207197 207193 207526 207920 207912
[10:53:05.362] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.4 99.6 99.7 99.8 99.6 99.7 99.7 99.6 99.8 100.0 100.0
[10:53:05.362] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.6 99.6 99.4 99.5 99.6 99.7 99.6 99.5 99.6 99.6 99.8 100.0 100.0
[10:53:05.362] INFO: X-ray hit rate [MHz/cm2]: 53.2 34.9 55.4 84.6 91.1 93.5 94.4 67.8 69.0 91.2 87.3 74.1 79.0 46.4 17.3 20.8
[10:53:05.362] INFO: PixTestHighRate::doXPixelAlive() done
[10:53:05.408] INFO: PixTest:: pg_setup set to default.
[10:53:05.421] INFO: enter test to run
[10:53:19.160] INFO: test: exit no parameter change
[10:53:19.489] QUIET: Connection to board 32 closed.
[10:53:19.491] INFO: pXar: this is the end, my friend