[14:34:04.321] INFO: *** Welcome to pxar ***
[14:34:04.321] INFO: *** Today: 2016/08/30
[14:34:05.286] INFO: *** Version: v1.9.0-818-g96727
[14:34:05.286] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//dacParameters35_C15.dat
[14:34:05.311] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:34:05.311] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//defaultMaskFile.dat
[14:34:05.316] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C15.dat
[14:34:05.444] INFO: clk: 4
[14:34:05.444] INFO: ctr: 4
[14:34:05.444] INFO: sda: 19
[14:34:05.444] INFO: tin: 9
[14:34:05.444] INFO: level: 15
[14:34:05.444] INFO: triggerdelay: 0
[14:34:05.444] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:34:05.444] INFO: Log level: INFO
[14:34:05.462] QUIET: Connection to board DTB_WREKRL opened.
[14:34:05.465] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[14:34:05.468] INFO: RPC call hashes of host and DTB match: 398089610
[14:34:06.999] INFO: DUT info:
[14:34:06.999] INFO: The DUT currently contains the following objects:
[14:34:06.999] INFO: 2 TBM Cores tbm08c (2 ON)
[14:34:06.999] INFO: TBM Core alpha (0): 7 registers set
[14:34:06.999] INFO: TBM Core beta (1): 7 registers set
[14:34:06.999] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:34:06.999] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.999] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.999] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.999] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.999] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.999] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.999] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.000] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.000] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.000] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.000] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.000] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.000] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.000] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.000] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:06.000] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:07.409] INFO: enter 'restricted' command line mode
[14:34:07.409] INFO: enter test to run
[14:34:17.847] INFO: test: PixelAlive no parameter change
[14:34:17.847] INFO: running: pixelalive
[14:34:17.856] INFO: ----------------------------------------------------------------------
[14:34:17.856] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:34:17.856] INFO: ----------------------------------------------------------------------
[14:34:18.174] INFO: Expecting 41600 events.
[14:34:22.515] INFO: 41600 events read in total (3623ms).
[14:34:22.681] INFO: Test took 4823ms.
[14:34:22.695] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:34:22.958] INFO: PixTestAlive::aliveTest() done
[14:34:22.958] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[14:34:22.989] INFO: enter test to run
[14:34:56.086] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:34:56.086] INFO: running: highrate
[14:34:56.087] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:34:56.346] INFO: ----------------------------------------------------------------------
[14:34:56.347] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:34:56.347] INFO: ----------------------------------------------------------------------
[14:34:56.347] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:34:56.347] INFO: edge/corner pixel THR is adjusted
[14:34:56.347] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:34:57.308] INFO: Collecting data for 5 seconds...
[14:35:02.325] INFO: Done with hot pixel readout
[14:35:13.705] INFO: PixTest:: pg_setup set to default.
[14:35:13.706] INFO: 19 hot pixels found in step 0
[14:35:14.719] INFO: Collecting data for 5 seconds...
[14:35:19.737] INFO: Done with hot pixel readout
[14:35:31.064] INFO: PixTest:: pg_setup set to default.
[14:35:31.065] INFO: 19 hot pixels found in step 1
[14:35:32.050] INFO: Collecting data for 5 seconds...
[14:35:37.067] INFO: Done with hot pixel readout
[14:35:48.414] INFO: PixTest:: pg_setup set to default.
[14:35:48.415] INFO: 20 hot pixels found in step 2
[14:35:49.399] INFO: Collecting data for 5 seconds...
[14:35:54.416] INFO: Done with hot pixel readout
[14:36:05.707] INFO: PixTest:: pg_setup set to default.
[14:36:05.708] INFO: 18 hot pixels found in step 3
[14:36:06.692] INFO: Collecting data for 5 seconds...
[14:36:11.708] INFO: Done with hot pixel readout
[14:36:23.037] INFO: PixTest:: pg_setup set to default.
[14:36:23.038] INFO: 18 hot pixels found in step 4
[14:36:24.023] INFO: Collecting data for 5 seconds...
[14:36:29.039] INFO: Done with hot pixel readout
[14:36:40.356] INFO: PixTest:: pg_setup set to default.
[14:36:40.357] INFO: 17 hot pixels found in step 5
[14:36:41.342] INFO: Collecting data for 5 seconds...
[14:36:46.359] INFO: Done with hot pixel readout
[14:36:57.672] INFO: PixTest:: pg_setup set to default.

