[12:21:18.620] INFO: *** Welcome to pxar ***
[12:21:18.620] INFO: *** Today: 2016/05/19
[12:21:19.244] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:21:19.244] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//dacParameters35_C15.dat
[12:21:19.267] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:21:19.267] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//defaultMaskFile.dat
[12:21:19.276] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C15.dat
[12:21:19.371] INFO: clk: 4
[12:21:19.371] INFO: ctr: 4
[12:21:19.371] INFO: sda: 19
[12:21:19.371] INFO: tin: 9
[12:21:19.371] INFO: level: 15
[12:21:19.371] INFO: triggerdelay: 0
[12:21:19.371] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:21:19.371] INFO: Log level: INFO
[12:21:19.389] QUIET: Connection to board DTB_WREK4U opened.
[12:21:19.393] 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:
------------------------------------------------------
[12:21:19.395] INFO: RPC call hashes of host and DTB match: 398089610
[12:21:20.927] INFO: DUT info:
[12:21:20.927] INFO: The DUT currently contains the following objects:
[12:21:20.927] INFO: 2 TBM Cores tbm08c (2 ON)
[12:21:20.927] INFO: TBM Core alpha (0): 7 registers set
[12:21:20.927] INFO: TBM Core beta (1): 7 registers set
[12:21:20.927] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:21:20.927] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.927] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.927] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:20.928] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:21:21.332] INFO: enter 'restricted' command line mode
[12:21:21.332] INFO: enter test to run
[12:21:27.569] INFO: test: yPixelAlive no parameter change
[12:21:27.569] INFO: running: ypixelalive
[12:21:27.569] INFO: command ->ypixelalive<- not known, ignored
[12:21:27.569] INFO: enter test to run
[12:21:42.593] INFO: test: PixelAlive no parameter change
[12:21:42.593] INFO: running: pixelalive
[12:21:42.602] INFO: ----------------------------------------------------------------------
[12:21:42.602] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:21:42.602] INFO: ----------------------------------------------------------------------
[12:21:42.920] INFO: Expecting 41600 events.
[12:21:47.051] INFO: 41600 events read in total (3412ms).
[12:21:47.214] INFO: Test took 4609ms.
[12:21:47.225] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:47.487] INFO: PixTestAlive::aliveTest() done
[12:21:47.487] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0
[12:21:47.519] INFO: enter test to run
[12:22:15.241] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:22:15.241] INFO: running: highrate
[12:22:15.241] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:22:16.897] INFO: ----------------------------------------------------------------------
[12:22:16.897] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:22:16.897] INFO: ----------------------------------------------------------------------
[12:22:16.897] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:22:16.897] INFO: edge/corner pixel THR is adjusted
[12:22:16.897] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:22:17.856] INFO: Collecting data for 5 seconds...
[12:22:22.872] INFO: Done with hot pixel readout
[12:22:35.248] INFO: PixTest:: pg_setup set to default.

[12:22:35.286] INFO: 150 hot pixels found in step 0
[12:22:36.289] INFO: Collecting data for 5 seconds...
[12:22:41.306] INFO: Done with hot pixel readout
[12:22:53.453] INFO: PixTest:: pg_setup set to default.



[12:22:53.454] INFO: 128 hot pixels found in step 1
[12:22:54.453] INFO: Collecting data for 5 seconds...
[12:22:59.471] INFO: Done with hot pixel readout
[12:23:11.331] INFO: PixTest:: pg_setup set to default.

[12:23:11.332] INFO: 125 hot pixels found in step 2
[12:23:12.332] INFO: Collecting data for 5 seconds...
[12:23:17.349] INFO: Done with hot pixel readout
[12:23:29.178] INFO: PixTest:: pg_setup set to default.


[12:23:29.179] INFO: 117 hot pixels found in step 3
[12:23:30.180] INFO: Collecting data for 5 seconds...
[12:23:35.197] INFO: Done with hot pixel readout
[12:23:47.204] INFO: PixTest:: pg_setup set to default.

[12:23:47.205] INFO: 88 hot pixels found in step 4
[12:23:48.217] INFO: Collecting data for 5 seconds...
[12:23:53.233] INFO: Done with hot pixel readout
[12:24:05.252] INFO: PixTest:: pg_setup set to default.








[12:24:05.253] INFO: 84 hot pixels found in step 5
[12:24:06.253] INFO: Collecting data for 5 seconds...
[12:24:11.270] INFO: Done with hot pixel readout
[12:24:22.816] INFO: PixTest:: pg_setup set to default.






