[14:15:20.368] INFO: *** Welcome to pxar ***
[14:15:20.368] INFO: *** Today: 2016/08/11
[14:15:20.386] INFO: *** Version: v1.9.0-818-g96727
[14:15:20.386] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//dacParameters35_C15.dat
[14:15:20.417] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:15:20.417] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//defaultMaskFile.dat
[14:15:20.419] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C15.dat
[14:15:20.561] INFO: clk: 4
[14:15:20.561] INFO: ctr: 4
[14:15:20.561] INFO: sda: 19
[14:15:20.561] INFO: tin: 9
[14:15:20.561] INFO: level: 15
[14:15:20.562] INFO: triggerdelay: 0
[14:15:20.562] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:15:20.562] INFO: Log level: INFO
[14:15:20.580] QUIET: Connection to board DTB_WREKRL opened.
[14:15:20.584] 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:15:20.587] INFO: RPC call hashes of host and DTB match: 398089610
[14:15:22.114] INFO: DUT info:
[14:15:22.114] INFO: The DUT currently contains the following objects:
[14:15:22.114] INFO: 2 TBM Cores tbm08c (2 ON)
[14:15:22.114] INFO: TBM Core alpha (0): 7 registers set
[14:15:22.115] INFO: TBM Core beta (1): 7 registers set
[14:15:22.115] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:15:22.115] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.115] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:15:22.537] INFO: enter 'restricted' command line mode
[14:15:22.537] INFO: enter test to run
[14:15:27.764] INFO: test: PixelAlive no parameter change
[14:15:27.764] INFO: running: pixelalive
[14:15:27.774] INFO: ----------------------------------------------------------------------
[14:15:27.774] 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:15:27.774] INFO: ----------------------------------------------------------------------
[14:15:28.088] INFO: Expecting 41600 events.
[14:15:32.425] INFO: 41600 events read in total (3618ms).
[14:15:32.591] INFO: Test took 4814ms.
[14:15:32.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:15:32.864] INFO: PixTestAlive::aliveTest() done
[14:15:32.864] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 93 53 52 52 50 11 0 0
[14:15:32.893] INFO: enter test to run
[14:15:59.804] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:15:59.804] INFO: running: highrate
[14:15:59.804] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:16:00.034] INFO: ----------------------------------------------------------------------
[14:16:00.034] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:16:00.034] INFO: ----------------------------------------------------------------------
[14:16:00.034] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:16:00.034] INFO: edge/corner pixel THR is adjusted
[14:16:00.034] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:16:00.993] INFO: Collecting data for 5 seconds...
[14:16:06.009] INFO: Done with hot pixel readout
[14:16:17.564] INFO: PixTest:: pg_setup set to default.
[14:16:17.565] INFO: 51 hot pixels found in step 0
[14:16:18.554] INFO: Collecting data for 5 seconds...
[14:16:23.571] INFO: Done with hot pixel readout
[14:16:34.645] INFO: PixTest:: pg_setup set to default.
[14:16:34.646] INFO: 31 hot pixels found in step 1
[14:16:35.639] INFO: Collecting data for 5 seconds...
[14:16:40.657] INFO: Done with hot pixel readout
[14:16:51.578] INFO: PixTest:: pg_setup set to default.
[14:16:51.579] INFO: 28 hot pixels found in step 2
[14:16:52.568] INFO: Collecting data for 5 seconds...
[14:16:57.587] INFO: Done with hot pixel readout
[14:17:08.753] INFO: PixTest:: pg_setup set to default.
[14:17:08.754] INFO: 25 hot pixels found in step 3
[14:17:09.743] INFO: Collecting data for 5 seconds...
[14:17:14.761] INFO: Done with hot pixel readout
[14:17:25.823] INFO: PixTest:: pg_setup set to default.
[14:17:25.823] INFO: 21 hot pixels found in step 4
[14:17:26.812] INFO: Collecting data for 5 seconds...
[14:17:31.831] INFO: Done with hot pixel readout
[14:17:42.947] INFO: PixTest:: pg_setup set to default.


[14:17:42.948] INFO: 18 hot pixels found in step 5
[14:17:43.937] INFO: Collecting data for 5 seconds...
[14:17:48.954] INFO: Done with hot pixel readout
[14:18:00.101] INFO: PixTest:: pg_setup set to default.