[14:36:57.673] INFO: 19 hot pixels found in step 6
[14:36:58.658] INFO: Collecting data for 5 seconds...
[14:37:03.674] INFO: Done with hot pixel readout
[14:37:15.008] INFO: PixTest:: pg_setup set to default.

[14:37:15.009] INFO: 14 hot pixels found in step 7
[14:37:15.994] INFO: Collecting data for 5 seconds...
[14:37:21.011] INFO: Done with hot pixel readout
[14:37:32.345] INFO: PixTest:: pg_setup set to default.

[14:37:32.345] INFO: 7 hot pixels found in step 8
[14:37:33.331] INFO: Collecting data for 5 seconds...
[14:37:38.347] INFO: Done with hot pixel readout
[14:37:49.689] INFO: PixTest:: pg_setup set to default.


[14:37:49.689] INFO: 7 hot pixels found in step 9
[14:37:50.674] INFO: Collecting data for 5 seconds...
[14:37:55.690] INFO: Done with hot pixel readout
[14:38:07.016] INFO: PixTest:: pg_setup set to default.



[14:38:07.017] INFO: 6 hot pixels found in step 10
[14:38:07.002] INFO: Collecting data for 5 seconds...
[14:38:13.018] INFO: Done with hot pixel readout
[14:38:24.341] INFO: PixTest:: pg_setup set to default.


[14:38:24.342] INFO: 4 hot pixels found in step 11
[14:38:25.326] INFO: Collecting data for 5 seconds...
[14:38:30.343] INFO: Done with hot pixel readout
[14:38:41.684] INFO: PixTest:: pg_setup set to default.


[14:38:41.684] INFO: 4 hot pixels found in step 12
[14:38:42.670] INFO: Collecting data for 5 seconds...
[14:38:47.687] INFO: Done with hot pixel readout
[14:38:58.000] INFO: PixTest:: pg_setup set to default.