[12:24:22.818] INFO: 94 hot pixels found in step 6
[12:24:23.822] INFO: Collecting data for 5 seconds...
[12:24:28.839] INFO: Done with hot pixel readout
[12:24:41.042] INFO: PixTest:: pg_setup set to default.








[12:24:41.043] INFO: 79 hot pixels found in step 7
[12:24:42.051] INFO: Collecting data for 5 seconds...
[12:24:47.070] INFO: Done with hot pixel readout
[12:24:59.123] INFO: PixTest:: pg_setup set to default.










[12:24:59.124] INFO: 75 hot pixels found in step 8
[12:25:00.125] INFO: Collecting data for 5 seconds...
[12:25:05.142] INFO: Done with hot pixel readout
[12:25:17.254] INFO: PixTest:: pg_setup set to default.








[12:25:17.255] INFO: 76 hot pixels found in step 9
[12:25:18.258] INFO: Collecting data for 5 seconds...
[12:25:23.276] INFO: Done with hot pixel readout
[12:25:35.377] INFO: PixTest:: pg_setup set to default.












[12:25:35.378] INFO: 67 hot pixels found in step 10
[12:25:36.390] INFO: Collecting data for 5 seconds...
[12:25:41.408] INFO: Done with hot pixel readout
[12:25:53.569] INFO: PixTest:: pg_setup set to default.
















[12:25:53.571] INFO: 79 hot pixels found in step 11
[12:25:54.580] INFO: Collecting data for 5 seconds...
[12:25:59.597] INFO: Done with hot pixel readout
[12:26:11.694] INFO: PixTest:: pg_setup set to default.

















[12:26:11.695] INFO: 70 hot pixels found in step 12
[12:26:12.695] INFO: Collecting data for 5 seconds...
[12:26:17.712] INFO: Done with hot pixel readout
[12:26:29.568] INFO: PixTest:: pg_setup set to default.











[12:26:29.569] INFO: 67 hot pixels found in step 13
[12:26:30.567] INFO: Collecting data for 5 seconds...
[12:26:35.583] INFO: Done with hot pixel readout
[12:26:47.645] INFO: PixTest:: pg_setup set to default.















