[09:17:10.033] INFO: *** Welcome to pxar ***
[09:17:10.033] INFO: *** Today: 2016/04/04
[09:17:10.077] INFO: *** Version: v1.9.0-793-ge521-dirty
[09:17:10.077] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//dacParameters35_C15.dat
[09:17:10.130] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//tbmParameters_C0b.dat
[09:17:10.131] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//defaultMaskFile.dat
[09:17:10.138] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C15.dat
[09:17:10.300] INFO: clk: 4
[09:17:10.300] INFO: ctr: 4
[09:17:10.300] INFO: sda: 19
[09:17:10.300] INFO: tin: 9
[09:17:10.300] INFO: level: 15
[09:17:10.300] INFO: triggerdelay: 0
[09:17:10.300] QUIET: Instanciating API for pxar v1.9.0+793~ge5211a7
[09:17:10.300] INFO: Log level: INFO
[09:17:10.319] QUIET: Connection to board DTB_WREKRL opened.
[09:17:10.322] 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:
------------------------------------------------------
[09:17:10.325] INFO: RPC call hashes of host and DTB match: 398089610
[09:17:11.871] INFO: DUT info:
[09:17:11.871] INFO: The DUT currently contains the following objects:
[09:17:11.871] INFO: 2 TBM Cores tbm08c (2 ON)
[09:17:11.871] INFO: TBM Core alpha (0): 7 registers set
[09:17:11.871] INFO: TBM Core beta (1): 7 registers set
[09:17:11.871] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[09:17:11.871] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.871] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.871] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.871] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.871] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.871] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.871] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.871] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.871] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.872] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.872] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.872] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.872] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.872] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.872] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:11.872] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[09:17:12.287] INFO: enter 'restricted' command line mode
[09:17:12.287] INFO: enter test to run
[09:17:19.345] INFO: test: PixelAlive no parameter change
[09:17:19.345] INFO: running: pixelalive
[09:17:19.354] INFO: ----------------------------------------------------------------------
[09:17:19.354] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[09:17:19.354] INFO: ----------------------------------------------------------------------
[09:17:19.676] INFO: Expecting 41600 events.
[09:17:24.016] INFO: 41600 events read in total (3621ms).
[09:17:24.182] INFO: Test took 4824ms.
[09:17:24.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:17:24.451] INFO: PixTestAlive::aliveTest() done
[09:17:24.451] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:17:24.482] INFO: enter test to run
[09:18:02.184] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[09:18:02.184] INFO: running: highrate
[09:18:02.185] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[09:18:02.565] INFO: ----------------------------------------------------------------------
[09:18:02.565] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[09:18:02.565] INFO: ----------------------------------------------------------------------
[09:18:02.565] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[09:18:02.565] INFO: edge/corner pixel THR is adjusted
[09:18:02.565] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:18:03.525] INFO: Collecting data for 5 seconds...
[09:18:08.541] INFO: Done with hot pixel readout
[09:18:20.668] INFO: PixTest:: pg_setup set to default.
[09:18:20.669] INFO: 26 hot pixels found in step 0
[09:18:21.662] INFO: Collecting data for 5 seconds...
[09:18:26.678] INFO: Done with hot pixel readout
[09:18:38.815] INFO: PixTest:: pg_setup set to default.
[09:18:38.816] INFO: 27 hot pixels found in step 1
[09:18:39.814] INFO: Collecting data for 5 seconds...
[09:18:44.831] INFO: Done with hot pixel readout
[09:18:56.956] INFO: PixTest:: pg_setup set to default.
[09:18:56.957] INFO: 31 hot pixels found in step 2
[09:18:57.953] INFO: Collecting data for 5 seconds...
[09:19:02.971] INFO: Done with hot pixel readout
[09:19:15.140] INFO: PixTest:: pg_setup set to default.
[09:19:15.141] INFO: 25 hot pixels found in step 3
[09:19:16.138] INFO: Collecting data for 5 seconds...
[09:19:21.155] INFO: Done with hot pixel readout
[09:19:33.305] INFO: PixTest:: pg_setup set to default.


[09:19:33.306] INFO: 22 hot pixels found in step 4
[09:19:34.303] INFO: Collecting data for 5 seconds...
[09:19:39.320] INFO: Done with hot pixel readout
[09:19:51.479] INFO: PixTest:: pg_setup set to default.