[14:38:58.000] INFO: 2 hot pixels found in step 13
[14:38:59.029] INFO: 2 hot pixels could not be trimmed and have been masked.
[14:38:59.033] INFO: PixTest::trimHotPixels() done
[14:38:59.033] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C0.dat
[14:38:59.044] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C1.dat
[14:38:59.049] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C2.dat
[14:38:59.054] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C3.dat
[14:38:59.060] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C4.dat
[14:38:59.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C5.dat
[14:38:59.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C6.dat
[14:38:59.076] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C7.dat
[14:38:59.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C8.dat
[14:38:59.087] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C9.dat
[14:38:59.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C10.dat
[14:38:59.098] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C11.dat
[14:38:59.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C12.dat
[14:38:59.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C13.dat
[14:38:59.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C14.dat
[14:38:59.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C15.dat
[14:38:59.125] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//defaultMaskFile.dat
[14:38:59.136] INFO: enter test to run
[14:40:31.084] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:40:31.084] INFO: running: highrate
[14:40:31.089] INFO: ----------------------------------------------------------------------
[14:40:31.089] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:40:31.089] INFO: ----------------------------------------------------------------------
[14:40:31.089] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:40:31.089] INFO: edge/corner pixel THR is adjusted
[14:40:31.089] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:40:32.054] INFO: Collecting data for 1 seconds...
[14:40:33.057] INFO: Done with hot pixel readout
[14:40:36.857] INFO: PixTest:: pg_setup set to default.
[14:40:36.858] INFO: 0 hot pixels found in step 0
[14:40:36.864] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:40:36.958] INFO: PixTest::trimHotPixels() done
[14:40:36.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C0.dat
[14:40:36.966] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C1.dat
[14:40:36.971] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C2.dat
[14:40:36.976] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C3.dat
[14:40:36.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C4.dat
[14:40:36.987] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C5.dat
[14:40:36.992] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C6.dat
[14:40:36.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C7.dat
[14:40:36.003] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C8.dat
[14:40:37.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C9.dat
[14:40:37.014] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C10.dat
[14:40:37.019] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C11.dat
[14:40:37.024] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C12.dat
[14:40:37.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C13.dat
[14:40:37.035] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C14.dat
[14:40:37.040] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//trimParameters35_C15.dat
[14:40:37.046] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-07_FPIXTest-17C-FNAL-160829-1249-300V_2016-08-29_12h49m_1472492982/000_FPIXTest_p17//defaultMaskFile.dat
[14:40:37.060] INFO: enter test to run
[14:41:54.595] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:41:54.596] INFO: running: xray
[14:41:54.597] INFO: ----------------------------------------------------------------------
[14:41:54.597] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:41:54.597] INFO: ----------------------------------------------------------------------
[14:41:55.562] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:42:07.383] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:42:36.107] INFO: Resuming triggers.
[14:42:47.930] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:43:17.503] INFO: Resuming triggers.
[14:43:29.327] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:43:58.749] INFO: Resuming triggers.
[14:44:10.578] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[14:44:40.452] INFO: Resuming triggers.
[14:44:52.282] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:45:22.279] INFO: Resuming triggers.
[14:45:34.107] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:46:03.902] INFO: Resuming triggers.
[14:46:15.729] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[14:46:44.940] INFO: Resuming triggers.
[14:46:56.767] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:47:26.031] INFO: Resuming triggers.
[14:47:31.792] INFO: data taking finished, elapsed time: 100 seconds.
[14:47:46.357] INFO: PixTest:: pg_setup set to default.
[14:47:46.360] INFO: PixTestXray::doPhRun() done
[14:47:46.540] INFO: enter test to run
[14:49:26.872] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:49:26.872] INFO: running: xray
[14:49:26.874] INFO: ----------------------------------------------------------------------
[14:49:26.874] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:49:26.874] INFO: ----------------------------------------------------------------------
[14:49:27.838] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:49:34.995] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:50:05.189] INFO: Resuming triggers.
[14:50:12.348] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:50:42.461] INFO: Resuming triggers.
[14:50:49.619] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:51:19.785] INFO: Resuming triggers.
[14:51:26.943] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:51:56.844] INFO: Resuming triggers.
[14:52:03.004] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:52:34.112] INFO: Resuming triggers.
[14:52:41.273] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[14:53:11.408] INFO: Resuming triggers.
[14:53:18.571] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:53:48.642] INFO: Resuming triggers.
[14:53:55.802] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:54:26.438] INFO: Resuming triggers.
[14:54:33.600] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[14:55:04.168] INFO: Resuming triggers.
[14:55:11.329] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:55:42.256] INFO: Resuming triggers.
[14:55:49.420] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:56:20.153] INFO: Resuming triggers.
[14:56:27.317] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:56:58.977] INFO: Resuming triggers.
[14:57:06.143] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:57:37.382] INFO: Resuming triggers.
[14:57:44.548] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:58:15.922] INFO: Resuming triggers.
[14:58:16.016] INFO: data taking finished, elapsed time: 100 seconds.
[14:58:16.901] INFO: PixTest:: pg_setup set to default.
[14:58:16.904] INFO: PixTestXray::doPhRun() done
[14:58:17.058] INFO: enter test to run
[14:58:46.077] INFO: test: HighRate no parameter change
[14:58:46.077] INFO: running: highrate
[14:58:46.086] INFO: ----------------------------------------------------------------------
[14:58:46.086] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:58:46.086] INFO: ----------------------------------------------------------------------
[14:58:46.241] INFO: Expecting 768 events.
[14:58:47.402] INFO: 768 events read in total (445ms).
[14:58:47.402] INFO: Test took 1296ms.
[14:58:48.206] INFO: Expecting 41600 events.
[14:58:51.283] INFO: 41600 events read in total (2550ms).
[14:58:51.284] INFO: Test took 3859ms.
[14:58:51.315] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:52.050] INFO: Expecting 41600 events.
[14:58:55.158] INFO: 41600 events read in total (2582ms).
[14:58:55.159] INFO: Test took 3829ms.
[14:58:55.189] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:55.918] INFO: Expecting 41600 events.
[14:58:59.111] INFO: 41600 events read in total (2666ms).
[14:58:59.111] INFO: Test took 3904ms.
[14:58:59.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:58:59.872] INFO: Expecting 41600 events.
[14:59:03.081] INFO: 41600 events read in total (2682ms).
[14:59:03.082] INFO: Test took 3922ms.
[14:59:03.114] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:03.842] INFO: Expecting 41600 events.
[14:59:07.051] INFO: 41600 events read in total (2682ms).
[14:59:07.052] INFO: Test took 3922ms.
[14:59:07.084] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:07.811] INFO: Expecting 41600 events.
[14:59:11.025] INFO: 41600 events read in total (2687ms).
[14:59:11.026] INFO: Test took 3925ms.
[14:59:11.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:11.784] INFO: Expecting 41600 events.
[14:59:14.996] INFO: 41600 events read in total (2685ms).
[14:59:14.997] INFO: Test took 3923ms.
[14:59:15.028] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:15.756] INFO: Expecting 41600 events.
[14:59:18.961] INFO: 41600 events read in total (2678ms).
[14:59:18.962] INFO: Test took 3917ms.
[14:59:18.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:19.724] INFO: Expecting 41600 events.
[14:59:22.942] INFO: 41600 events read in total (2691ms).
[14:59:22.943] INFO: Test took 3932ms.
[14:59:22.975] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:23.703] INFO: Expecting 41600 events.
[14:59:26.915] INFO: 41600 events read in total (2685ms).
[14:59:26.917] INFO: Test took 3925ms.
[14:59:26.948] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:27.677] INFO: Expecting 41600 events.
[14:59:30.876] INFO: 41600 events read in total (2672ms).
[14:59:30.877] INFO: Test took 3912ms.
[14:59:30.909] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:31.638] INFO: Expecting 41600 events.
[14:59:34.847] INFO: 41600 events read in total (2682ms).
[14:59:34.848] INFO: Test took 3922ms.
[14:59:34.880] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:35.609] INFO: Expecting 41600 events.
[14:59:38.828] INFO: 41600 events read in total (2692ms).
[14:59:38.829] INFO: Test took 3932ms.
[14:59:38.861] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:39.587] INFO: Expecting 41600 events.
[14:59:42.801] INFO: 41600 events read in total (2687ms).
[14:59:42.802] INFO: Test took 3923ms.
[14:59:42.833] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:43.559] INFO: Expecting 41600 events.
[14:59:46.751] INFO: 41600 events read in total (2665ms).
[14:59:46.752] INFO: Test took 3902ms.
[14:59:46.783] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:47.514] INFO: Expecting 41600 events.
[14:59:50.734] INFO: 41600 events read in total (2694ms).
[14:59:50.735] INFO: Test took 3934ms.
[14:59:50.767] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:51.495] INFO: Expecting 41600 events.
[14:59:54.714] INFO: 41600 events read in total (2693ms).
[14:59:54.715] INFO: Test took 3930ms.
[14:59:54.747] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:55.471] INFO: Expecting 41600 events.
[14:59:58.666] INFO: 41600 events read in total (2668ms).
[14:59:58.667] INFO: Test took 3902ms.
[14:59:58.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:59:59.426] INFO: Expecting 41600 events.
[15:00:02.564] INFO: 41600 events read in total (2612ms).
[15:00:02.565] INFO: Test took 3849ms.
[15:00:02.597] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:03.322] INFO: Expecting 41600 events.
[15:00:06.291] INFO: 41600 events read in total (2442ms).
[15:00:06.292] INFO: Test took 3678ms.
[15:00:06.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:00:06.686] INFO: enter test to run
[15:01:10.556] INFO: test: HighRate no parameter change
[15:01:10.556] INFO: running: highrate
[15:01:10.557] INFO: ----------------------------------------------------------------------
[15:01:10.557] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:01:10.557] INFO: ----------------------------------------------------------------------
[15:01:11.176] INFO: Expecting 208000 events.
[15:01:22.863] INFO: 208000 events read in total (11160ms).
[15:01:22.866] INFO: Test took 12300ms.
[15:01:22.998] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:01:23.245] INFO: number of dead pixels (per ROC): 101 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:01:23.245] INFO: number of red-efficiency pixels: 239 45 84 110 108 144 150 77 82 118 124 106 93 63 22 29
[15:01:23.245] INFO: number of X-ray hits detected: 65918 41623 63126 96524 99082 101748 100247 66470 67500 91076 89158 78050 81509 49049 20714 26213
[15:01:23.245] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:01:23.245] INFO: number of Vcal hits detected: 200389 207953 207914 207889 207892 207855 207849 207923 207915 207880 207872 207893 207907 207936 207978 207922
[15:01:23.245] INFO: Vcal hit fiducial efficiency (%): 98.7 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:01:23.245] INFO: Vcal hit overall efficiency (%): 96.3 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[15:01:23.245] INFO: X-ray hit rate [MHz/cm2]: 19.3 12.2 18.5 28.3 29.0 29.8 29.4 19.5 19.8 26.7 26.1 22.9 23.9 14.4 6.1 7.7
[15:01:23.245] INFO: PixTestHighRate::doXPixelAlive() done
[15:01:23.297] INFO: PixTest:: pg_setup set to default.
[15:01:23.315] INFO: enter test to run
[15:03:34.819] INFO: test: HighRate no parameter change
[15:03:34.819] INFO: running: highrate
[15:03:34.820] INFO: ----------------------------------------------------------------------
[15:03:34.820] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:03:34.820] INFO: ----------------------------------------------------------------------
[15:03:35.442] INFO: Expecting 208000 events.
[15:03:48.648] INFO: 208000 events read in total (12680ms).
[15:03:48.653] INFO: Test took 13822ms.
[15:03:48.909] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:03:49.199] INFO: number of dead pixels (per ROC): 42 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:03:49.200] INFO: number of red-efficiency pixels: 399 134 258 325 303 424 450 206 216 371 334 269 289 184 61 71
[15:03:49.200] INFO: number of X-ray hits detected: 130921 83834 127439 195246 200802 205521 202514 133747 136399 182336 180534 156891 164702 100163 42151 53312
[15:03:49.200] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:03:49.200] INFO: number of Vcal hits detected: 199975 207862 207718 207653 207682 207541 207515 207782 207774 207617 207651 207712 207693 207805 207939 207878
[15:03:49.200] INFO: Vcal hit fiducial efficiency (%): 97.0 99.9 99.9 99.8 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:03:49.200] INFO: Vcal hit overall efficiency (%): 96.1 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 99.9
[15:03:49.200] INFO: X-ray hit rate [MHz/cm2]: 38.4 24.6 37.4 57.2 58.9 60.2 59.4 39.2 40.0 53.4 52.9 46.0 48.3 29.4 12.4 15.6
[15:03:49.200] INFO: PixTestHighRate::doXPixelAlive() done
[15:03:49.250] INFO: PixTest:: pg_setup set to default.
[15:03:49.265] INFO: enter test to run
[15:04:31.410] INFO: test: HighRate no parameter change
[15:04:31.410] INFO: running: highrate
[15:04:31.412] INFO: ----------------------------------------------------------------------
[15:04:31.412] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:04:31.412] INFO: ----------------------------------------------------------------------
[15:04:32.031] INFO: Expecting 208000 events.
[15:04:46.862] INFO: 208000 events read in total (14305ms).
[15:04:46.869] INFO: Test took 15446ms.
[15:04:47.257] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:04:47.592] INFO: number of dead pixels (per ROC): 34 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1
[15:04:47.592] INFO: number of red-efficiency pixels: 640 252 637 705 742 1024 1045 559 466 804 839 650 730 345 95 108
[15:04:47.592] INFO: number of X-ray hits detected: 199228 126850 193854 296667 304340 313138 309529 203336 208168 277994 273799 238562 252454 150763 63950 80937
[15:04:47.592] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:04:47.592] INFO: number of Vcal hits detected: 199634 207715 207185 207193 207125 206715 206706 207345 207474 207062 207030 207263 207172 207601 207903 207840
[15:04:47.592] INFO: Vcal hit fiducial efficiency (%): 96.7 99.9 99.7 99.6 99.6 99.4 99.4 99.7 99.8 99.6 99.6 99.7 99.6 99.8 100.0 100.0
[15:04:47.592] INFO: Vcal hit overall efficiency (%): 96.0 99.9 99.6 99.6 99.6 99.4 99.4 99.7 99.7 99.5 99.5 99.6 99.6 99.8 100.0 99.9
[15:04:47.592] INFO: X-ray hit rate [MHz/cm2]: 58.4 37.2 56.8 87.0 89.2 91.8 90.7 59.6 61.0 81.5 80.3 69.9 74.0 44.2 18.7 23.7
[15:04:47.592] INFO: PixTestHighRate::doXPixelAlive() done
[15:04:47.639] INFO: PixTest:: pg_setup set to default.
[15:04:47.657] INFO: enter test to run
[15:05:49.298] INFO: test: exit no parameter change
[15:05:49.601] QUIET: Connection to board 33 closed.
[15:05:49.611] INFO: pXar: this is the end, my friend