[14:37:07.156] INFO: *** Welcome to pxar ***
[14:37:07.156] INFO: *** Today: 2016/05/16
[14:37:07.173] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:37:07.173] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//dacParameters35_C15.dat
[14:37:07.191] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:37:07.191] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//defaultMaskFile.dat
[14:37:07.191] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C15.dat
[14:37:07.273] INFO: clk: 4
[14:37:07.273] INFO: ctr: 4
[14:37:07.273] INFO: sda: 19
[14:37:07.273] INFO: tin: 9
[14:37:07.273] INFO: level: 15
[14:37:07.273] INFO: triggerdelay: 0
[14:37:07.273] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:37:07.273] INFO: Log level: INFO
[14:37:07.291] QUIET: Connection to board DTB_WREKRL opened.
[14:37:07.294] 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:
------------------------------------------------------
[14:37:07.297] INFO: RPC call hashes of host and DTB match: 398089610
[14:37:08.834] INFO: DUT info:
[14:37:08.834] INFO: The DUT currently contains the following objects:
[14:37:08.834] INFO: 2 TBM Cores tbm08c (2 ON)
[14:37:08.834] INFO: TBM Core alpha (0): 7 registers set
[14:37:08.834] INFO: TBM Core beta (1): 7 registers set
[14:37:08.834] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:37:08.834] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.834] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.834] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.834] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.834] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.834] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.834] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.834] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.834] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.835] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.835] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.835] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.835] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.835] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.835] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:08.835] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:37:09.238] INFO: enter 'restricted' command line mode
[14:37:09.238] INFO: enter test to run
[14:37:14.487] INFO: test: PixelAlive no parameter change
[14:37:14.488] INFO: running: pixelalive
[14:37:14.497] INFO: ----------------------------------------------------------------------
[14:37:14.497] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:37:14.497] INFO: ----------------------------------------------------------------------
[14:37:14.815] INFO: Expecting 41600 events.
[14:37:18.860] INFO: 41600 events read in total (3327ms).
[14:37:19.032] INFO: Test took 4533ms.
[14:37:19.038] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:19.299] INFO: PixTestAlive::aliveTest() done
[14:37:19.299] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[14:37:19.325] INFO: enter test to run
[14:38:25.839] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:38:25.839] INFO: running: highrate
[14:38:25.839] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:38:26.054] INFO: ----------------------------------------------------------------------
[14:38:26.054] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:38:26.054] INFO: ----------------------------------------------------------------------
[14:38:26.054] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:38:26.054] INFO: edge/corner pixel THR is adjusted
[14:38:26.054] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:38:27.013] INFO: Collecting data for 5 seconds...
[14:38:32.031] INFO: Done with hot pixel readout
[14:38:43.039] INFO: PixTest:: pg_setup set to default.
[14:38:43.039] INFO: 10 hot pixels found in step 0
[14:38:44.025] INFO: Collecting data for 5 seconds...
[14:38:49.042] INFO: Done with hot pixel readout
[14:39:00.438] INFO: PixTest:: pg_setup set to default.
[14:39:00.439] INFO: 10 hot pixels found in step 1
[14:39:01.428] INFO: Collecting data for 5 seconds...
[14:39:06.445] INFO: Done with hot pixel readout
[14:39:17.886] INFO: PixTest:: pg_setup set to default.
[14:39:17.887] INFO: 10 hot pixels found in step 2
[14:39:18.877] INFO: Collecting data for 5 seconds...
[14:39:23.894] INFO: Done with hot pixel readout
[14:39:35.310] INFO: PixTest:: pg_setup set to default.

[14:39:35.311] INFO: 9 hot pixels found in step 3
[14:39:36.300] INFO: Collecting data for 5 seconds...
[14:39:41.318] INFO: Done with hot pixel readout
[14:39:52.396] INFO: PixTest:: pg_setup set to default.

[14:39:52.397] INFO: 9 hot pixels found in step 4
[14:39:53.386] INFO: Collecting data for 5 seconds...
[14:39:58.403] INFO: Done with hot pixel readout
[14:40:09.603] INFO: PixTest:: pg_setup set to default.

