[16:37:02.967] INFO: *** Welcome to pxar ***
[16:37:02.967] INFO: *** Today: 2016/08/18
[16:37:03.233] INFO: *** Version: v1.9.0-818-g96727
[16:37:03.233] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//dacParameters35_C15.dat
[16:37:03.293] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//tbmParameters_C0b.dat
[16:37:03.293] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//defaultMaskFile.dat
[16:37:03.299] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C15.dat
[16:37:03.414] INFO: clk: 4
[16:37:03.414] INFO: ctr: 4
[16:37:03.414] INFO: sda: 19
[16:37:03.414] INFO: tin: 9
[16:37:03.414] INFO: level: 15
[16:37:03.414] INFO: triggerdelay: 0
[16:37:03.414] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[16:37:03.414] INFO: Log level: INFO
[16:37:03.431] QUIET: Connection to board DTB_WREKRL opened.
[16:37:03.434] 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:37:03.437] INFO: RPC call hashes of host and DTB match: 398089610
[16:37:04.968] INFO: DUT info:
[16:37:04.968] INFO: The DUT currently contains the following objects:
[16:37:04.968] INFO: 2 TBM Cores tbm08c (2 ON)
[16:37:04.968] INFO: TBM Core alpha (0): 7 registers set
[16:37:04.968] INFO: TBM Core beta (1): 7 registers set
[16:37:04.968] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[16:37:04.968] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.968] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.968] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.968] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.968] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:04.969] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[16:37:05.372] INFO: enter 'restricted' command line mode
[16:37:05.372] INFO: enter test to run
[16:37:11.821] INFO: test: PixelAlive no parameter change
[16:37:11.821] INFO: running: pixelalive
[16:37:11.830] INFO: ----------------------------------------------------------------------
[16:37:11.830] 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:37:11.830] INFO: ----------------------------------------------------------------------
[16:37:12.149] INFO: Expecting 41600 events.
[16:37:16.479] INFO: 41600 events read in total (3611ms).
[16:37:16.647] INFO: Test took 4814ms.
[16:37:16.657] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:37:16.937] INFO: PixTestAlive::aliveTest() done
[16:37:16.938] INFO: number of dead pixels (per ROC): 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0 0
[16:37:16.967] INFO: enter test to run
[16:38:21.797] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[16:38:21.797] INFO: running: highrate
[16:38:21.797] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[16:38:22.019] INFO: ----------------------------------------------------------------------
[16:38:22.019] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[16:38:22.019] INFO: ----------------------------------------------------------------------
[16:38:22.019] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[16:38:22.019] INFO: edge/corner pixel THR is adjusted
[16:38:22.019] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:38:22.978] INFO: Collecting data for 5 seconds...
[16:38:27.996] INFO: Done with hot pixel readout
[16:38:39.340] INFO: PixTest:: pg_setup set to default.
[16:38:39.341] INFO: 1 hot pixels found in step 0
[16:38:40.330] INFO: Collecting data for 5 seconds...
[16:38:45.348] INFO: Done with hot pixel readout
[16:38:56.635] INFO: PixTest:: pg_setup set to default.
[16:38:56.635] INFO: 6 hot pixels found in step 1
[16:38:57.629] INFO: Collecting data for 5 seconds...
[16:39:02.647] INFO: Done with hot pixel readout
[16:39:13.542] INFO: PixTest:: pg_setup set to default.
[16:39:13.543] INFO: 2 hot pixels found in step 2
[16:39:14.534] INFO: Collecting data for 5 seconds...
[16:39:19.551] INFO: Done with hot pixel readout
[16:39:31.160] INFO: PixTest:: pg_setup set to default.
[16:39:31.161] INFO: 3 hot pixels found in step 3
[16:39:32.151] INFO: Collecting data for 5 seconds...
[16:39:37.167] INFO: Done with hot pixel readout
[16:39:48.782] INFO: PixTest:: pg_setup set to default.
[16:39:48.783] INFO: 1 hot pixels found in step 4
[16:39:49.774] INFO: Collecting data for 5 seconds...
[16:39:54.791] INFO: Done with hot pixel readout
[16:40:05.602] INFO: PixTest:: pg_setup set to default.
[16:40:05.603] INFO: 3 hot pixels found in step 5
[16:40:06.594] INFO: Collecting data for 5 seconds...
[16:40:11.612] INFO: Done with hot pixel readout
[16:40:23.210] INFO: PixTest:: pg_setup set to default.
[16:40:23.211] INFO: 3 hot pixels found in step 6
[16:40:24.202] INFO: Collecting data for 5 seconds...
[16:40:29.218] INFO: Done with hot pixel readout
[16:40:40.802] INFO: PixTest:: pg_setup set to default.
[16:40:40.803] INFO: 1 hot pixels found in step 7
[16:40:41.794] INFO: Collecting data for 5 seconds...
[16:40:46.812] INFO: Done with hot pixel readout
[16:40:58.408] INFO: PixTest:: pg_setup set to default.
[16:40:58.409] INFO: 0 hot pixels found in step 8
[16:40:58.444] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:40:58.448] INFO: PixTest::trimHotPixels() done
[16:40:58.448] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C0.dat
[16:40:58.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C1.dat
[16:40:58.460] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C2.dat
[16:40:58.467] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C3.dat
[16:40:58.472] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C4.dat
[16:40:58.477] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C5.dat
[16:40:58.482] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C6.dat
[16:40:58.488] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C7.dat
[16:40:58.493] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C8.dat
[16:40:58.498] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C9.dat
[16:40:58.503] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C10.dat
[16:40:58.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C11.dat
[16:40:58.514] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C12.dat
[16:40:58.519] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C13.dat
[16:40:58.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C14.dat
[16:40:58.529] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C15.dat
[16:40:58.535] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//defaultMaskFile.dat
[16:40:58.546] INFO: enter test to run
[16:42:40.571] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:42:40.571] INFO: running: highrate
[16:42:40.576] INFO: ----------------------------------------------------------------------
[16:42:40.576] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:42:40.576] INFO: ----------------------------------------------------------------------
[16:42:40.576] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:42:40.576] INFO: edge/corner pixel THR is adjusted
[16:42:40.576] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:42:41.532] INFO: Collecting data for 1 seconds...
[16:42:42.536] INFO: Done with hot pixel readout
[16:42:46.278] INFO: PixTest:: pg_setup set to default.
[16:42:46.278] INFO: 0 hot pixels found in step 0
[16:42:46.284] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:42:46.379] INFO: PixTest::trimHotPixels() done
[16:42:46.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C0.dat
[16:42:46.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C1.dat
[16:42:46.398] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C2.dat
[16:42:46.404] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C3.dat
[16:42:46.410] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C4.dat
[16:42:46.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C5.dat
[16:42:46.420] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C6.dat
[16:42:46.426] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C7.dat
[16:42:46.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C8.dat
[16:42:46.436] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C9.dat
[16:42:46.443] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C10.dat
[16:42:46.448] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C11.dat
[16:42:46.453] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C12.dat
[16:42:46.459] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C13.dat
[16:42:46.464] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C14.dat
[16:42:46.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C15.dat
[16:42:46.476] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-40_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//defaultMaskFile.dat
[16:42:46.491] INFO: enter test to run
[16:43:17.803] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:43:17.803] INFO: running: xray
[16:43:17.804] INFO: ----------------------------------------------------------------------
[16:43:17.804] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:43:17.804] INFO: ----------------------------------------------------------------------
[16:43:18.768] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:43:30.635] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:44:00.045] INFO: Resuming triggers.
[16:44:11.914] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[16:44:41.073] INFO: Resuming triggers.
[16:44:52.941] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[16:45:22.523] INFO: Resuming triggers.
[16:45:34.391] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[16:46:03.597] INFO: Resuming triggers.
[16:46:15.466] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[16:46:44.718] INFO: Resuming triggers.
[16:46:56.589] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[16:47:25.857] INFO: Resuming triggers.
[16:47:37.724] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[16:48:06.942] INFO: Resuming triggers.
[16:48:18.811] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[16:48:48.009] INFO: Resuming triggers.
[16:48:53.405] INFO: data taking finished, elapsed time: 100 seconds.
[16:49:07.010] INFO: PixTest:: pg_setup set to default.
[16:49:07.013] INFO: PixTestXray::doPhRun() done
[16:49:07.163] INFO: enter test to run
[16:49:50.960] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:49:50.960] INFO: running: xray
[16:49:50.961] INFO: ----------------------------------------------------------------------
[16:49:50.961] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:49:50.961] INFO: ----------------------------------------------------------------------
[16:49:51.926] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:49:58.925] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:50:28.809] INFO: Resuming triggers.
[16:50:35.819] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:51:05.845] INFO: Resuming triggers.
[16:51:12.854] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:51:42.734] INFO: Resuming triggers.
[16:51:49.740] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[16:52:19.750] INFO: Resuming triggers.
[16:52:26.762] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:52:57.464] INFO: Resuming triggers.
[16:53:04.478] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[16:53:34.430] INFO: Resuming triggers.
[16:53:41.445] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[16:54:11.785] INFO: Resuming triggers.
[16:54:18.797] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[16:54:49.614] INFO: Resuming triggers.
[16:54:56.628] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[16:55:26.985] INFO: Resuming triggers.
[16:55:33.001] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[16:56:04.752] INFO: Resuming triggers.
[16:56:11.762] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[16:56:42.671] INFO: Resuming triggers.
[16:56:49.685] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[16:57:20.767] INFO: Resuming triggers.
[16:57:27.781] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[16:57:58.702] INFO: Resuming triggers.
[16:58:05.715] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[16:58:36.178] INFO: Resuming triggers.
[16:58:38.376] INFO: data taking finished, elapsed time: 100 seconds.
[16:58:48.067] INFO: PixTest:: pg_setup set to default.
[16:58:48.070] INFO: PixTestXray::doPhRun() done
[16:58:48.217] INFO: enter test to run
[16:59:24.044] INFO: test: HighRate no parameter change
[16:59:24.044] INFO: running: highrate
[16:59:24.057] INFO: ----------------------------------------------------------------------
[16:59:24.057] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:59:24.057] INFO: ----------------------------------------------------------------------
[16:59:24.212] INFO: Expecting 768 events.
[16:59:25.346] INFO: 768 events read in total (418ms).
[16:59:25.347] INFO: Test took 1270ms.
[16:59:26.150] INFO: Expecting 41600 events.
[16:59:29.130] INFO: 41600 events read in total (2453ms).
[16:59:29.131] INFO: Test took 3778ms.
[16:59:29.162] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:29.898] INFO: Expecting 41600 events.
[16:59:33.023] INFO: 41600 events read in total (2598ms).
[16:59:33.024] INFO: Test took 3847ms.
[16:59:33.054] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:33.786] INFO: Expecting 41600 events.
[16:59:36.971] INFO: 41600 events read in total (2658ms).
[16:59:36.972] INFO: Test took 3900ms.
[16:59:36.004] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:37.734] INFO: Expecting 41600 events.
[16:59:40.942] INFO: 41600 events read in total (2681ms).
[16:59:40.943] INFO: Test took 3923ms.
[16:59:40.975] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:41.704] INFO: Expecting 41600 events.
[16:59:44.904] INFO: 41600 events read in total (2673ms).
[16:59:44.905] INFO: Test took 3914ms.
[16:59:44.937] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:45.666] INFO: Expecting 41600 events.
[16:59:48.874] INFO: 41600 events read in total (2681ms).
[16:59:48.875] INFO: Test took 3922ms.
[16:59:48.908] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:49.633] INFO: Expecting 41600 events.
[16:59:52.846] INFO: 41600 events read in total (2686ms).
[16:59:52.847] INFO: Test took 3921ms.
[16:59:52.878] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:53.606] INFO: Expecting 41600 events.
[16:59:56.829] INFO: 41600 events read in total (2696ms).
[16:59:56.830] INFO: Test took 3934ms.
[16:59:56.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:59:57.591] INFO: Expecting 41600 events.
[17:00:00.790] INFO: 41600 events read in total (2672ms).
[17:00:00.791] INFO: Test took 3912ms.
[17:00:00.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:01.549] INFO: Expecting 41600 events.
[17:00:04.752] INFO: 41600 events read in total (2676ms).
[17:00:04.753] INFO: Test took 3914ms.
[17:00:04.785] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:05.516] INFO: Expecting 41600 events.
[17:00:08.743] INFO: 41600 events read in total (2701ms).
[17:00:08.744] INFO: Test took 3942ms.
[17:00:08.776] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:09.501] INFO: Expecting 41600 events.
[17:00:12.721] INFO: 41600 events read in total (2693ms).
[17:00:12.722] INFO: Test took 3929ms.
[17:00:12.754] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:13.484] INFO: Expecting 41600 events.
[17:00:16.713] INFO: 41600 events read in total (2702ms).
[17:00:16.714] INFO: Test took 3943ms.
[17:00:16.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:17.473] INFO: Expecting 41600 events.
[17:00:20.676] INFO: 41600 events read in total (2677ms).
[17:00:20.677] INFO: Test took 3914ms.
[17:00:20.709] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:21.439] INFO: Expecting 41600 events.
[17:00:24.661] INFO: 41600 events read in total (2695ms).
[17:00:24.662] INFO: Test took 3936ms.
[17:00:24.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:25.424] INFO: Expecting 41600 events.
[17:00:28.641] INFO: 41600 events read in total (2690ms).
[17:00:28.641] INFO: Test took 3931ms.
[17:00:28.673] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:29.399] INFO: Expecting 41600 events.
[17:00:32.613] INFO: 41600 events read in total (2687ms).
[17:00:32.614] INFO: Test took 3924ms.
[17:00:32.646] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:33.373] INFO: Expecting 41600 events.
[17:00:36.586] INFO: 41600 events read in total (2686ms).
[17:00:36.587] INFO: Test took 3923ms.
[17:00:36.619] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:37.349] INFO: Expecting 41600 events.
[17:00:40.557] INFO: 41600 events read in total (2681ms).
[17:00:40.558] INFO: Test took 3921ms.
[17:00:40.590] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:41.317] INFO: Expecting 41600 events.
[17:00:44.418] INFO: 41600 events read in total (2574ms).
[17:00:44.419] INFO: Test took 3811ms.
[17:00:44.451] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:00:44.810] INFO: enter test to run
[17:00:52.772] INFO: test: HighRate no parameter change
[17:00:52.772] INFO: running: highrate
[17:00:52.773] INFO: ----------------------------------------------------------------------
[17:00:52.773] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:00:52.773] INFO: ----------------------------------------------------------------------
[17:00:53.384] INFO: Expecting 208000 events.
[17:01:05.094] INFO: 208000 events read in total (11183ms).
[17:01:05.097] INFO: Test took 12318ms.
[17:01:05.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:01:05.478] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0
[17:01:05.478] INFO: number of red-efficiency pixels: 58 34 82 137 131 127 135 83 77 115 109 78 98 45 22 27
[17:01:05.478] INFO: number of X-ray hits detected: 57724 36566 60654 100350 103671 107904 108925 77160 68537 92133 89828 74482 78086 46450 18548 21520
[17:01:05.478] 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:01:05.478] INFO: number of Vcal hits detected: 207942 207966 207917 207859 207868 207822 207864 207916 207923 207883 207889 207918 207899 207955 207977 207973
[17:01:05.478] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[17:01:05.478] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[17:01:05.478] INFO: X-ray hit rate [MHz/cm2]: 16.9 10.7 17.8 29.4 30.4 31.6 31.9 22.6 20.1 27.0 26.3 21.8 22.9 13.6 5.4 6.3
[17:01:05.478] INFO: PixTestHighRate::doXPixelAlive() done
[17:01:05.526] INFO: PixTest:: pg_setup set to default.
[17:01:05.538] INFO: enter test to run
[17:01:24.395] INFO: test: HighRate no parameter change
[17:01:24.395] INFO: running: highrate
[17:01:24.397] INFO: ----------------------------------------------------------------------
[17:01:24.397] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:01:24.397] INFO: ----------------------------------------------------------------------
[17:01:25.015] INFO: Expecting 208000 events.
[17:01:38.413] INFO: 208000 events read in total (12871ms).
[17:01:38.418] INFO: Test took 14013ms.
[17:01:38.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:01:38.002] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0
[17:01:38.002] INFO: number of red-efficiency pixels: 182 86 267 475 402 462 495 349 218 334 359 235 326 149 52 54
[17:01:38.002] INFO: number of X-ray hits detected: 124037 77784 130429 213778 223113 231145 233312 164314 146520 198179 190665 160955 167162 101081 39557 46838
[17:01:38.003] 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:01:38.003] INFO: number of Vcal hits detected: 207810 207910 207716 207485 207565 207453 207477 207621 207773 207647 207626 207755 207660 207844 207945 207946
[17:01:38.003] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[17:01:38.003] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[17:01:38.003] INFO: X-ray hit rate [MHz/cm2]: 36.4 22.8 38.2 62.7 65.4 67.8 68.4 48.2 42.9 58.1 55.9 47.2 49.0 29.6 11.6 13.7
[17:01:38.003] INFO: PixTestHighRate::doXPixelAlive() done
[17:01:39.053] INFO: PixTest:: pg_setup set to default.
[17:01:39.067] INFO: enter test to run
[17:02:00.803] INFO: test: HighRate no parameter change
[17:02:00.803] INFO: running: highrate
[17:02:00.804] INFO: ----------------------------------------------------------------------
[17:02:00.804] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:02:00.804] INFO: ----------------------------------------------------------------------
[17:02:01.421] INFO: Expecting 208000 events.
[17:02:16.578] INFO: 208000 events read in total (14630ms).
[17:02:16.585] INFO: Test took 15772ms.
[17:02:16.997] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:02:17.338] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0
[17:02:17.338] INFO: number of red-efficiency pixels: 425 171 634 1133 875 950 1176 684 492 685 896 473 711 315 82 88
[17:02:17.338] INFO: number of X-ray hits detected: 185384 116962 195928 322273 335070 347877 351263 248556 220949 297229 287489 242891 250189 150552 60107 71136
[17:02:17.338] 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:02:17.338] INFO: number of Vcal hits detected: 207518 207813 207189 206595 206971 206788 206497 207161 207437 207215 206939 207470 207191 207646 207917 207907
[17:02:17.338] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.6 99.5 99.4 99.6 99.8 99.7 99.5 99.8 99.7 99.8 100.0 100.0
[17:02:17.338] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.3 99.5 99.4 99.3 99.6 99.7 99.6 99.5 99.7 99.6 99.8 100.0 100.0
[17:02:17.338] INFO: X-ray hit rate [MHz/cm2]: 54.3 34.3 57.4 94.5 98.2 102.0 103.0 72.9 64.8 87.1 84.3 71.2 73.3 44.1 17.6 20.9
[17:02:17.338] INFO: PixTestHighRate::doXPixelAlive() done
[17:02:17.389] INFO: PixTest:: pg_setup set to default.
[17:02:17.404] INFO: enter test to run
[17:02:21.819] INFO: test: exit no parameter change
[17:02:22.092] QUIET: Connection to board 33 closed.
[17:02:22.103] INFO: pXar: this is the end, my friend