[13:32:23.703] INFO: *** Welcome to pxar ***
[13:32:23.703] INFO: *** Today: 2016/06/30
[13:32:23.778] INFO: *** Version: v1.9.0-814-g7497
[13:32:23.778] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//dacParameters35_C15.dat
[13:32:23.828] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:32:23.828] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//defaultMaskFile.dat
[13:32:23.828] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C15.dat
[13:32:23.941] INFO: clk: 4
[13:32:23.941] INFO: ctr: 4
[13:32:23.941] INFO: sda: 19
[13:32:23.941] INFO: tin: 9
[13:32:23.941] INFO: level: 15
[13:32:23.941] INFO: triggerdelay: 0
[13:32:23.941] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:32:23.941] INFO: Log level: INFO
[13:32:23.957] QUIET: Connection to board DTB_WREKRL opened.
[13:32:23.960] 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:
------------------------------------------------------
[13:32:23.963] INFO: RPC call hashes of host and DTB match: 398089610
[13:32:25.498] INFO: DUT info:
[13:32:25.498] INFO: The DUT currently contains the following objects:
[13:32:25.498] INFO: 2 TBM Cores tbm08c (2 ON)
[13:32:25.498] INFO: TBM Core alpha (0): 7 registers set
[13:32:25.498] INFO: TBM Core beta (1): 7 registers set
[13:32:25.498] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:32:25.498] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.498] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.498] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.498] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.499] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:32:25.902] INFO: enter 'restricted' command line mode
[13:32:25.902] INFO: enter test to run
[13:32:37.058] INFO: test: PixelAlive no parameter change
[13:32:37.058] INFO: running: pixelalive
[13:32:37.067] INFO: ----------------------------------------------------------------------
[13:32:37.067] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:32:37.067] INFO: ----------------------------------------------------------------------
[13:32:37.390] INFO: Expecting 41600 events.
[13:32:41.766] INFO: 41600 events read in total (3657ms).
[13:32:41.935] INFO: Test took 4865ms.
[13:32:41.950] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:32:42.214] INFO: PixTestAlive::aliveTest() done
[13:32:42.214] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:32:42.249] INFO: enter test to run
[13:33:08.602] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:33:08.602] INFO: running: highrate
[13:33:08.602] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:33:08.819] INFO: ----------------------------------------------------------------------
[13:33:08.819] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:33:08.819] INFO: ----------------------------------------------------------------------
[13:33:08.819] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:33:08.819] INFO: edge/corner pixel THR is adjusted
[13:33:08.819] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:33:09.777] INFO: Collecting data for 5 seconds...
[13:33:14.795] INFO: Done with hot pixel readout
[13:33:26.372] INFO: PixTest:: pg_setup set to default.
[13:33:26.373] INFO: 19 hot pixels found in step 0
[13:33:27.384] INFO: Collecting data for 5 seconds...
[13:33:32.403] INFO: Done with hot pixel readout
[13:33:43.994] INFO: PixTest:: pg_setup set to default.
[13:33:43.995] INFO: 15 hot pixels found in step 1
[13:33:44.984] INFO: Collecting data for 5 seconds...
[13:33:50.002] INFO: Done with hot pixel readout
[13:34:01.068] INFO: PixTest:: pg_setup set to default.
[13:34:01.069] INFO: 16 hot pixels found in step 2
[13:34:02.058] INFO: Collecting data for 5 seconds...
[13:34:07.076] INFO: Done with hot pixel readout
[13:34:18.228] INFO: PixTest:: pg_setup set to default.
[13:34:18.229] INFO: 16 hot pixels found in step 3
[13:34:19.228] INFO: Collecting data for 5 seconds...
[13:34:24.246] INFO: Done with hot pixel readout
[13:34:35.999] INFO: PixTest:: pg_setup set to default.

[13:34:35.000] INFO: 15 hot pixels found in step 4
[13:34:36.988] INFO: Collecting data for 5 seconds...
[13:34:42.006] INFO: Done with hot pixel readout
[13:34:53.829] INFO: PixTest:: pg_setup set to default.


[13:34:53.830] INFO: 10 hot pixels found in step 5
[13:34:54.818] INFO: Collecting data for 5 seconds...
[13:34:59.837] INFO: Done with hot pixel readout
[13:35:11.740] INFO: PixTest:: pg_setup set to default.