[14:18:00.102] INFO: 13 hot pixels found in step 6
[14:18:01.091] INFO: Collecting data for 5 seconds...
[14:18:06.109] INFO: Done with hot pixel readout
[14:18:16.858] INFO: PixTest:: pg_setup set to default.

[14:18:16.859] INFO: 4 hot pixels found in step 7
[14:18:17.848] INFO: Collecting data for 5 seconds...
[14:18:22.867] INFO: Done with hot pixel readout
[14:18:34.027] INFO: PixTest:: pg_setup set to default.

[14:18:34.028] INFO: 8 hot pixels found in step 8
[14:18:35.021] INFO: Collecting data for 5 seconds...
[14:18:40.040] INFO: Done with hot pixel readout
[14:18:51.536] INFO: PixTest:: pg_setup set to default.

[14:18:51.537] INFO: 3 hot pixels found in step 9
[14:18:52.527] INFO: Collecting data for 5 seconds...
[14:18:57.546] INFO: Done with hot pixel readout
[14:19:08.899] INFO: PixTest:: pg_setup set to default.


[14:19:08.900] INFO: 7 hot pixels found in step 10
[14:19:09.890] INFO: Collecting data for 5 seconds...
[14:19:14.908] INFO: Done with hot pixel readout
[14:19:26.125] INFO: PixTest:: pg_setup set to default.


[14:19:26.126] INFO: 4 hot pixels found in step 11
[14:19:27.115] INFO: Collecting data for 5 seconds...
[14:19:32.136] INFO: Done with hot pixel readout
[14:19:43.642] INFO: PixTest:: pg_setup set to default.


[14:19:43.643] INFO: 5 hot pixels found in step 12
[14:19:44.632] INFO: Collecting data for 5 seconds...
[14:19:49.652] INFO: Done with hot pixel readout
[14:20:01.057] INFO: PixTest:: pg_setup set to default.

[14:20:01.058] INFO: 2 hot pixels found in step 13
[14:20:02.047] INFO: Collecting data for 5 seconds...
[14:20:07.067] INFO: Done with hot pixel readout
[14:20:18.318] INFO: PixTest:: pg_setup set to default.