[09:19:51.480] INFO: 20 hot pixels found in step 5
[09:19:52.476] INFO: Collecting data for 5 seconds...
[09:19:57.493] INFO: Done with hot pixel readout
[09:20:09.593] INFO: PixTest:: pg_setup set to default.



[09:20:09.594] INFO: 26 hot pixels found in step 6
[09:20:10.591] INFO: Collecting data for 5 seconds...
[09:20:15.608] INFO: Done with hot pixel readout
[09:20:27.739] INFO: PixTest:: pg_setup set to default.


[09:20:27.740] INFO: 19 hot pixels found in step 7
[09:20:28.736] INFO: Collecting data for 5 seconds...
[09:20:33.754] INFO: Done with hot pixel readout
[09:20:45.871] INFO: PixTest:: pg_setup set to default.



[09:20:45.872] INFO: 13 hot pixels found in step 8
[09:20:46.870] INFO: Collecting data for 5 seconds...
[09:20:51.886] INFO: Done with hot pixel readout
[09:21:03.898] INFO: PixTest:: pg_setup set to default.



[09:21:03.899] INFO: 18 hot pixels found in step 9
[09:21:04.897] INFO: Collecting data for 5 seconds...
[09:21:09.913] INFO: Done with hot pixel readout
[09:21:22.041] INFO: PixTest:: pg_setup set to default.



[09:21:22.042] INFO: 12 hot pixels found in step 10
[09:21:23.040] INFO: Collecting data for 5 seconds...
[09:21:28.057] INFO: Done with hot pixel readout
[09:21:39.748] INFO: PixTest:: pg_setup set to default.




[09:21:39.749] INFO: 15 hot pixels found in step 11
[09:21:40.745] INFO: Collecting data for 5 seconds...
[09:21:45.763] INFO: Done with hot pixel readout
[09:21:57.883] INFO: PixTest:: pg_setup set to default.




[09:21:57.884] INFO: 20 hot pixels found in step 12
[09:21:58.880] INFO: Collecting data for 5 seconds...
[09:22:03.897] INFO: Done with hot pixel readout
[09:22:16.010] INFO: PixTest:: pg_setup set to default.



[09:22:16.011] INFO: 9 hot pixels found in step 13
[09:22:17.009] INFO: Collecting data for 5 seconds...
[09:22:22.026] INFO: Done with hot pixel readout
[09:22:33.613] INFO: PixTest:: pg_setup set to default.