[13:35:11.741] INFO: 11 hot pixels found in step 6
[13:35:12.730] INFO: Collecting data for 5 seconds...
[13:35:17.749] INFO: Done with hot pixel readout
[13:35:29.682] INFO: PixTest:: pg_setup set to default.



[13:35:29.683] INFO: 10 hot pixels found in step 7
[13:35:30.671] INFO: Collecting data for 5 seconds...
[13:35:35.690] INFO: Done with hot pixel readout
[13:35:47.523] INFO: PixTest:: pg_setup set to default.



[13:35:47.524] INFO: 10 hot pixels found in step 8
[13:35:48.512] INFO: Collecting data for 5 seconds...
[13:35:53.531] INFO: Done with hot pixel readout
[13:36:05.471] INFO: PixTest:: pg_setup set to default.






[13:36:05.472] INFO: 13 hot pixels found in step 9
[13:36:06.460] INFO: Collecting data for 5 seconds...
[13:36:11.476] INFO: Done with hot pixel readout
[13:36:23.254] INFO: PixTest:: pg_setup set to default.





[13:36:23.255] INFO: 11 hot pixels found in step 10
[13:36:24.244] INFO: Collecting data for 5 seconds...
[13:36:29.261] INFO: Done with hot pixel readout
[13:36:41.023] INFO: PixTest:: pg_setup set to default.


[13:36:41.024] INFO: 6 hot pixels found in step 11
[13:36:42.012] INFO: Collecting data for 5 seconds...
[13:36:47.029] INFO: Done with hot pixel readout
[13:36:58.797] INFO: PixTest:: pg_setup set to default.


[13:36:58.798] INFO: 5 hot pixels found in step 12
[13:36:59.786] INFO: Collecting data for 5 seconds...
[13:37:04.803] INFO: Done with hot pixel readout
[13:37:16.533] INFO: PixTest:: pg_setup set to default.




[13:37:16.534] INFO: 10 hot pixels found in step 13
[13:37:17.522] INFO: Collecting data for 5 seconds...
[13:37:22.539] INFO: Done with hot pixel readout
[13:37:34.223] INFO: PixTest:: pg_setup set to default.