[14:20:18.319] INFO: 3 hot pixels found in step 14
[14:20:18.352] INFO: 3 hot pixels could not be trimmed and have been masked.
[14:20:18.356] INFO: PixTest::trimHotPixels() done
[14:20:18.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C0.dat
[14:20:18.361] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C1.dat
[14:20:18.367] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C2.dat
[14:20:18.373] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C3.dat
[14:20:18.378] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C4.dat
[14:20:18.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C5.dat
[14:20:18.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C6.dat
[14:20:18.394] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C7.dat
[14:20:18.400] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C8.dat
[14:20:18.405] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C9.dat
[14:20:18.410] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C10.dat
[14:20:18.415] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C11.dat
[14:20:18.421] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C12.dat
[14:20:18.426] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C13.dat
[14:20:18.431] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C14.dat
[14:20:18.437] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C15.dat
[14:20:18.442] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//defaultMaskFile.dat
[14:20:18.452] INFO: enter test to run
[14:20:48.930] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:20:48.930] INFO: running: highrate
[14:20:48.935] INFO: ----------------------------------------------------------------------
[14:20:48.935] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:20:48.935] INFO: ----------------------------------------------------------------------
[14:20:48.935] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:20:48.935] INFO: edge/corner pixel THR is adjusted
[14:20:48.935] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:20:49.893] INFO: Collecting data for 1 seconds...
[14:20:50.896] INFO: Done with hot pixel readout
[14:20:54.743] INFO: PixTest:: pg_setup set to default.
[14:20:54.744] INFO: 0 hot pixels found in step 0
[14:20:54.749] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:20:54.838] INFO: PixTest::trimHotPixels() done
[14:20:54.838] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C0.dat
[14:20:54.846] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C1.dat
[14:20:54.851] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C2.dat
[14:20:54.857] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C3.dat
[14:20:54.862] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C4.dat
[14:20:54.868] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C5.dat
[14:20:54.873] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C6.dat
[14:20:54.878] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C7.dat
[14:20:54.884] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C8.dat
[14:20:54.889] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C9.dat
[14:20:54.894] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C10.dat
[14:20:54.900] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C11.dat
[14:20:54.905] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C12.dat
[14:20:54.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C13.dat
[14:20:54.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C14.dat
[14:20:54.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//trimParameters35_C15.dat
[14:20:54.926] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-4-12_FPIXTest-17C-FNAL-160804-0925_2016-08-04_09h25m_1470320723/000_FPIXTest_p17//defaultMaskFile.dat
[14:20:54.935] INFO: enter test to run
[14:21:18.346] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:21:18.346] INFO: running: xray
[14:21:18.347] INFO: ----------------------------------------------------------------------
[14:21:18.347] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:21:18.347] INFO: ----------------------------------------------------------------------
[14:21:19.310] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:21:31.047] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:22:00.120] INFO: Resuming triggers.
[14:22:11.859] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:22:41.176] INFO: Resuming triggers.
[14:22:52.919] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:23:22.097] INFO: Resuming triggers.
[14:23:33.839] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:24:02.817] INFO: Resuming triggers.
[14:24:14.557] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:24:43.607] INFO: Resuming triggers.
[14:24:55.348] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:25:24.435] INFO: Resuming triggers.
[14:25:36.176] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:26:05.304] INFO: Resuming triggers.
[14:26:17.045] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[14:26:46.221] INFO: Resuming triggers.
[14:26:52.612] INFO: data taking finished, elapsed time: 100 seconds.
[14:27:08.819] INFO: PixTest:: pg_setup set to default.
[14:27:08.823] INFO: PixTestXray::doPhRun() done
[14:27:08.985] INFO: enter test to run
[14:27:35.671] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:27:35.671] INFO: running: xray
[14:27:35.673] INFO: ----------------------------------------------------------------------
[14:27:35.673] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:27:35.673] INFO: ----------------------------------------------------------------------
[14:27:36.636] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:27:43.726] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:28:13.649] INFO: Resuming triggers.
[14:28:20.739] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:28:51.297] INFO: Resuming triggers.
[14:28:58.389] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:29:28.546] INFO: Resuming triggers.
[14:29:35.637] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:30:05.609] INFO: Resuming triggers.
[14:30:12.697] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[14:30:43.577] INFO: Resuming triggers.
[14:30:50.668] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[14:31:21.810] INFO: Resuming triggers.
[14:31:28.902] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[14:32:00.268] INFO: Resuming triggers.
[14:32:07.360] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[14:32:37.657] INFO: Resuming triggers.
[14:32:44.750] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[14:33:14.812] INFO: Resuming triggers.
[14:33:21.905] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[14:33:51.950] INFO: Resuming triggers.
[14:33:59.040] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[14:34:29.024] INFO: Resuming triggers.
[14:34:36.113] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[14:35:06.220] INFO: Resuming triggers.
[14:35:13.307] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:35:43.376] INFO: Resuming triggers.
[14:35:50.463] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:36:20.399] INFO: Resuming triggers.
[14:36:21.477] INFO: data taking finished, elapsed time: 100 seconds.
[14:36:26.400] INFO: PixTest:: pg_setup set to default.
[14:36:26.403] INFO: PixTestXray::doPhRun() done
[14:36:26.552] INFO: enter test to run
[14:37:51.995] INFO: test: HighRate no parameter change
[14:37:51.995] INFO: running: highrate
[14:37:52.007] INFO: ----------------------------------------------------------------------
[14:37:52.007] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:37:52.007] INFO: ----------------------------------------------------------------------
[14:37:52.154] INFO: Expecting 768 events.
[14:37:53.288] INFO: 768 events read in total (419ms).
[14:37:53.288] INFO: Test took 1269ms.
[14:37:54.092] INFO: Expecting 41600 events.
[14:37:57.128] INFO: 41600 events read in total (2510ms).
[14:37:57.129] INFO: Test took 3833ms.
[14:37:57.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:37:57.893] INFO: Expecting 41600 events.
[14:38:01.054] INFO: 41600 events read in total (2634ms).
[14:38:01.055] INFO: Test took 3878ms.
[14:38:01.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:01.813] INFO: Expecting 41600 events.
[14:38:05.017] INFO: 41600 events read in total (2677ms).
[14:38:05.017] INFO: Test took 3913ms.
[14:38:05.051] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:05.778] INFO: Expecting 41600 events.
[14:38:08.965] INFO: 41600 events read in total (2660ms).
[14:38:08.966] INFO: Test took 3898ms.
[14:38:08.999] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:09.727] INFO: Expecting 41600 events.
[14:38:12.947] INFO: 41600 events read in total (2693ms).
[14:38:12.948] INFO: Test took 3931ms.
[14:38:12.981] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:13.707] INFO: Expecting 41600 events.
[14:38:16.896] INFO: 41600 events read in total (2662ms).
[14:38:16.897] INFO: Test took 3898ms.
[14:38:16.930] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:17.658] INFO: Expecting 41600 events.
[14:38:20.889] INFO: 41600 events read in total (2704ms).
[14:38:20.890] INFO: Test took 3942ms.
[14:38:20.922] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:21.646] INFO: Expecting 41600 events.
[14:38:24.862] INFO: 41600 events read in total (2689ms).
[14:38:24.863] INFO: Test took 3924ms.
[14:38:24.896] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:25.622] INFO: Expecting 41600 events.
[14:38:28.849] INFO: 41600 events read in total (2700ms).
[14:38:28.850] INFO: Test took 3937ms.
[14:38:28.883] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:29.609] INFO: Expecting 41600 events.
[14:38:32.830] INFO: 41600 events read in total (2694ms).
[14:38:32.831] INFO: Test took 3930ms.
[14:38:32.864] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:33.587] INFO: Expecting 41600 events.
[14:38:36.809] INFO: 41600 events read in total (2695ms).
[14:38:36.810] INFO: Test took 3928ms.
[14:38:36.843] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:37.562] INFO: Expecting 41600 events.
[14:38:40.799] INFO: 41600 events read in total (2710ms).
[14:38:40.800] INFO: Test took 3940ms.
[14:38:40.832] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:41.557] INFO: Expecting 41600 events.
[14:38:44.782] INFO: 41600 events read in total (2698ms).
[14:38:44.783] INFO: Test took 3934ms.
[14:38:44.816] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:45.541] INFO: Expecting 41600 events.
[14:38:48.746] INFO: 41600 events read in total (2679ms).
[14:38:48.747] INFO: Test took 3913ms.
[14:38:48.779] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:49.508] INFO: Expecting 41600 events.
[14:38:52.724] INFO: 41600 events read in total (2690ms).
[14:38:52.725] INFO: Test took 3927ms.
[14:38:52.758] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:53.488] INFO: Expecting 41600 events.
[14:38:56.712] INFO: 41600 events read in total (2697ms).
[14:38:56.712] INFO: Test took 3938ms.
[14:38:56.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:38:57.473] INFO: Expecting 41600 events.
[14:39:00.694] INFO: 41600 events read in total (2694ms).
[14:39:00.695] INFO: Test took 3932ms.
[14:39:00.727] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:01.455] INFO: Expecting 41600 events.
[14:39:04.665] INFO: 41600 events read in total (2683ms).
[14:39:04.666] INFO: Test took 3922ms.
[14:39:04.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:05.423] INFO: Expecting 41600 events.
[14:39:08.625] INFO: 41600 events read in total (2675ms).
[14:39:08.626] INFO: Test took 3910ms.
[14:39:08.659] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:09.385] INFO: Expecting 41600 events.
[14:39:12.451] INFO: 41600 events read in total (2539ms).
[14:39:12.452] INFO: Test took 3776ms.
[14:39:12.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:12.849] INFO: enter test to run
[14:39:24.546] INFO: test: HighRate no parameter change
[14:39:24.547] INFO: running: highrate
[14:39:24.548] INFO: ----------------------------------------------------------------------
[14:39:24.548] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:39:24.548] INFO: ----------------------------------------------------------------------
[14:39:25.161] INFO: Expecting 208000 events.
[14:39:36.929] INFO: 208000 events read in total (11241ms).
[14:39:36.932] INFO: Test took 12375ms.
[14:39:37.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:39:37.320] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 93 53 52 52 50 10 0 0
[14:39:37.320] INFO: number of red-efficiency pixels: 69 53 61 91 145 145 146 104 321 145 160 173 125 77 19 22
[14:39:37.320] INFO: number of X-ray hits detected: 60654 37495 61281 96094 109356 113288 106886 78788 91226 85846 91986 76199 81227 51614 18503 24733
[14:39:37.320] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:39:37.320] INFO: number of Vcal hits detected: 207931 207946 207938 207908 207855 207851 207850 207845 203109 205256 205289 205276 205422 207384 207978 207978
[14:39:37.320] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0
[14:39:37.320] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 99.9 97.6 98.7 98.7 98.7 98.8 99.7 100.0 100.0
[14:39:37.320] INFO: X-ray hit rate [MHz/cm2]: 17.8 11.0 18.0 28.2 32.1 33.2 31.3 23.1 26.7 25.2 27.0 22.3 23.8 15.1 5.4 7.2
[14:39:37.320] INFO: PixTestHighRate::doXPixelAlive() done
[14:39:37.370] INFO: PixTest:: pg_setup set to default.
[14:39:37.384] INFO: enter test to run
[14:39:56.610] INFO: test: HighRate no parameter change
[14:39:56.610] INFO: running: highrate
[14:39:56.612] INFO: ----------------------------------------------------------------------
[14:39:56.612] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:39:56.612] INFO: ----------------------------------------------------------------------
[14:39:57.227] INFO: Expecting 208000 events.
[14:40:10.471] INFO: 208000 events read in total (12717ms).
[14:40:10.476] INFO: Test took 13854ms.
[14:40:10.745] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:11.038] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 93 53 52 52 50 10 0 0
[14:40:11.038] INFO: number of red-efficiency pixels: 207 109 173 289 470 519 470 303 386 313 345 355 270 196 36 60
[14:40:11.038] INFO: number of X-ray hits detected: 121848 75102 123070 191436 219047 225918 214058 158952 170218 172016 184359 152016 161625 103186 37595 49589
[14:40:11.038] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:40:11.038] INFO: number of Vcal hits detected: 207768 207887 207815 207699 207485 207431 207493 207634 203039 205078 205096 205067 205269 207251 207964 207940
[14:40:11.038] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:40:11.038] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.7 99.8 99.8 97.6 98.6 98.6 98.6 98.7 99.6 100.0 100.0
[14:40:11.038] INFO: X-ray hit rate [MHz/cm2]: 35.7 22.0 36.1 56.1 64.2 66.2 62.7 46.6 49.9 50.4 54.0 44.6 47.4 30.2 11.0 14.5
[14:40:11.038] INFO: PixTestHighRate::doXPixelAlive() done
[14:40:11.089] INFO: PixTest:: pg_setup set to default.
[14:40:11.105] INFO: enter test to run
[14:40:37.066] INFO: test: HighRate no parameter change
[14:40:37.066] INFO: running: highrate
[14:40:37.068] INFO: ----------------------------------------------------------------------
[14:40:37.068] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:40:37.068] INFO: ----------------------------------------------------------------------
[14:40:37.690] INFO: Expecting 208000 events.
[14:40:52.718] INFO: 208000 events read in total (14501ms).
[14:40:52.724] INFO: Test took 15646ms.
[14:40:53.147] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:40:53.488] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 93 53 52 52 50 11 0 0
[14:40:53.488] INFO: number of red-efficiency pixels: 420 214 400 595 1029 1206 1116 624 609 685 667 673 508 421 62 97
[14:40:53.488] INFO: number of X-ray hits detected: 185230 114052 187216 290879 331582 342131 323957 241765 251519 258852 279176 231231 247258 157464 57380 75647
[14:40:53.488] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:40:53.488] INFO: number of Vcal hits detected: 207496 207774 207529 207324 206726 206436 206586 207189 202764 204634 204702 204694 205002 206972 207929 207902
[14:40:53.488] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.5 99.3 99.4 99.7 99.7 99.7 99.7 99.7 99.8 99.8 100.0 100.0
[14:40:53.488] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.4 99.2 99.3 99.6 97.5 98.4 98.4 98.4 98.6 99.5 100.0 100.0
[14:40:53.488] INFO: X-ray hit rate [MHz/cm2]: 54.3 33.4 54.9 85.3 97.2 100.3 95.0 70.9 73.7 75.9 81.8 67.8 72.5 46.2 16.8 22.2
[14:40:53.488] INFO: PixTestHighRate::doXPixelAlive() done
[14:40:53.534] INFO: PixTest:: pg_setup set to default.
[14:40:53.550] INFO: enter test to run
[14:41:04.530] INFO: test: exit no parameter change
[14:41:04.841] QUIET: Connection to board 33 closed.
[14:41:04.853] INFO: pXar: this is the end, my friend