[09:22:33.614] INFO: 13 hot pixels found in step 14
[09:22:33.655] INFO: 13 hot pixels could not be trimmed and have been masked.
[09:22:33.659] INFO: PixTest::trimHotPixels() done
[09:22:33.659] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C0.dat
[09:22:33.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C1.dat
[09:22:33.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C2.dat
[09:22:33.678] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C3.dat
[09:22:33.684] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C4.dat
[09:22:33.689] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C5.dat
[09:22:33.694] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C6.dat
[09:22:33.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C7.dat
[09:22:33.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C8.dat
[09:22:33.711] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C9.dat
[09:22:33.716] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C10.dat
[09:22:33.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C11.dat
[09:22:33.727] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C12.dat
[09:22:33.732] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C13.dat
[09:22:33.738] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C14.dat
[09:22:33.744] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C15.dat
[09:22:33.749] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//defaultMaskFile.dat
[09:22:33.759] INFO: enter test to run
[09:26:03.781] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[09:26:03.781] INFO: running: highrate
[09:26:03.785] INFO: ----------------------------------------------------------------------
[09:26:03.786] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[09:26:03.786] INFO: ----------------------------------------------------------------------
[09:26:03.786] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[09:26:03.786] INFO: edge/corner pixel THR is adjusted
[09:26:03.786] INFO: PixTestHighRate::trimHotPixels: step 0...
[09:26:04.743] INFO: Collecting data for 1 seconds...
[09:26:05.747] INFO: Done with hot pixel readout
[09:26:10.174] INFO: PixTest:: pg_setup set to default.
[09:26:10.175] INFO: 0 hot pixels found in step 0
[09:26:10.181] INFO: 0 hot pixels could not be trimmed and have been masked.
[09:26:10.253] INFO: PixTest::trimHotPixels() done
[09:26:10.253] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C0.dat
[09:26:10.258] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C1.dat
[09:26:10.264] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C2.dat
[09:26:10.269] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C3.dat
[09:26:10.275] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C4.dat
[09:26:10.280] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C5.dat
[09:26:10.286] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C6.dat
[09:26:10.291] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C7.dat
[09:26:10.297] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C8.dat
[09:26:10.302] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C9.dat
[09:26:10.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C10.dat
[09:26:10.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C11.dat
[09:26:10.337] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C12.dat
[09:26:10.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C13.dat
[09:26:10.348] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C14.dat
[09:26:10.353] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//trimParameters35_C15.dat
[09:26:10.359] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-20_FPIXTest-17C-FNAL-160331-1154_2016-03-31_11h54m_1459443258/000_FPIXTest_p17//defaultMaskFile.dat
[09:26:10.368] INFO: enter test to run
[09:26:28.389] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[09:26:28.389] INFO: running: xray
[09:26:28.390] INFO: ----------------------------------------------------------------------
[09:26:28.390] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:26:28.390] INFO: ----------------------------------------------------------------------
[09:26:29.355] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:26:40.036] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[09:27:09.628] INFO: Resuming triggers.
[09:27:20.306] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[09:27:50.045] INFO: Resuming triggers.
[09:28:00.725] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[09:28:30.317] INFO: Resuming triggers.
[09:28:40.994] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[09:29:10.674] INFO: Resuming triggers.
[09:29:21.356] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[09:29:50.932] INFO: Resuming triggers.
[09:30:01.613] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[09:30:31.204] INFO: Resuming triggers.
[09:30:41.877] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[09:31:11.493] INFO: Resuming triggers.
[09:31:22.166] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[09:31:51.807] INFO: Resuming triggers.
[09:32:02.483] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[09:32:32.121] INFO: Resuming triggers.
[09:32:36.359] INFO: data taking finished, elapsed time: 100 seconds.
[09:32:48.360] INFO: PixTest:: pg_setup set to default.
[09:32:48.363] INFO: PixTestXray::doPhRun() done
[09:32:48.500] INFO: enter test to run
[09:33:26.626] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[09:33:26.626] INFO: running: xray
[09:33:26.627] INFO: ----------------------------------------------------------------------
[09:33:26.627] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[09:33:26.627] INFO: ----------------------------------------------------------------------
[09:33:27.605] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[09:33:33.487] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[09:34:03.658] INFO: Resuming triggers.
[09:34:09.540] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[09:34:39.628] INFO: Resuming triggers.
[09:34:45.507] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[09:35:15.688] INFO: Resuming triggers.
[09:35:21.569] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[09:35:52.310] INFO: Resuming triggers.
[09:35:58.194] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[09:36:27.331] INFO: Resuming triggers.
[09:36:33.214] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[09:37:03.287] INFO: Resuming triggers.
[09:37:09.170] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[09:37:39.267] INFO: Resuming triggers.
[09:37:45.152] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[09:38:15.257] INFO: Resuming triggers.
[09:38:21.143] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[09:38:51.197] INFO: Resuming triggers.
[09:38:57.083] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[09:39:27.248] INFO: Resuming triggers.
[09:39:33.129] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[09:40:03.264] INFO: Resuming triggers.
[09:40:09.144] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[09:40:39.269] INFO: Resuming triggers.
[09:40:45.148] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[09:41:15.296] INFO: Resuming triggers.
[09:41:21.177] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[09:41:51.235] INFO: Resuming triggers.
[09:41:57.119] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[09:42:27.198] INFO: Resuming triggers.
[09:42:33.076] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[09:43:03.156] INFO: Resuming triggers.
[09:43:09.032] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[09:43:39.079] INFO: Resuming triggers.
[09:43:39.422] INFO: data taking finished, elapsed time: 100 seconds.
[09:43:41.564] INFO: PixTest:: pg_setup set to default.
[09:43:41.567] INFO: PixTestXray::doPhRun() done
[09:43:41.716] INFO: enter test to run
[09:48:36.803] INFO: test: HighRate no parameter change
[09:48:36.803] INFO: running: highrate
[09:48:36.804] INFO: ----------------------------------------------------------------------
[09:48:36.804] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[09:48:36.804] INFO: ----------------------------------------------------------------------
[09:48:36.945] INFO: Expecting 768 events.
[09:48:38.079] INFO: 768 events read in total (418ms).
[09:48:38.080] INFO: Test took 1270ms.
[09:48:38.883] INFO: Expecting 41600 events.
[09:48:42.006] INFO: 41600 events read in total (2597ms).
[09:48:42.007] INFO: Test took 3921ms.
[09:48:42.045] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:42.767] INFO: Expecting 41600 events.
[09:48:46.026] INFO: 41600 events read in total (2732ms).
[09:48:46.027] INFO: Test took 3962ms.
[09:48:46.066] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:46.781] INFO: Expecting 41600 events.
[09:48:50.082] INFO: 41600 events read in total (2774ms).
[09:48:50.083] INFO: Test took 3997ms.
[09:48:50.122] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:50.835] INFO: Expecting 41600 events.
[09:48:54.138] INFO: 41600 events read in total (2777ms).
[09:48:54.139] INFO: Test took 3996ms.
[09:48:54.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:54.890] INFO: Expecting 41600 events.
[09:48:58.186] INFO: 41600 events read in total (2769ms).
[09:48:58.187] INFO: Test took 3989ms.
[09:48:58.226] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:48:58.943] INFO: Expecting 41600 events.
[09:49:02.250] INFO: 41600 events read in total (2780ms).
[09:49:02.251] INFO: Test took 4004ms.
[09:49:02.290] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:02.004] INFO: Expecting 41600 events.
[09:49:06.310] INFO: 41600 events read in total (2780ms).
[09:49:06.311] INFO: Test took 4003ms.
[09:49:06.350] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:07.067] INFO: Expecting 41600 events.
[09:49:10.351] INFO: 41600 events read in total (2758ms).
[09:49:10.352] INFO: Test took 3982ms.
[09:49:10.392] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:11.106] INFO: Expecting 41600 events.
[09:49:14.407] INFO: 41600 events read in total (2774ms).
[09:49:14.408] INFO: Test took 3998ms.
[09:49:14.446] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:15.161] INFO: Expecting 41600 events.
[09:49:18.466] INFO: 41600 events read in total (2778ms).
[09:49:18.467] INFO: Test took 4000ms.
[09:49:18.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:19.221] INFO: Expecting 41600 events.
[09:49:22.522] INFO: 41600 events read in total (2774ms).
[09:49:22.523] INFO: Test took 3997ms.
[09:49:22.562] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:23.279] INFO: Expecting 41600 events.
[09:49:26.577] INFO: 41600 events read in total (2771ms).
[09:49:26.578] INFO: Test took 3997ms.
[09:49:26.617] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:27.333] INFO: Expecting 41600 events.
[09:49:30.647] INFO: 41600 events read in total (2787ms).
[09:49:30.648] INFO: Test took 4011ms.
[09:49:30.687] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:31.404] INFO: Expecting 41600 events.
[09:49:34.703] INFO: 41600 events read in total (2772ms).
[09:49:34.704] INFO: Test took 3996ms.
[09:49:34.743] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:35.460] INFO: Expecting 41600 events.
[09:49:38.770] INFO: 41600 events read in total (2783ms).
[09:49:38.771] INFO: Test took 4009ms.
[09:49:38.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:39.525] INFO: Expecting 41600 events.
[09:49:42.827] INFO: 41600 events read in total (2775ms).
[09:49:42.828] INFO: Test took 3997ms.
[09:49:42.867] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:43.584] INFO: Expecting 41600 events.
[09:49:46.902] INFO: 41600 events read in total (2791ms).
[09:49:46.903] INFO: Test took 4016ms.
[09:49:46.941] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:47.654] INFO: Expecting 41600 events.
[09:49:50.947] INFO: 41600 events read in total (2766ms).
[09:49:50.948] INFO: Test took 3987ms.
[09:49:50.986] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:51.703] INFO: Expecting 41600 events.
[09:49:55.006] INFO: 41600 events read in total (2776ms).
[09:49:55.007] INFO: Test took 4001ms.
[09:49:55.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:55.762] INFO: Expecting 41600 events.
[09:49:58.948] INFO: 41600 events read in total (2659ms).
[09:49:58.950] INFO: Test took 3883ms.
[09:49:58.989] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:49:59.342] INFO: enter test to run
[09:50:51.386] INFO: test: HighRate no parameter change
[09:50:51.386] INFO: running: highrate
[09:50:51.387] INFO: ----------------------------------------------------------------------
[09:50:51.387] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:50:51.387] INFO: ----------------------------------------------------------------------
[09:50:51.997] INFO: Expecting 208000 events.
[09:51:04.174] INFO: 208000 events read in total (11650ms).
[09:51:04.177] INFO: Test took 12779ms.
[09:51:04.344] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:04.606] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:51:04.606] INFO: number of red-efficiency pixels: 102 66 122 141 198 185 169 134 109 124 136 91 115 72 32 38
[09:51:04.606] INFO: number of X-ray hits detected: 77625 50843 80064 127679 134777 138520 141198 96026 86620 114680 115748 98687 98876 60488 26787 33217
[09:51:04.606] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:51:04.606] INFO: number of Vcal hits detected: 207846 207931 207876 207856 207797 207813 207828 207861 207889 207875 207864 207902 207884 207927 207968 207962
[09:51:04.606] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[09:51:04.606] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[09:51:04.606] INFO: X-ray hit rate [MHz/cm2]: 22.8 14.9 23.5 37.4 39.5 40.6 41.4 28.1 25.4 33.6 33.9 28.9 29.0 17.7 7.9 9.7
[09:51:04.606] INFO: PixTestHighRate::doXPixelAlive() done
[09:51:04.653] INFO: PixTest:: pg_setup set to default.
[09:51:04.665] INFO: enter test to run
[09:51:22.746] INFO: test: HighRate no parameter change
[09:51:22.746] INFO: running: highrate
[09:51:22.747] INFO: ----------------------------------------------------------------------
[09:51:22.747] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:51:22.747] INFO: ----------------------------------------------------------------------
[09:51:23.363] INFO: Expecting 208000 events.
[09:51:37.740] INFO: 208000 events read in total (13851ms).
[09:51:37.746] INFO: Test took 14990ms.
[09:51:38.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:51:38.430] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:51:38.430] INFO: number of red-efficiency pixels: 302 167 371 534 720 682 658 501 265 442 443 350 330 216 77 77
[09:51:38.430] INFO: number of X-ray hits detected: 161504 105988 166825 267692 282185 290336 295018 202581 182929 241170 241708 207504 207025 126643 55923 69599
[09:51:38.430] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:51:38.430] INFO: number of Vcal hits detected: 207624 207818 207573 207409 207158 207241 207274 207443 207712 207517 207532 207630 207658 207778 207919 207921
[09:51:38.430] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.6 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[09:51:38.430] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.6 99.7 99.7 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[09:51:38.431] INFO: X-ray hit rate [MHz/cm2]: 47.3 31.1 48.9 78.5 82.7 85.1 86.5 59.4 53.6 70.7 70.8 60.8 60.7 37.1 16.4 20.4
[09:51:38.431] INFO: PixTestHighRate::doXPixelAlive() done
[09:51:38.479] INFO: PixTest:: pg_setup set to default.
[09:51:38.494] INFO: enter test to run
[09:52:20.049] INFO: test: HighRate no parameter change
[09:52:20.049] INFO: running: highrate
[09:52:20.050] INFO: ----------------------------------------------------------------------
[09:52:20.050] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[09:52:20.051] INFO: ----------------------------------------------------------------------
[09:52:20.668] INFO: Expecting 208000 events.
[09:52:37.473] INFO: 208000 events read in total (16278ms).
[09:52:37.481] INFO: Test took 17422ms.
[09:52:38.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[09:52:38.406] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[09:52:38.406] INFO: number of red-efficiency pixels: 731 335 956 1269 1737 1569 1572 1100 619 1001 1058 796 776 502 134 140
[09:52:38.406] INFO: number of X-ray hits detected: 245036 161159 254323 403887 427672 437897 445831 306490 278107 365630 367807 314604 314331 192188 84966 106309
[09:52:38.406] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[09:52:38.406] INFO: number of Vcal hits detected: 207003 207618 206548 206334 205421 205749 205761 206378 207291 206760 206654 207025 207093 207359 207860 207856
[09:52:38.406] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.4 99.3 98.9 99.0 99.0 99.3 99.7 99.5 99.4 99.6 99.6 99.7 99.9 99.9
[09:52:38.406] INFO: Vcal hit overall efficiency (%): 99.5 99.8 99.3 99.2 98.8 98.9 98.9 99.2 99.7 99.4 99.4 99.5 99.6 99.7 99.9 99.9
[09:52:38.406] INFO: X-ray hit rate [MHz/cm2]: 71.8 47.2 74.5 118.4 125.4 128.4 130.7 89.8 81.5 107.2 107.8 92.2 92.1 56.3 24.9 31.2
[09:52:38.406] INFO: PixTestHighRate::doXPixelAlive() done
[09:52:38.454] INFO: PixTest:: pg_setup set to default.
[09:52:38.470] INFO: enter test to run
[09:52:52.945] INFO: test: exit no parameter change
[09:52:53.302] QUIET: Connection to board 33 closed.
[09:52:53.303] INFO: pXar: this is the end, my friend