[13:37:34.224] INFO: 9 hot pixels found in step 14
[13:37:34.257] INFO: 9 hot pixels could not be trimmed and have been masked.
[13:37:34.260] INFO: PixTest::trimHotPixels() done
[13:37:34.265] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C0.dat
[13:37:34.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C1.dat
[13:37:34.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C2.dat
[13:37:34.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C3.dat
[13:37:34.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C4.dat
[13:37:34.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C5.dat
[13:37:34.299] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C6.dat
[13:37:34.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C7.dat
[13:37:34.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C8.dat
[13:37:34.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C9.dat
[13:37:34.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C10.dat
[13:37:34.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C11.dat
[13:37:34.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C12.dat
[13:37:34.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C13.dat
[13:37:34.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C14.dat
[13:37:34.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C15.dat
[13:37:34.352] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//defaultMaskFile.dat
[13:37:34.363] INFO: enter test to run
[13:38:39.759] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:38:39.759] INFO: running: highrate
[13:38:39.764] INFO: ----------------------------------------------------------------------
[13:38:39.764] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:38:39.764] INFO: ----------------------------------------------------------------------
[13:38:39.764] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:38:39.764] INFO: edge/corner pixel THR is adjusted
[13:38:39.764] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:38:40.723] INFO: Collecting data for 1 seconds...
[13:38:41.727] INFO: Done with hot pixel readout
[13:38:45.669] INFO: PixTest:: pg_setup set to default.
[13:38:45.670] INFO: 0 hot pixels found in step 0
[13:38:45.676] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:38:45.768] INFO: PixTest::trimHotPixels() done
[13:38:45.769] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C0.dat
[13:38:45.782] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C1.dat
[13:38:45.787] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C2.dat
[13:38:45.793] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C3.dat
[13:38:45.799] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C4.dat
[13:38:45.804] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C5.dat
[13:38:45.809] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C6.dat
[13:38:45.815] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C7.dat
[13:38:45.820] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C8.dat
[13:38:45.825] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C9.dat
[13:38:45.831] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C10.dat
[13:38:45.837] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C11.dat
[13:38:45.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C12.dat
[13:38:45.848] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C13.dat
[13:38:45.853] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C14.dat
[13:38:45.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//trimParameters35_C15.dat
[13:38:45.865] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-36_FPIXTest-17C-FNAL-160621-1520_2016-06-21_15h20m_1466540429/000_FPIXTest_p17//defaultMaskFile.dat
[13:38:45.874] INFO: enter test to run
[13:39:23.087] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:39:23.087] INFO: running: xray
[13:39:23.088] INFO: ----------------------------------------------------------------------
[13:39:23.088] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:39:23.088] INFO: ----------------------------------------------------------------------
[13:39:24.053] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:39:35.593] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:40:05.095] INFO: Resuming triggers.
[13:40:16.631] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:40:45.960] INFO: Resuming triggers.
[13:40:57.499] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:41:26.972] INFO: Resuming triggers.
[13:41:38.511] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:42:07.950] INFO: Resuming triggers.
[13:42:19.488] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:42:48.927] INFO: Resuming triggers.
[13:43:00.466] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:43:29.940] INFO: Resuming triggers.
[13:43:41.476] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:44:11.504] INFO: Resuming triggers.
[13:44:23.039] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:44:53.053] INFO: Resuming triggers.
[13:45:01.081] INFO: data taking finished, elapsed time: 100 seconds.
[13:45:22.035] INFO: PixTest:: pg_setup set to default.
[13:45:22.038] INFO: PixTestXray::doPhRun() done
[13:45:22.178] INFO: enter test to run
[13:46:04.396] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:46:04.397] INFO: running: xray
[13:46:04.398] INFO: ----------------------------------------------------------------------
[13:46:04.398] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:46:04.398] INFO: ----------------------------------------------------------------------
[13:46:05.368] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:46:12.230] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:46:43.567] INFO: Resuming triggers.
[13:46:50.428] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:47:21.983] INFO: Resuming triggers.
[13:47:28.848] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:47:59.334] INFO: Resuming triggers.
[13:48:06.199] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:48:36.526] INFO: Resuming triggers.
[13:48:43.392] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:49:13.711] INFO: Resuming triggers.
[13:49:20.577] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[13:49:50.907] INFO: Resuming triggers.
[13:49:57.768] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:50:27.894] INFO: Resuming triggers.
[13:50:34.755] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:51:05.006] INFO: Resuming triggers.
[13:51:11.870] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:51:42.158] INFO: Resuming triggers.
[13:51:49.018] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:52:19.298] INFO: Resuming triggers.
[13:52:26.161] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:52:56.466] INFO: Resuming triggers.
[13:53:03.324] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:53:33.676] INFO: Resuming triggers.
[13:53:40.536] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[13:54:10.771] INFO: Resuming triggers.
[13:54:17.632] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[13:54:47.878] INFO: Resuming triggers.
[13:54:52.146] INFO: data taking finished, elapsed time: 100 seconds.
[13:55:11.245] INFO: PixTest:: pg_setup set to default.
[13:55:11.248] INFO: PixTestXray::doPhRun() done
[13:55:11.394] INFO: enter test to run
[13:55:57.472] INFO: test: HighRate no parameter change
[13:55:57.472] INFO: running: highrate
[13:55:57.487] INFO: ----------------------------------------------------------------------
[13:55:57.487] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:55:57.487] INFO: ----------------------------------------------------------------------
[13:55:57.643] INFO: Expecting 768 events.
[13:55:58.777] INFO: 768 events read in total (418ms).
[13:55:58.777] INFO: Test took 1269ms.
[13:55:59.580] INFO: Expecting 41600 events.
[13:56:02.679] INFO: 41600 events read in total (2572ms).
[13:56:02.681] INFO: Test took 3878ms.
[13:56:02.718] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:03.429] INFO: Expecting 41600 events.
[13:56:06.682] INFO: 41600 events read in total (2726ms).
[13:56:06.683] INFO: Test took 3948ms.
[13:56:06.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:07.439] INFO: Expecting 41600 events.
[13:56:10.781] INFO: 41600 events read in total (2815ms).
[13:56:10.782] INFO: Test took 4048ms.
[13:56:10.816] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:11.538] INFO: Expecting 41600 events.
[13:56:14.865] INFO: 41600 events read in total (2800ms).
[13:56:14.866] INFO: Test took 4032ms.
[13:56:14.901] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:15.619] INFO: Expecting 41600 events.
[13:56:18.887] INFO: 41600 events read in total (2741ms).
[13:56:18.888] INFO: Test took 3970ms.
[13:56:18.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:19.645] INFO: Expecting 41600 events.
[13:56:22.968] INFO: 41600 events read in total (2797ms).
[13:56:22.969] INFO: Test took 4030ms.
[13:56:23.003] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:23.726] INFO: Expecting 41600 events.
[13:56:26.986] INFO: 41600 events read in total (2733ms).
[13:56:26.987] INFO: Test took 3966ms.
[13:56:27.021] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:27.741] INFO: Expecting 41600 events.
[13:56:31.045] INFO: 41600 events read in total (2777ms).
[13:56:31.046] INFO: Test took 4007ms.
[13:56:31.082] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:31.798] INFO: Expecting 41600 events.
[13:56:35.020] INFO: 41600 events read in total (2695ms).
[13:56:35.021] INFO: Test took 3921ms.
[13:56:35.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:35.779] INFO: Expecting 41600 events.
[13:56:39.043] INFO: 41600 events read in total (2737ms).
[13:56:39.043] INFO: Test took 3970ms.
[13:56:39.078] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:39.793] INFO: Expecting 41600 events.
[13:56:43.059] INFO: 41600 events read in total (2739ms).
[13:56:43.060] INFO: Test took 3964ms.
[13:56:43.094] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:43.818] INFO: Expecting 41600 events.
[13:56:47.111] INFO: 41600 events read in total (2766ms).
[13:56:47.112] INFO: Test took 3999ms.
[13:56:47.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:47.867] INFO: Expecting 41600 events.
[13:56:51.163] INFO: 41600 events read in total (2769ms).
[13:56:51.164] INFO: Test took 3999ms.
[13:56:51.198] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:51.914] INFO: Expecting 41600 events.
[13:56:55.138] INFO: 41600 events read in total (2698ms).
[13:56:55.139] INFO: Test took 3923ms.
[13:56:55.173] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:55.893] INFO: Expecting 41600 events.
[13:56:59.146] INFO: 41600 events read in total (2726ms).
[13:56:59.147] INFO: Test took 3955ms.
[13:56:59.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:56:59.902] INFO: Expecting 41600 events.
[13:57:03.190] INFO: 41600 events read in total (2762ms).
[13:57:03.191] INFO: Test took 3993ms.
[13:57:03.226] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:03.945] INFO: Expecting 41600 events.
[13:57:07.200] INFO: 41600 events read in total (2728ms).
[13:57:07.201] INFO: Test took 3957ms.
[13:57:07.236] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:07.958] INFO: Expecting 41600 events.
[13:57:11.227] INFO: 41600 events read in total (2742ms).
[13:57:11.228] INFO: Test took 3974ms.
[13:57:11.262] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:11.980] INFO: Expecting 41600 events.
[13:57:15.233] INFO: 41600 events read in total (2727ms).
[13:57:15.234] INFO: Test took 3954ms.
[13:57:15.269] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:15.983] INFO: Expecting 41600 events.
[13:57:19.194] INFO: 41600 events read in total (2684ms).
[13:57:19.196] INFO: Test took 3910ms.
[13:57:19.230] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:19.585] INFO: enter test to run
[13:57:28.376] INFO: test: HighRate no parameter change
[13:57:28.376] INFO: running: highrate
[13:57:28.377] INFO: ----------------------------------------------------------------------
[13:57:28.377] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:57:28.377] INFO: ----------------------------------------------------------------------
[13:57:28.999] INFO: Expecting 208000 events.
[13:57:40.764] INFO: 208000 events read in total (11238ms).
[13:57:40.767] INFO: Test took 12383ms.
[13:57:40.911] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:57:41.165] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:57:41.165] INFO: number of red-efficiency pixels: 70 56 93 151 144 123 143 84 90 109 124 93 104 63 20 26
[13:57:41.165] INFO: number of X-ray hits detected: 65173 42328 67497 107614 114575 117436 112538 76929 73469 96329 96171 83103 83604 50211 19914 23178
[13:57:41.165] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:57:41.165] INFO: number of Vcal hits detected: 207928 207943 207905 207844 207854 207870 207849 207914 207909 207882 207871 207904 207895 207936 207980 207974
[13:57:41.165] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[13:57:41.165] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[13:57:41.165] INFO: X-ray hit rate [MHz/cm2]: 19.1 12.4 19.8 31.5 33.6 34.4 33.0 22.5 21.5 28.2 28.2 24.4 24.5 14.7 5.8 6.8
[13:57:41.166] INFO: PixTestHighRate::doXPixelAlive() done
[13:57:41.213] INFO: PixTest:: pg_setup set to default.
[13:57:41.221] INFO: enter test to run
[13:58:05.743] INFO: test: HighRate no parameter change
[13:58:05.744] INFO: running: highrate
[13:58:05.745] INFO: ----------------------------------------------------------------------
[13:58:05.745] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:58:05.745] INFO: ----------------------------------------------------------------------
[13:58:06.371] INFO: Expecting 208000 events.
[13:58:20.180] INFO: 208000 events read in total (13282ms).
[13:58:20.185] INFO: Test took 14430ms.
[13:58:20.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:58:20.776] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:58:20.776] INFO: number of red-efficiency pixels: 252 145 243 432 384 428 370 218 225 323 385 244 300 195 41 58
[13:58:20.776] INFO: number of X-ray hits detected: 131920 85277 136283 217456 230051 236110 229115 155372 149075 195921 195190 168315 168933 101853 39701 46972
[13:58:20.776] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:58:20.776] INFO: number of Vcal hits detected: 207721 207850 207739 207523 207596 207531 207596 207774 207768 207640 207589 207737 207687 207791 207959 207941
[13:58:20.776] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[13:58:20.777] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[13:58:20.777] INFO: X-ray hit rate [MHz/cm2]: 38.7 25.0 39.9 63.7 67.4 69.2 67.2 45.5 43.7 57.4 57.2 49.3 49.5 29.9 11.6 13.8
[13:58:20.777] INFO: PixTestHighRate::doXPixelAlive() done
[13:58:20.821] INFO: PixTest:: pg_setup set to default.
[13:58:20.837] INFO: enter test to run
[13:59:02.335] INFO: test: HighRate no parameter change
[13:59:02.335] INFO: running: highrate
[13:59:02.336] INFO: ----------------------------------------------------------------------
[13:59:02.336] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:59:02.336] INFO: ----------------------------------------------------------------------
[13:59:02.956] INFO: Expecting 208000 events.
[13:59:18.709] INFO: 208000 events read in total (15227ms).
[13:59:18.717] INFO: Test took 16370ms.
[13:59:19.192] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:59:19.539] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:59:19.539] INFO: number of red-efficiency pixels: 497 261 497 1051 869 1028 886 517 427 623 876 468 624 402 61 98
[13:59:19.539] INFO: number of X-ray hits detected: 198113 127520 205758 327169 345376 353264 342716 234115 223325 293127 293295 250949 253407 152479 59980 70985
[13:59:19.539] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:59:19.539] INFO: number of Vcal hits detected: 207416 207722 207364 206690 206970 206732 206894 207415 207531 207253 206940 207477 207269 207536 207937 207901
[13:59:19.539] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.4 99.6 99.4 99.5 99.7 99.8 99.7 99.5 99.8 99.7 99.8 100.0 100.0
[13:59:19.539] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.4 99.5 99.4 99.5 99.7 99.8 99.6 99.5 99.7 99.6 99.8 100.0 100.0
[13:59:19.539] INFO: X-ray hit rate [MHz/cm2]: 58.1 37.4 60.3 95.9 101.2 103.5 100.5 68.6 65.5 85.9 86.0 73.6 74.3 44.7 17.6 20.8
[13:59:19.539] INFO: PixTestHighRate::doXPixelAlive() done
[13:59:19.584] INFO: PixTest:: pg_setup set to default.
[13:59:19.601] INFO: enter test to run
[14:00:00.735] INFO: test: exit no parameter change
[14:00:01.077] QUIET: Connection to board 33 closed.
[14:00:01.091] INFO: pXar: this is the end, my friend