[13:57:48.791] INFO: *** Welcome to pxar ***
[13:57:48.791] INFO: *** Today: 2016/06/02
[13:57:48.809] INFO: *** Version: v1.9.0-796-gef167-dirty
[13:57:48.809] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//dacParameters35_C15.dat
[13:57:48.859] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:57:48.859] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//defaultMaskFile.dat
[13:57:48.866] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C15.dat
[13:57:48.949] INFO: clk: 4
[13:57:48.949] INFO: ctr: 4
[13:57:48.949] INFO: sda: 19
[13:57:48.949] INFO: tin: 9
[13:57:48.949] INFO: level: 15
[13:57:48.949] INFO: triggerdelay: 0
[13:57:48.949] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[13:57:48.949] INFO: Log level: INFO
[13:57:48.966] QUIET: Connection to board DTB_WREK4U opened.
[13:57:48.969] 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:
------------------------------------------------------
[13:57:48.972] INFO: RPC call hashes of host and DTB match: 398089610
[13:57:50.503] INFO: DUT info:
[13:57:50.503] INFO: The DUT currently contains the following objects:
[13:57:50.503] INFO: 2 TBM Cores tbm08c (2 ON)
[13:57:50.504] INFO: TBM Core alpha (0): 7 registers set
[13:57:50.504] INFO: TBM Core beta (1): 7 registers set
[13:57:50.504] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:57:50.504] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.504] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:57:50.907] INFO: enter 'restricted' command line mode
[13:57:50.907] INFO: enter test to run
[13:58:04.230] INFO: test: PixelAlive no parameter change
[13:58:04.230] INFO: running: pixelalive
[13:58:04.240] INFO: ----------------------------------------------------------------------
[13:58:04.240] 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:58:04.240] INFO: ----------------------------------------------------------------------
[13:58:04.562] INFO: Expecting 41600 events.
[13:58:08.905] INFO: 41600 events read in total (3625ms).
[13:58:09.075] INFO: Test took 4832ms.
[13:58:09.089] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:09.352] INFO: PixTestAlive::aliveTest() done
[13:58:09.352] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:58:09.381] INFO: enter test to run
[13:59:00.446] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:59:00.446] INFO: running: highrate
[13:59:00.446] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:59:00.799] INFO: ----------------------------------------------------------------------
[13:59:00.799] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:59:00.799] INFO: ----------------------------------------------------------------------
[13:59:00.799] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:59:00.799] INFO: edge/corner pixel THR is adjusted
[13:59:00.799] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:59:01.759] INFO: Collecting data for 5 seconds...
[13:59:06.776] INFO: Done with hot pixel readout
[13:59:18.485] INFO: PixTest:: pg_setup set to default.
[13:59:18.486] INFO: 15 hot pixels found in step 0
[13:59:19.500] INFO: Collecting data for 5 seconds...
[13:59:24.517] INFO: Done with hot pixel readout
[13:59:36.215] INFO: PixTest:: pg_setup set to default.
[13:59:36.216] INFO: 12 hot pixels found in step 1
[13:59:37.203] INFO: Collecting data for 5 seconds...
[13:59:42.220] INFO: Done with hot pixel readout
[13:59:53.944] INFO: PixTest:: pg_setup set to default.
[13:59:53.945] INFO: 11 hot pixels found in step 2
[13:59:54.933] INFO: Collecting data for 5 seconds...
[13:59:59.950] INFO: Done with hot pixel readout
[14:00:11.634] INFO: PixTest:: pg_setup set to default.
[14:00:11.634] INFO: 11 hot pixels found in step 3
[14:00:12.623] INFO: Collecting data for 5 seconds...
[14:00:17.640] INFO: Done with hot pixel readout
[14:00:29.299] INFO: PixTest:: pg_setup set to default.
[14:00:29.300] INFO: 9 hot pixels found in step 4
[14:00:30.289] INFO: Collecting data for 5 seconds...
[14:00:35.306] INFO: Done with hot pixel readout
[14:00:47.012] INFO: PixTest:: pg_setup set to default.
[14:00:47.013] INFO: 9 hot pixels found in step 5
[14:00:47.001] INFO: Collecting data for 5 seconds...
[14:00:53.018] INFO: Done with hot pixel readout
[14:01:04.675] INFO: PixTest:: pg_setup set to default.
[14:01:04.676] INFO: 4 hot pixels found in step 6
[14:01:05.663] INFO: Collecting data for 5 seconds...
[14:01:10.680] INFO: Done with hot pixel readout
[14:01:22.400] INFO: PixTest:: pg_setup set to default.
[14:01:22.401] INFO: 1 hot pixels found in step 7
[14:01:23.389] INFO: Collecting data for 5 seconds...
[14:01:28.406] INFO: Done with hot pixel readout
[14:01:40.075] INFO: PixTest:: pg_setup set to default.
[14:01:40.076] INFO: 0 hot pixels found in step 8
[14:01:40.107] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:01:40.111] INFO: PixTest::trimHotPixels() done
[14:01:40.132] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C0.dat
[14:01:40.143] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C1.dat
[14:01:40.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C2.dat
[14:01:40.157] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C3.dat
[14:01:40.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C4.dat
[14:01:40.167] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C5.dat
[14:01:40.172] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C6.dat
[14:01:40.178] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C7.dat
[14:01:40.183] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C8.dat
[14:01:40.188] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C9.dat
[14:01:40.193] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C10.dat
[14:01:40.199] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C11.dat
[14:01:40.204] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C12.dat
[14:01:40.209] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C13.dat
[14:01:40.214] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C14.dat
[14:01:40.219] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C15.dat
[14:01:40.225] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//defaultMaskFile.dat
[14:01:40.237] INFO: enter test to run
[14:02:20.980] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:02:20.981] INFO: running: highrate
[14:02:20.985] INFO: ----------------------------------------------------------------------
[14:02:20.985] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:02:20.985] INFO: ----------------------------------------------------------------------
[14:02:20.985] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:02:20.985] INFO: edge/corner pixel THR is adjusted
[14:02:20.985] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:02:21.943] INFO: Collecting data for 1 seconds...
[14:02:22.946] INFO: Done with hot pixel readout
[14:02:26.972] INFO: PixTest:: pg_setup set to default.
[14:02:26.973] INFO: 0 hot pixels found in step 0
[14:02:26.978] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:02:27.066] INFO: PixTest::trimHotPixels() done
[14:02:27.066] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C0.dat
[14:02:27.079] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C1.dat
[14:02:27.085] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C2.dat
[14:02:27.091] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C3.dat
[14:02:27.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C4.dat
[14:02:27.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C5.dat
[14:02:27.107] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C6.dat
[14:02:27.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C7.dat
[14:02:27.118] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C8.dat
[14:02:27.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C9.dat
[14:02:27.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C10.dat
[14:02:27.134] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C11.dat
[14:02:27.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C12.dat
[14:02:27.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C13.dat
[14:02:27.150] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C14.dat
[14:02:27.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//trimParameters35_C15.dat
[14:02:27.161] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-2-14_FPIXTest-17C-FNAL-160527-1134_2016-05-27_11h34m_1464366856/000_FPIXTest_p17//defaultMaskFile.dat
[14:02:27.172] INFO: enter test to run
[14:03:15.116] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:03:15.116] INFO: running: xray
[14:03:15.117] INFO: ----------------------------------------------------------------------
[14:03:15.117] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:03:15.117] INFO: ----------------------------------------------------------------------
[14:03:16.080] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:03:27.557] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:03:56.961] INFO: Resuming triggers.
[14:04:08.435] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:04:37.759] INFO: Resuming triggers.
[14:04:49.239] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:05:18.676] INFO: Resuming triggers.
[14:05:30.153] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:05:59.575] INFO: Resuming triggers.
[14:06:11.052] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:06:40.488] INFO: Resuming triggers.
[14:06:51.966] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:07:21.332] INFO: Resuming triggers.
[14:07:32.814] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:08:02.254] INFO: Resuming triggers.
[14:08:13.735] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:08:43.048] INFO: Resuming triggers.
[14:08:51.561] INFO: data taking finished, elapsed time: 100 seconds.
[14:09:13.522] INFO: PixTest:: pg_setup set to default.
[14:09:13.525] INFO: PixTestXray::doPhRun() done
[14:09:13.701] INFO: enter test to run
[14:10:06.417] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:10:06.417] INFO: running: xray
[14:10:06.418] INFO: ----------------------------------------------------------------------
[14:10:06.418] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:10:06.418] INFO: ----------------------------------------------------------------------
[14:10:07.389] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:10:14.046] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:10:44.047] INFO: Resuming triggers.
[14:10:50.703] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:11:20.732] INFO: Resuming triggers.
[14:11:27.388] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:11:57.425] INFO: Resuming triggers.
[14:12:04.079] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:12:34.170] INFO: Resuming triggers.
[14:12:40.831] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:13:10.875] INFO: Resuming triggers.
[14:13:17.533] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:13:47.584] INFO: Resuming triggers.
[14:13:54.240] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:14:24.348] INFO: Resuming triggers.
[14:14:31.007] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[14:15:01.058] INFO: Resuming triggers.
[14:15:07.718] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:15:37.598] INFO: Resuming triggers.
[14:15:44.259] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:16:14.334] INFO: Resuming triggers.
[14:16:20.993] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:16:51.034] INFO: Resuming triggers.
[14:16:57.695] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:17:27.851] INFO: Resuming triggers.
[14:17:34.513] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:18:04.469] INFO: Resuming triggers.
[14:18:11.130] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:18:41.216] INFO: Resuming triggers.
[14:18:47.876] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:19:17.942] INFO: Resuming triggers.
[14:19:18.394] INFO: data taking finished, elapsed time: 100 seconds.
[14:19:20.807] INFO: PixTest:: pg_setup set to default.
[14:19:20.811] INFO: PixTestXray::doPhRun() done
[14:19:20.957] INFO: enter test to run
[14:20:10.356] INFO: test: HighRate no parameter change
[14:20:10.356] INFO: running: highrate
[14:20:10.358] INFO: ----------------------------------------------------------------------
[14:20:10.358] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:20:10.358] INFO: ----------------------------------------------------------------------
[14:20:10.498] INFO: Expecting 768 events.
[14:20:11.637] INFO: 768 events read in total (418ms).
[14:20:11.637] INFO: Test took 1273ms.
[14:20:12.440] INFO: Expecting 41600 events.
[14:20:15.468] INFO: 41600 events read in total (2501ms).
[14:20:15.469] INFO: Test took 3825ms.
[14:20:15.501] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:16.229] INFO: Expecting 41600 events.
[14:20:19.408] INFO: 41600 events read in total (2652ms).
[14:20:19.409] INFO: Test took 3890ms.
[14:20:19.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:20.167] INFO: Expecting 41600 events.
[14:20:23.420] INFO: 41600 events read in total (2726ms).
[14:20:23.421] INFO: Test took 3960ms.
[14:20:23.455] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:24.180] INFO: Expecting 41600 events.
[14:20:27.426] INFO: 41600 events read in total (2719ms).
[14:20:27.427] INFO: Test took 3953ms.
[14:20:27.461] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:28.186] INFO: Expecting 41600 events.
[14:20:31.433] INFO: 41600 events read in total (2721ms).
[14:20:31.434] INFO: Test took 3955ms.
[14:20:31.468] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:32.191] INFO: Expecting 41600 events.
[14:20:35.442] INFO: 41600 events read in total (2724ms).
[14:20:35.443] INFO: Test took 3956ms.
[14:20:35.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:36.202] INFO: Expecting 41600 events.
[14:20:39.441] INFO: 41600 events read in total (2712ms).
[14:20:39.442] INFO: Test took 3948ms.
[14:20:39.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:40.203] INFO: Expecting 41600 events.
[14:20:43.459] INFO: 41600 events read in total (2729ms).
[14:20:43.460] INFO: Test took 3966ms.
[14:20:43.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:44.219] INFO: Expecting 41600 events.
[14:20:47.469] INFO: 41600 events read in total (2724ms).
[14:20:47.470] INFO: Test took 3958ms.
[14:20:47.503] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:48.231] INFO: Expecting 41600 events.
[14:20:51.476] INFO: 41600 events read in total (2718ms).
[14:20:51.477] INFO: Test took 3956ms.
[14:20:51.511] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:52.238] INFO: Expecting 41600 events.
[14:20:55.471] INFO: 41600 events read in total (2706ms).
[14:20:55.472] INFO: Test took 3943ms.
[14:20:55.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:20:56.231] INFO: Expecting 41600 events.
[14:20:59.482] INFO: 41600 events read in total (2725ms).
[14:20:59.483] INFO: Test took 3958ms.
[14:20:59.516] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:00.244] INFO: Expecting 41600 events.
[14:21:03.497] INFO: 41600 events read in total (2726ms).
[14:21:03.498] INFO: Test took 3964ms.
[14:21:03.532] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:04.253] INFO: Expecting 41600 events.
[14:21:07.504] INFO: 41600 events read in total (2724ms).
[14:21:07.505] INFO: Test took 3955ms.
[14:21:07.538] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:08.262] INFO: Expecting 41600 events.
[14:21:11.515] INFO: 41600 events read in total (2726ms).
[14:21:11.516] INFO: Test took 3959ms.
[14:21:11.549] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:12.276] INFO: Expecting 41600 events.
[14:21:15.533] INFO: 41600 events read in total (2731ms).
[14:21:15.534] INFO: Test took 3967ms.
[14:21:15.568] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:16.288] INFO: Expecting 41600 events.
[14:21:19.545] INFO: 41600 events read in total (2730ms).
[14:21:19.546] INFO: Test took 3961ms.
[14:21:19.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:20.306] INFO: Expecting 41600 events.
[14:21:23.563] INFO: 41600 events read in total (2730ms).
[14:21:23.564] INFO: Test took 3967ms.
[14:21:23.598] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:24.323] INFO: Expecting 41600 events.
[14:21:27.580] INFO: 41600 events read in total (2730ms).
[14:21:27.581] INFO: Test took 3964ms.
[14:21:27.615] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:28.337] INFO: Expecting 41600 events.
[14:21:31.518] INFO: 41600 events read in total (2654ms).
[14:21:31.519] INFO: Test took 3887ms.
[14:21:31.553] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:31.914] INFO: enter test to run
[14:21:36.876] INFO: test: HighRate no parameter change
[14:21:36.876] INFO: running: highrate
[14:21:36.877] INFO: ----------------------------------------------------------------------
[14:21:36.877] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:21:36.877] INFO: ----------------------------------------------------------------------
[14:21:37.489] INFO: Expecting 208000 events.
[14:21:49.308] INFO: 208000 events read in total (11292ms).
[14:21:49.311] INFO: Test took 12428ms.
[14:21:49.455] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:21:49.706] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:21:49.706] INFO: number of red-efficiency pixels: 66 66 79 133 152 157 162 90 92 119 109 95 81 66 19 31
[14:21:49.706] INFO: number of X-ray hits detected: 59586 43619 69460 109481 115452 118261 119027 82979 80280 92925 90808 77985 78686 49566 21573 25934
[14:21:49.706] 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:21:49.706] INFO: number of Vcal hits detected: 207932 207934 207918 207866 207848 207843 207830 207909 207906 207878 207888 207904 207918 207933 207981 207969
[14:21:49.706] 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
[14:21:49.707] 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
[14:21:49.707] INFO: X-ray hit rate [MHz/cm2]: 17.5 12.8 20.4 32.1 33.8 34.7 34.9 24.3 23.5 27.2 26.6 22.9 23.1 14.5 6.3 7.6
[14:21:49.707] INFO: PixTestHighRate::doXPixelAlive() done
[14:21:49.751] INFO: PixTest:: pg_setup set to default.
[14:21:49.764] INFO: enter test to run
[14:22:20.516] INFO: test: HighRate no parameter change
[14:22:20.516] INFO: running: highrate
[14:22:20.517] INFO: ----------------------------------------------------------------------
[14:22:20.517] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:22:20.517] INFO: ----------------------------------------------------------------------
[14:22:21.134] INFO: Expecting 208000 events.
[14:22:34.761] INFO: 208000 events read in total (13100ms).
[14:22:34.767] INFO: Test took 14240ms.
[14:22:35.055] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:35.355] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:22:35.355] INFO: number of red-efficiency pixels: 159 140 233 510 436 527 629 310 263 398 338 243 235 147 50 65
[14:22:35.355] INFO: number of X-ray hits detected: 125312 92442 144737 229106 241531 247100 247665 174284 167985 195181 189532 163489 164834 104140 45136 54245
[14:22:35.355] 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:22:35.355] INFO: number of Vcal hits detected: 207833 207852 207750 207457 207532 207421 207283 207667 207727 207583 207634 207734 207754 207846 207949 207935
[14:22:35.355] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:22:35.355] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:22:35.355] INFO: X-ray hit rate [MHz/cm2]: 36.7 27.1 42.4 67.2 70.8 72.4 72.6 51.1 49.2 57.2 55.6 47.9 48.3 30.5 13.2 15.9
[14:22:35.355] INFO: PixTestHighRate::doXPixelAlive() done
[14:22:35.409] INFO: PixTest:: pg_setup set to default.
[14:22:35.424] INFO: enter test to run
[14:23:06.123] INFO: test: HighRate no parameter change
[14:23:06.123] INFO: running: highrate
[14:23:06.124] INFO: ----------------------------------------------------------------------
[14:23:06.124] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:23:06.124] INFO: ----------------------------------------------------------------------
[14:23:06.744] INFO: Expecting 208000 events.
[14:23:22.307] INFO: 208000 events read in total (15036ms).
[14:23:22.315] INFO: Test took 16181ms.
[14:23:22.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:23:23.115] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:23:23.115] INFO: number of red-efficiency pixels: 357 324 558 1126 1036 1237 1450 643 638 912 784 636 565 305 75 85
[14:23:23.115] INFO: number of X-ray hits detected: 190541 141121 222272 349120 368325 377393 377536 266039 257974 296794 290625 250802 251863 159183 69833 83817
[14:23:23.115] 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:23:23.116] INFO: number of Vcal hits detected: 207590 207646 207296 206571 206710 206390 206032 207223 207263 206939 207088 207246 207364 207665 207921 207913
[14:23:23.116] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.7 99.4 99.4 99.3 99.2 99.7 99.7 99.5 99.6 99.7 99.7 99.9 100.0 100.0
[14:23:23.116] INFO: Vcal hit overall efficiency (%): 99.8 99.8 99.7 99.3 99.4 99.2 99.1 99.6 99.6 99.5 99.6 99.6 99.7 99.8 100.0 100.0
[14:23:23.116] INFO: X-ray hit rate [MHz/cm2]: 55.8 41.4 65.1 102.3 108.0 110.6 110.7 78.0 75.6 87.0 85.2 73.5 73.8 46.7 20.5 24.6
[14:23:23.116] INFO: PixTestHighRate::doXPixelAlive() done
[14:23:23.172] INFO: PixTest:: pg_setup set to default.
[14:23:23.193] INFO: enter test to run
[14:23:35.363] INFO: test: exit no parameter change
[14:23:35.682] QUIET: Connection to board 32 closed.
[14:23:35.684] INFO: pXar: this is the end, my friend