[14:40:09.604] INFO: 6 hot pixels found in step 5
[14:40:10.593] INFO: Collecting data for 5 seconds...
[14:40:15.610] INFO: Done with hot pixel readout
[14:40:26.387] INFO: PixTest:: pg_setup set to default.

[14:40:26.388] INFO: 8 hot pixels found in step 6
[14:40:27.377] INFO: Collecting data for 5 seconds...
[14:40:32.396] INFO: Done with hot pixel readout
[14:40:43.846] INFO: PixTest:: pg_setup set to default.

[14:40:43.847] INFO: 8 hot pixels found in step 7
[14:40:44.838] INFO: Collecting data for 5 seconds...
[14:40:49.856] INFO: Done with hot pixel readout
[14:41:00.779] INFO: PixTest:: pg_setup set to default.

[14:41:00.780] INFO: 5 hot pixels found in step 8
[14:41:01.770] INFO: Collecting data for 5 seconds...
[14:41:06.788] INFO: Done with hot pixel readout
[14:41:17.347] INFO: PixTest:: pg_setup set to default.

[14:41:17.348] INFO: 1 hot pixels found in step 9
[14:41:17.397] INFO: 1 hot pixels could not be trimmed and have been masked.
[14:41:17.403] INFO: PixTest::trimHotPixels() done
[14:41:17.404] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C0.dat
[14:41:17.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C1.dat
[14:41:17.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C2.dat
[14:41:17.430] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C3.dat
[14:41:17.436] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C4.dat
[14:41:17.442] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C5.dat
[14:41:17.447] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C6.dat
[14:41:17.452] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C7.dat
[14:41:17.458] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C8.dat
[14:41:17.463] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C9.dat
[14:41:17.469] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C10.dat
[14:41:17.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C11.dat
[14:41:17.482] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C12.dat
[14:41:17.487] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C13.dat
[14:41:17.492] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C14.dat
[14:41:17.497] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C15.dat
[14:41:17.504] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//defaultMaskFile.dat
[14:41:17.514] INFO: enter test to run
[14:41:45.117] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:41:45.117] INFO: running: highrate
[14:41:45.122] INFO: ----------------------------------------------------------------------
[14:41:45.122] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:41:45.122] INFO: ----------------------------------------------------------------------
[14:41:45.122] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:41:45.122] INFO: edge/corner pixel THR is adjusted
[14:41:45.122] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:41:46.079] INFO: Collecting data for 1 seconds...
[14:41:47.084] INFO: Done with hot pixel readout
[14:41:50.974] INFO: PixTest:: pg_setup set to default.
[14:41:50.975] INFO: 0 hot pixels found in step 0
[14:41:50.981] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:41:51.075] INFO: PixTest::trimHotPixels() done
[14:41:51.075] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C0.dat
[14:41:51.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C1.dat
[14:41:51.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C2.dat
[14:41:51.095] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C3.dat
[14:41:51.101] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C4.dat
[14:41:51.107] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C5.dat
[14:41:51.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C6.dat
[14:41:51.118] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C7.dat
[14:41:51.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C8.dat
[14:41:51.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C9.dat
[14:41:51.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C10.dat
[14:41:51.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C11.dat
[14:41:51.146] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C12.dat
[14:41:51.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C13.dat
[14:41:51.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C14.dat
[14:41:51.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//trimParameters35_C15.dat
[14:41:51.168] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-1-28_FPIXTest-17C-FNAL-160510-1228_2016-05-10_12h35m_1462901749/000_FPIXTest_p17//defaultMaskFile.dat
[14:41:51.177] INFO: enter test to run
[14:42:35.717] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:42:35.717] INFO: running: xray
[14:42:35.718] INFO: ----------------------------------------------------------------------
[14:42:35.718] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:42:35.718] INFO: ----------------------------------------------------------------------
[14:42:36.681] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:42:48.579] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:43:18.500] INFO: Resuming triggers.
[14:43:30.404] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:43:59.520] INFO: Resuming triggers.
[14:44:11.421] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:44:38.992] INFO: Resuming triggers.
[14:44:50.894] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:45:20.099] INFO: Resuming triggers.
[14:45:31.001] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:46:01.149] INFO: Resuming triggers.
[14:46:13.051] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:46:42.168] INFO: Resuming triggers.
[14:46:54.071] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:47:23.311] INFO: Resuming triggers.
[14:47:35.212] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:48:05.048] INFO: Resuming triggers.
[14:48:10.177] INFO: data taking finished, elapsed time: 100 seconds.
[14:48:22.756] INFO: PixTest:: pg_setup set to default.
[14:48:22.759] INFO: PixTestXray::doPhRun() done
[14:48:22.893] INFO: enter test to run
[14:48:41.650] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:48:41.650] INFO: running: xray
[14:48:41.652] INFO: ----------------------------------------------------------------------
[14:48:41.652] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:48:41.652] INFO: ----------------------------------------------------------------------
[14:48:42.615] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:48:49.690] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:49:19.413] INFO: Resuming triggers.
[14:49:26.486] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:49:57.446] INFO: Resuming triggers.
[14:50:04.518] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:50:33.854] INFO: Resuming triggers.
[14:50:40.927] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:51:11.088] INFO: Resuming triggers.
[14:51:18.159] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:51:48.904] INFO: Resuming triggers.
[14:51:55.975] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[14:52:26.604] INFO: Resuming triggers.
[14:52:33.676] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:53:04.538] INFO: Resuming triggers.
[14:53:11.610] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:53:42.761] INFO: Resuming triggers.
[14:53:49.834] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[14:54:20.274] INFO: Resuming triggers.
[14:54:27.347] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:54:57.555] INFO: Resuming triggers.
[14:55:04.628] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:55:34.751] INFO: Resuming triggers.
[14:55:41.824] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[14:56:12.062] INFO: Resuming triggers.
[14:56:19.136] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:56:49.410] INFO: Resuming triggers.
[14:56:56.480] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:57:26.639] INFO: Resuming triggers.
[14:57:27.966] INFO: data taking finished, elapsed time: 100 seconds.
[14:57:33.975] INFO: PixTest:: pg_setup set to default.
[14:57:33.978] INFO: PixTestXray::doPhRun() done
[14:57:34.127] INFO: enter test to run
[14:58:02.278] INFO: test: HighRate no parameter change
[14:58:02.278] INFO: running: highrate
[14:58:02.279] INFO: ----------------------------------------------------------------------
[14:58:02.279] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:58:02.279] INFO: ----------------------------------------------------------------------
[14:58:02.421] INFO: Expecting 768 events.
[14:58:03.555] INFO: 768 events read in total (419ms).
[14:58:03.555] INFO: Test took 1268ms.
[14:58:04.359] INFO: Expecting 41600 events.
[14:58:07.350] INFO: 41600 events read in total (2464ms).
[14:58:07.351] INFO: Test took 3788ms.
[14:58:07.381] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:08.116] INFO: Expecting 41600 events.
[14:58:11.262] INFO: 41600 events read in total (2619ms).
[14:58:11.263] INFO: Test took 3866ms.
[14:58:11.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:12.022] INFO: Expecting 41600 events.
[14:58:15.225] INFO: 41600 events read in total (2676ms).
[14:58:15.226] INFO: Test took 3915ms.
[14:58:15.257] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:15.989] INFO: Expecting 41600 events.
[14:58:19.188] INFO: 41600 events read in total (2672ms).
[14:58:19.189] INFO: Test took 3916ms.
[14:58:19.221] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:19.951] INFO: Expecting 41600 events.
[14:58:23.154] INFO: 41600 events read in total (2676ms).
[14:58:23.155] INFO: Test took 3917ms.
[14:58:23.187] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:23.912] INFO: Expecting 41600 events.
[14:58:27.128] INFO: 41600 events read in total (2689ms).
[14:58:27.129] INFO: Test took 3924ms.
[14:58:27.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:27.886] INFO: Expecting 41600 events.
[14:58:31.101] INFO: 41600 events read in total (2688ms).
[14:58:31.102] INFO: Test took 3924ms.
[14:58:31.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:31.863] INFO: Expecting 41600 events.
[14:58:35.073] INFO: 41600 events read in total (2683ms).
[14:58:35.074] INFO: Test took 3923ms.
[14:58:35.106] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:35.834] INFO: Expecting 41600 events.
[14:58:39.044] INFO: 41600 events read in total (2683ms).
[14:58:39.044] INFO: Test took 3920ms.
[14:58:39.076] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:39.802] INFO: Expecting 41600 events.
[14:58:43.016] INFO: 41600 events read in total (2687ms).
[14:58:43.016] INFO: Test took 3923ms.
[14:58:43.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:43.775] INFO: Expecting 41600 events.
[14:58:46.990] INFO: 41600 events read in total (2688ms).
[14:58:46.991] INFO: Test took 3925ms.
[14:58:47.023] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:47.750] INFO: Expecting 41600 events.
[14:58:50.964] INFO: 41600 events read in total (2688ms).
[14:58:50.965] INFO: Test took 3923ms.
[14:58:50.996] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:51.727] INFO: Expecting 41600 events.
[14:58:54.948] INFO: 41600 events read in total (2694ms).
[14:58:54.949] INFO: Test took 3935ms.
[14:58:54.981] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:55.710] INFO: Expecting 41600 events.
[14:58:58.920] INFO: 41600 events read in total (2683ms).
[14:58:58.921] INFO: Test took 3924ms.
[14:58:58.952] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:59.682] INFO: Expecting 41600 events.
[14:59:02.890] INFO: 41600 events read in total (2681ms).
[14:59:02.891] INFO: Test took 3922ms.
[14:59:02.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:03.653] INFO: Expecting 41600 events.
[14:59:06.884] INFO: 41600 events read in total (2704ms).
[14:59:06.885] INFO: Test took 3945ms.
[14:59:06.917] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:07.644] INFO: Expecting 41600 events.
[14:59:10.857] INFO: 41600 events read in total (2686ms).
[14:59:10.858] INFO: Test took 3924ms.
[14:59:10.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:11.616] INFO: Expecting 41600 events.
[14:59:14.830] INFO: 41600 events read in total (2687ms).
[14:59:14.831] INFO: Test took 3923ms.
[14:59:14.862] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:15.591] INFO: Expecting 41600 events.
[14:59:18.802] INFO: 41600 events read in total (2684ms).
[14:59:18.803] INFO: Test took 3925ms.
[14:59:18.834] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:19.563] INFO: Expecting 41600 events.
[14:59:22.679] INFO: 41600 events read in total (2589ms).
[14:59:22.680] INFO: Test took 3829ms.
[14:59:22.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:23.083] INFO: enter test to run
[14:59:38.334] INFO: test: HighRate no parameter change
[14:59:38.334] INFO: running: highrate
[14:59:38.335] INFO: ----------------------------------------------------------------------
[14:59:38.335] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:59:38.335] INFO: ----------------------------------------------------------------------
[14:59:38.949] INFO: Expecting 208000 events.
[14:59:50.608] INFO: 208000 events read in total (11132ms).
[14:59:50.611] INFO: Test took 12268ms.
[14:59:50.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:50.992] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[14:59:50.992] INFO: number of red-efficiency pixels: 86 63 72 125 121 94 128 68 90 98 88 80 94 56 23 31
[14:59:50.992] INFO: number of X-ray hits detected: 58632 43334 57548 97937 99245 100307 100976 75761 73175 86385 87670 78445 83535 48934 22707 25669
[14:59:50.992] 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:59:50.992] INFO: number of Vcal hits detected: 207910 207937 207926 207873 207875 207901 207853 207931 207908 207900 207911 207920 207902 207944 207976 207871
[14:59:50.992] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[14:59:50.992] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 99.9
[14:59:50.992] INFO: X-ray hit rate [MHz/cm2]: 17.2 12.7 16.9 28.7 29.1 29.4 29.6 22.2 21.4 25.3 25.7 23.0 24.5 14.3 6.7 7.5
[14:59:50.992] INFO: PixTestHighRate::doXPixelAlive() done
[14:59:51.036] INFO: PixTest:: pg_setup set to default.
[14:59:51.044] INFO: enter test to run
[15:00:05.757] INFO: test: HighRate no parameter change
[15:00:05.757] INFO: running: highrate
[15:00:05.758] INFO: ----------------------------------------------------------------------
[15:00:05.758] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:00:05.759] INFO: ----------------------------------------------------------------------
[15:00:06.370] INFO: Expecting 208000 events.
[15:00:19.637] INFO: 208000 events read in total (12740ms).
[15:00:19.642] INFO: Test took 13874ms.
[15:00:19.904] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:20.195] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[15:00:20.195] INFO: number of red-efficiency pixels: 207 122 192 354 361 365 290 239 250 298 246 278 234 165 40 72
[15:00:20.195] INFO: number of X-ray hits detected: 120700 88572 117937 199759 202884 206144 204868 153882 150170 175796 178588 160677 170256 100191 46383 53254
[15:00:20.195] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:00:20.195] INFO: number of Vcal hits detected: 207774 207871 207800 207625 207621 207612 207680 207742 207736 207694 207744 207709 207761 207828 207960 207830
[15:00:20.195] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[15:00:20.195] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9
[15:00:20.195] INFO: X-ray hit rate [MHz/cm2]: 35.4 26.0 34.6 58.6 59.5 60.4 60.0 45.1 44.0 51.5 52.3 47.1 49.9 29.4 13.6 15.6
[15:00:20.195] INFO: PixTestHighRate::doXPixelAlive() done
[15:00:20.243] INFO: PixTest:: pg_setup set to default.
[15:00:20.257] INFO: enter test to run
[15:00:47.493] INFO: test: HighRate no parameter change
[15:00:47.493] INFO: running: highrate
[15:00:47.494] INFO: ----------------------------------------------------------------------
[15:00:47.494] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:00:47.494] INFO: ----------------------------------------------------------------------
[15:00:48.105] INFO: Expecting 208000 events.
[15:01:02.976] INFO: 208000 events read in total (14344ms).
[15:01:02.983] INFO: Test took 15481ms.
[15:01:03.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:03.726] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[15:01:03.726] INFO: number of red-efficiency pixels: 413 267 336 809 934 761 692 533 502 717 532 635 479 341 57 120
[15:01:03.726] INFO: number of X-ray hits detected: 181006 133889 178059 300160 306464 310183 309649 233069 226298 266344 268900 243078 257607 151034 69484 80300
[15:01:03.726] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:01:03.726] INFO: number of Vcal hits detected: 207524 207713 207607 207063 206881 207134 207196 207381 207457 207183 207418 207278 207478 207608 207943 207777
[15:01:03.726] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.6 99.6 99.7 99.8 99.6 99.7 99.7 99.8 99.8 100.0 99.9
[15:01:03.727] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.5 99.5 99.6 99.6 99.7 99.7 99.6 99.7 99.7 99.7 99.8 100.0 99.9
[15:01:03.727] INFO: X-ray hit rate [MHz/cm2]: 53.1 39.2 52.2 88.0 89.8 90.9 90.8 68.3 66.3 78.1 78.8 71.2 75.5 44.3 20.4 23.5
[15:01:03.727] INFO: PixTestHighRate::doXPixelAlive() done
[15:01:03.774] INFO: PixTest:: pg_setup set to default.
[15:01:03.788] INFO: enter test to run
[15:01:14.093] INFO: test: exit no parameter change
[15:01:14.445] QUIET: Connection to board 33 closed.
[15:01:14.446] INFO: pXar: this is the end, my friend