[12:26:47.647] INFO: 62 hot pixels found in step 14
[12:26:47.696] INFO: 62 hot pixels could not be trimmed and have been masked.
[12:26:47.699] INFO: PixTest::trimHotPixels() done
[12:26:47.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C0.dat
[12:26:47.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C1.dat
[12:26:47.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C2.dat
[12:26:47.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C3.dat
[12:26:47.723] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C4.dat
[12:26:47.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C5.dat
[12:26:47.733] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C6.dat
[12:26:47.739] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C7.dat
[12:26:47.744] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C8.dat
[12:26:47.750] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C9.dat
[12:26:47.755] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C10.dat
[12:26:47.760] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C11.dat
[12:26:47.766] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C12.dat
[12:26:47.771] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C13.dat
[12:26:47.776] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C14.dat
[12:26:47.782] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C15.dat
[12:26:47.787] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//defaultMaskFile.dat
[12:26:47.797] INFO: enter test to run
[12:27:30.039] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:27:30.039] INFO: running: highrate
[12:27:30.043] INFO: ----------------------------------------------------------------------
[12:27:30.043] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:27:30.043] INFO: ----------------------------------------------------------------------
[12:27:30.043] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:27:30.043] INFO: edge/corner pixel THR is adjusted
[12:27:30.044] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:27:30.001] INFO: Collecting data for 1 seconds...
[12:27:32.004] INFO: Done with hot pixel readout
[12:27:36.373] INFO: PixTest:: pg_setup set to default.
[12:27:36.374] INFO: 0 hot pixels found in step 0
[12:27:36.379] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:27:36.448] INFO: PixTest::trimHotPixels() done
[12:27:36.448] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C0.dat
[12:27:36.673] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C1.dat
[12:27:36.682] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C2.dat
[12:27:36.690] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C3.dat
[12:27:36.696] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C4.dat
[12:27:36.701] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C5.dat
[12:27:36.706] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C6.dat
[12:27:36.712] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C7.dat
[12:27:36.717] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C8.dat
[12:27:36.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C9.dat
[12:27:36.727] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C10.dat
[12:27:36.733] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C11.dat
[12:27:36.738] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C12.dat
[12:27:36.743] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C13.dat
[12:27:36.749] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C14.dat
[12:27:36.754] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//trimParameters35_C15.dat
[12:27:36.759] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-M-NR_FPIXTest-17C-FNAL-160516-0917_2016-05-16_09h17m_1463408253/000_FPIXTest_p17//defaultMaskFile.dat
[12:27:36.769] INFO: enter test to run
[12:27:58.518] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:27:58.518] INFO: running: xray
[12:27:58.519] INFO: ----------------------------------------------------------------------
[12:27:58.520] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:27:58.520] INFO: ----------------------------------------------------------------------
[12:27:59.482] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:28:09.947] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[12:28:37.797] INFO: Resuming triggers.
[12:28:48.263] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:29:16.483] INFO: Resuming triggers.
[12:29:26.949] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[12:29:54.996] INFO: Resuming triggers.
[12:30:05.461] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[12:30:30.939] INFO: Resuming triggers.
[12:30:41.401] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[12:31:09.207] INFO: Resuming triggers.
[12:31:19.672] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[12:31:47.453] INFO: Resuming triggers.
[12:31:57.915] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:32:26.413] INFO: Resuming triggers.
[12:32:36.877] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[12:33:04.756] INFO: Resuming triggers.
[12:33:15.220] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:33:43.577] INFO: Resuming triggers.
[12:33:49.729] INFO: data taking finished, elapsed time: 100 seconds.
[12:34:06.719] INFO: PixTest:: pg_setup set to default.
[12:34:06.722] INFO: PixTestXray::doPhRun() done
[12:34:06.861] INFO: enter test to run
[12:34:57.755] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:34:57.755] INFO: running: xray
[12:34:57.757] INFO: ----------------------------------------------------------------------
[12:34:57.757] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:34:57.757] INFO: ----------------------------------------------------------------------
[12:34:58.720] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:35:04.370] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[12:35:32.798] INFO: Resuming triggers.
[12:35:38.447] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:36:07.562] INFO: Resuming triggers.
[12:36:13.215] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[12:36:43.051] INFO: Resuming triggers.
[12:36:48.701] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[12:37:15.199] INFO: Resuming triggers.
[12:37:20.852] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[12:37:51.018] INFO: Resuming triggers.
[12:37:56.670] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:38:26.787] INFO: Resuming triggers.
[12:38:32.436] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[12:39:02.523] INFO: Resuming triggers.
[12:39:08.172] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[12:39:38.911] INFO: Resuming triggers.
[12:39:44.560] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[12:40:15.540] INFO: Resuming triggers.
[12:40:21.190] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[12:40:52.413] INFO: Resuming triggers.
[12:40:58.058] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[12:41:28.858] INFO: Resuming triggers.
[12:41:34.504] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:42:04.682] INFO: Resuming triggers.
[12:42:10.327] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:42:40.531] INFO: Resuming triggers.
[12:42:46.182] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[12:43:16.388] INFO: Resuming triggers.
[12:43:22.036] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[12:43:52.217] INFO: Resuming triggers.
[12:43:57.866] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[12:44:27.366] INFO: Resuming triggers.
[12:44:33.014] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[12:45:02.697] INFO: Resuming triggers.
[12:45:06.998] INFO: data taking finished, elapsed time: 100 seconds.
[12:45:30.158] INFO: PixTest:: pg_setup set to default.
[12:45:30.161] INFO: PixTestXray::doPhRun() done
[12:45:30.313] INFO: enter test to run
[12:46:03.310] INFO: test: HighRate no parameter change
[12:46:03.310] INFO: running: highrate
[12:46:03.326] INFO: ----------------------------------------------------------------------
[12:46:03.326] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:46:03.326] INFO: ----------------------------------------------------------------------
[12:46:03.481] INFO: Expecting 768 events.
[12:46:04.613] INFO: 768 events read in total (416ms).
[12:46:04.614] INFO: Test took 1267ms.
[12:46:05.417] INFO: Expecting 41600 events.
[12:46:08.582] INFO: 41600 events read in total (2638ms).
[12:46:08.583] INFO: Test took 3961ms.
[12:46:08.624] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:09.339] INFO: Expecting 41600 events.
[12:46:12.582] INFO: 41600 events read in total (2716ms).
[12:46:12.583] INFO: Test took 3940ms.
[12:46:12.626] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:13.334] INFO: Expecting 41600 events.
[12:46:16.650] INFO: 41600 events read in total (2789ms).
[12:46:16.651] INFO: Test took 4003ms.
[12:46:16.693] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:17.401] INFO: Expecting 41600 events.
[12:46:20.635] INFO: 41600 events read in total (2708ms).
[12:46:20.636] INFO: Test took 3921ms.
[12:46:20.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:21.385] INFO: Expecting 41600 events.
[12:46:24.595] INFO: 41600 events read in total (2683ms).
[12:46:24.596] INFO: Test took 3896ms.
[12:46:24.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:25.347] INFO: Expecting 41600 events.
[12:46:28.331] INFO: 41600 events read in total (2457ms).
[12:46:28.333] INFO: Test took 3672ms.
[12:46:28.377] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:29.083] INFO: Expecting 41600 events.
[12:46:32.242] INFO: 41600 events read in total (2632ms).
[12:46:32.243] INFO: Test took 3844ms.
[12:46:32.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:32.994] INFO: Expecting 41600 events.
[12:46:36.317] INFO: 41600 events read in total (2796ms).
[12:46:36.318] INFO: Test took 4009ms.
[12:46:36.361] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:37.066] INFO: Expecting 41600 events.
[12:46:40.079] INFO: 41600 events read in total (2486ms).
[12:46:40.081] INFO: Test took 3698ms.
[12:46:40.126] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:40.831] INFO: Expecting 41600 events.
[12:46:44.155] INFO: 41600 events read in total (2797ms).
[12:46:44.157] INFO: Test took 4008ms.
[12:46:44.202] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:44.903] INFO: Expecting 41600 events.
[12:46:48.221] INFO: 41600 events read in total (2791ms).
[12:46:48.222] INFO: Test took 3998ms.
[12:46:48.265] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:48.972] INFO: Expecting 41600 events.
[12:46:52.278] INFO: 41600 events read in total (2779ms).
[12:46:52.280] INFO: Test took 3993ms.
[12:46:52.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:53.032] INFO: Expecting 41600 events.
[12:46:56.332] INFO: 41600 events read in total (2773ms).
[12:46:56.333] INFO: Test took 3989ms.
[12:46:56.376] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:46:57.081] INFO: Expecting 41600 events.
[12:47:00.401] INFO: 41600 events read in total (2793ms).
[12:47:00.403] INFO: Test took 4006ms.
[12:47:00.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:01.154] INFO: Expecting 41600 events.
[12:47:04.475] INFO: 41600 events read in total (2794ms).
[12:47:04.476] INFO: Test took 4008ms.
[12:47:04.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:05.228] INFO: Expecting 41600 events.
[12:47:08.553] INFO: 41600 events read in total (2798ms).
[12:47:08.554] INFO: Test took 4014ms.
[12:47:08.596] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:09.306] INFO: Expecting 41600 events.
[12:47:12.640] INFO: 41600 events read in total (2807ms).
[12:47:12.642] INFO: Test took 4024ms.
[12:47:12.683] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:13.389] INFO: Expecting 41600 events.
[12:47:16.713] INFO: 41600 events read in total (2797ms).
[12:47:16.715] INFO: Test took 4009ms.
[12:47:16.757] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:17.468] INFO: Expecting 41600 events.
[12:47:20.788] INFO: 41600 events read in total (2794ms).
[12:47:20.789] INFO: Test took 4011ms.
[12:47:20.831] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:21.537] INFO: Expecting 41600 events.
[12:47:24.724] INFO: 41600 events read in total (2660ms).
[12:47:24.725] INFO: Test took 3872ms.
[12:47:24.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:25.115] INFO: enter test to run
[12:47:39.142] INFO: test: HighRate no parameter change
[12:47:39.142] INFO: running: highrate
[12:47:39.143] INFO: ----------------------------------------------------------------------
[12:47:39.143] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:47:39.143] INFO: ----------------------------------------------------------------------
[12:47:39.753] INFO: Expecting 208000 events.
[12:47:52.088] INFO: 208000 events read in total (11808ms).
[12:47:52.092] INFO: Test took 12941ms.
[12:47:52.283] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:47:52.551] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[12:47:52.551] INFO: number of red-efficiency pixels: 86 66 100 159 151 167 181 116 126 160 166 184 173 81 30 31
[12:47:52.551] INFO: number of X-ray hits detected: 83657 55403 85273 138655 138155 135435 139920 103313 108759 132536 137099 125646 122427 69759 30971 31680
[12:47:52.551] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:47:52.551] INFO: number of Vcal hits detected: 207912 207932 207896 207830 207846 207829 207817 207881 207870 207837 207781 207804 207819 207917 207968 207969
[12:47:52.551] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:47:52.551] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[12:47:52.551] INFO: X-ray hit rate [MHz/cm2]: 24.5 16.2 25.0 40.6 40.5 39.7 41.0 30.3 31.9 38.8 40.2 36.8 35.9 20.4 9.1 9.3
[12:47:52.551] INFO: PixTestHighRate::doXPixelAlive() done
[12:47:52.596] INFO: PixTest:: pg_setup set to default.
[12:47:52.611] INFO: enter test to run
[12:48:12.117] INFO: test: HighRate no parameter change
[12:48:12.117] INFO: running: highrate
[12:48:12.118] INFO: ----------------------------------------------------------------------
[12:48:12.119] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:48:12.119] INFO: ----------------------------------------------------------------------
[12:48:12.734] INFO: Expecting 208000 events.
[12:48:27.597] INFO: 208000 events read in total (14336ms).
[12:48:27.604] INFO: Test took 15477ms.
[12:48:27.000] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:48:28.341] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0
[12:48:28.341] INFO: number of red-efficiency pixels: 309 160 331 612 630 660 684 418 469 574 608 760 711 343 119 90
[12:48:28.341] INFO: number of X-ray hits detected: 177450 117462 180450 295349 294179 287403 297173 220363 231755 281810 292651 266232 260271 149131 66072 67298
[12:48:28.341] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:48:28.341] INFO: number of Vcal hits detected: 207657 207837 207611 207318 207292 207266 207231 207537 207486 207365 207274 207121 207189 207609 207878 207909
[12:48:28.341] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.7 99.7 99.7 99.7 99.8 99.8 99.7 99.7 99.6 99.6 99.8 99.9 100.0
[12:48:28.341] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.6 99.6 99.8 99.8 99.7 99.7 99.6 99.6 99.8 99.9 100.0
[12:48:28.341] INFO: X-ray hit rate [MHz/cm2]: 52.0 34.4 52.9 86.6 86.2 84.2 87.1 64.6 67.9 82.6 85.8 78.0 76.3 43.7 19.4 19.7
[12:48:28.341] INFO: PixTestHighRate::doXPixelAlive() done
[12:48:28.385] INFO: PixTest:: pg_setup set to default.
[12:48:28.397] INFO: enter test to run
[12:48:53.557] INFO: test: HighRate no parameter change
[12:48:53.557] INFO: running: highrate
[12:48:53.558] INFO: ----------------------------------------------------------------------
[12:48:53.558] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:48:53.558] INFO: ----------------------------------------------------------------------
[12:48:54.184] INFO: Expecting 208000 events.
[12:49:11.695] INFO: 208000 events read in total (16985ms).
[12:49:11.704] INFO: Test took 18136ms.
[12:49:12.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:12.733] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[12:49:12.733] INFO: number of red-efficiency pixels: 654 334 699 1384 1486 1491 1529 917 983 1330 1392 1648 1576 798 184 135
[12:49:12.733] INFO: number of X-ray hits detected: 261751 173530 268513 436477 434854 423142 439913 326226 340943 415688 430441 391359 384164 220663 97759 99926
[12:49:12.733] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:49:12.733] INFO: number of Vcal hits detected: 207176 207634 207003 206125 205987 205969 205836 206775 206720 206188 206088 205556 205829 206928 207808 207861
[12:49:12.733] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.2 99.1 99.1 99.1 99.5 99.4 99.2 99.2 98.9 99.1 99.5 99.9 99.9
[12:49:12.733] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.1 99.0 99.0 99.0 99.4 99.4 99.1 99.1 98.8 99.0 99.5 99.9 99.9
[12:49:12.733] INFO: X-ray hit rate [MHz/cm2]: 76.7 50.9 78.7 127.9 127.5 124.0 128.9 95.6 99.9 121.8 126.2 114.7 112.6 64.7 28.7 29.3
[12:49:12.733] INFO: PixTestHighRate::doXPixelAlive() done
[12:49:12.779] INFO: PixTest:: pg_setup set to default.
[12:49:12.804] INFO: enter test to run
[12:49:16.125] INFO: test: exit no parameter change
[12:49:16.454] QUIET: Connection to board 32 closed.
[12:49:16.464] INFO: pXar: this is the end, my friend