[11:07:55.927] INFO: *** Welcome to pxar ***
[11:07:55.927] INFO: *** Today: 2016/06/10
[11:07:55.955] INFO: *** Version: v1.9.0-814-g7497
[11:07:55.955] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//dacParameters35_C15.dat
[11:07:55.979] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:07:55.979] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//defaultMaskFile.dat
[11:07:55.989] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C15.dat
[11:07:56.075] INFO: clk: 4
[11:07:56.075] INFO: ctr: 4
[11:07:56.075] INFO: sda: 19
[11:07:56.075] INFO: tin: 9
[11:07:56.075] INFO: level: 15
[11:07:56.075] INFO: triggerdelay: 0
[11:07:56.075] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:07:56.075] INFO: Log level: INFO
[11:07:56.091] QUIET: Connection to board DTB_WREKRL opened.
[11:07:56.094] 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:
------------------------------------------------------
[11:07:56.097] INFO: RPC call hashes of host and DTB match: 398089610
[11:07:57.627] INFO: DUT info:
[11:07:57.627] INFO: The DUT currently contains the following objects:
[11:07:57.627] INFO: 2 TBM Cores tbm08c (2 ON)
[11:07:57.627] INFO: TBM Core alpha (0): 7 registers set
[11:07:57.627] INFO: TBM Core beta (1): 7 registers set
[11:07:57.627] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:07:57.628] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:57.628] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:07:58.032] INFO: enter 'restricted' command line mode
[11:07:58.032] INFO: enter test to run
[11:08:04.907] INFO: test: PixelAlive no parameter change
[11:08:04.908] INFO: running: pixelalive
[11:08:04.916] INFO: ----------------------------------------------------------------------
[11:08:04.916] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:08:04.916] INFO: ----------------------------------------------------------------------
[11:08:05.239] INFO: Expecting 41600 events.
[11:08:09.536] INFO: 41600 events read in total (3578ms).
[11:08:09.700] INFO: Test took 4781ms.
[11:08:09.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:08:09.984] INFO: PixTestAlive::aliveTest() done
[11:08:09.984] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[11:08:10.015] INFO: enter test to run
[11:08:54.675] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:08:54.675] INFO: running: highrate
[11:08:54.675] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:08:54.898] INFO: ----------------------------------------------------------------------
[11:08:54.898] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:08:54.898] INFO: ----------------------------------------------------------------------
[11:08:54.898] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:08:54.898] INFO: edge/corner pixel THR is adjusted
[11:08:54.898] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:08:55.856] INFO: Collecting data for 5 seconds...
[11:09:00.875] INFO: Done with hot pixel readout
[11:09:13.063] INFO: PixTest:: pg_setup set to default.
[11:09:13.063] INFO: 21 hot pixels found in step 0
[11:09:14.055] INFO: Collecting data for 5 seconds...
[11:09:19.075] INFO: Done with hot pixel readout
[11:09:31.379] INFO: PixTest:: pg_setup set to default.


[11:09:31.379] INFO: 18 hot pixels found in step 1
[11:09:32.375] INFO: Collecting data for 5 seconds...
[11:09:37.395] INFO: Done with hot pixel readout
[11:09:49.634] INFO: PixTest:: pg_setup set to default.
[11:09:49.635] INFO: 12 hot pixels found in step 2
[11:09:50.631] INFO: Collecting data for 5 seconds...
[11:09:55.649] INFO: Done with hot pixel readout
[11:10:07.860] INFO: PixTest:: pg_setup set to default.


[11:10:07.861] INFO: 16 hot pixels found in step 3
[11:10:08.857] INFO: Collecting data for 5 seconds...
[11:10:13.875] INFO: Done with hot pixel readout
[11:10:26.162] INFO: PixTest:: pg_setup set to default.


[11:10:26.163] INFO: 18 hot pixels found in step 4
[11:10:27.159] INFO: Collecting data for 5 seconds...
[11:10:32.176] INFO: Done with hot pixel readout
[11:10:44.248] INFO: PixTest:: pg_setup set to default.

[11:10:44.249] INFO: 9 hot pixels found in step 5
[11:10:45.244] INFO: Collecting data for 5 seconds...
[11:10:50.261] INFO: Done with hot pixel readout
[11:11:02.349] INFO: PixTest:: pg_setup set to default.

[11:11:02.350] INFO: 12 hot pixels found in step 6
[11:11:03.345] INFO: Collecting data for 5 seconds...
[11:11:08.362] INFO: Done with hot pixel readout
[11:11:20.440] INFO: PixTest:: pg_setup set to default.

[11:11:20.441] INFO: 17 hot pixels found in step 7
[11:11:21.436] INFO: Collecting data for 5 seconds...
[11:11:26.453] INFO: Done with hot pixel readout
[11:11:38.524] INFO: PixTest:: pg_setup set to default.
[11:11:38.525] INFO: 8 hot pixels found in step 8
[11:11:39.519] INFO: Collecting data for 5 seconds...
[11:11:44.536] INFO: Done with hot pixel readout
[11:11:56.604] INFO: PixTest:: pg_setup set to default.

[11:11:56.605] INFO: 13 hot pixels found in step 9
[11:11:57.599] INFO: Collecting data for 5 seconds...
[11:12:02.616] INFO: Done with hot pixel readout
[11:12:14.462] INFO: PixTest:: pg_setup set to default.



[11:12:14.463] INFO: 19 hot pixels found in step 10
[11:12:15.458] INFO: Collecting data for 5 seconds...
[11:12:20.475] INFO: Done with hot pixel readout
[11:12:32.579] INFO: PixTest:: pg_setup set to default.


[11:12:32.580] INFO: 16 hot pixels found in step 11
[11:12:33.574] INFO: Collecting data for 5 seconds...
[11:12:38.591] INFO: Done with hot pixel readout
[11:12:50.644] INFO: PixTest:: pg_setup set to default.



[11:12:50.646] INFO: 15 hot pixels found in step 12
[11:12:51.641] INFO: Collecting data for 5 seconds...
[11:12:56.659] INFO: Done with hot pixel readout
[11:13:08.728] INFO: PixTest:: pg_setup set to default.


[11:13:08.729] INFO: 17 hot pixels found in step 13
[11:13:09.723] INFO: Collecting data for 5 seconds...
[11:13:14.740] INFO: Done with hot pixel readout
[11:13:26.785] INFO: PixTest:: pg_setup set to default.


[11:13:26.786] INFO: 10 hot pixels found in step 14
[11:13:26.826] INFO: 10 hot pixels could not be trimmed and have been masked.
[11:13:26.829] INFO: PixTest::trimHotPixels() done
[11:13:26.830] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C0.dat
[11:13:26.835] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C1.dat
[11:13:26.858] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C2.dat
[11:13:26.870] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C3.dat
[11:13:26.879] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C4.dat
[11:13:26.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C5.dat
[11:13:26.890] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C6.dat
[11:13:26.895] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C7.dat
[11:13:26.900] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C8.dat
[11:13:26.906] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C9.dat
[11:13:26.911] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C10.dat
[11:13:26.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C11.dat
[11:13:26.922] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C12.dat
[11:13:26.927] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C13.dat
[11:13:26.932] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C14.dat
[11:13:26.937] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C15.dat
[11:13:26.943] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//defaultMaskFile.dat
[11:13:26.961] INFO: enter test to run
[11:14:36.977] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:14:36.977] INFO: running: highrate
[11:14:36.981] INFO: ----------------------------------------------------------------------
[11:14:36.982] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:14:36.982] INFO: ----------------------------------------------------------------------
[11:14:36.982] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:14:36.982] INFO: edge/corner pixel THR is adjusted
[11:14:36.982] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:14:37.940] INFO: Collecting data for 1 seconds...
[11:14:38.944] INFO: Done with hot pixel readout
[11:14:43.030] INFO: PixTest:: pg_setup set to default.
[11:14:43.031] INFO: 0 hot pixels found in step 0
[11:14:43.038] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:14:43.120] INFO: PixTest::trimHotPixels() done
[11:14:43.121] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C0.dat
[11:14:43.128] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C1.dat
[11:14:43.133] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C2.dat
[11:14:43.139] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C3.dat
[11:14:43.144] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C4.dat
[11:14:43.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C5.dat
[11:14:43.154] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C6.dat
[11:14:43.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C7.dat
[11:14:43.165] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C8.dat
[11:14:43.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C9.dat
[11:14:43.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C10.dat
[11:14:43.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C11.dat
[11:14:43.186] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C12.dat
[11:14:43.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C13.dat
[11:14:43.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C14.dat
[11:14:43.201] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//trimParameters35_C15.dat
[11:14:43.206] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-1-08_FPIXTest-17C-FNAL-160608-1416_2016-06-08_14h16m_1465413417/000_FPIXTest_p17//defaultMaskFile.dat
[11:14:43.222] INFO: enter test to run
[11:17:00.607] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:17:00.608] INFO: running: xray
[11:17:00.609] INFO: ----------------------------------------------------------------------
[11:17:00.609] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:17:00.609] INFO: ----------------------------------------------------------------------
[11:17:01.574] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:17:12.740] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:17:42.317] INFO: Resuming triggers.
[11:17:53.489] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:18:22.990] INFO: Resuming triggers.
[11:18:34.163] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:19:04.162] INFO: Resuming triggers.
[11:19:15.335] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[11:19:41.321] INFO: Resuming triggers.
[11:19:52.495] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[11:20:21.900] INFO: Resuming triggers.
[11:20:33.072] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[11:21:03.731] INFO: Resuming triggers.
[11:21:14.905] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[11:21:44.833] INFO: Resuming triggers.
[11:21:56.005] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[11:22:25.480] INFO: Resuming triggers.
[11:22:36.461] INFO: data taking finished, elapsed time: 100 seconds.
[11:23:01.658] INFO: PixTest:: pg_setup set to default.
[11:23:01.662] INFO: PixTestXray::doPhRun() done
[11:23:01.824] INFO: enter test to run
[11:23:24.549] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:23:24.549] INFO: running: xray
[11:23:24.550] INFO: ----------------------------------------------------------------------
[11:23:24.550] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:23:24.550] INFO: ----------------------------------------------------------------------
[11:23:25.524] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:23:31.955] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:24:02.209] INFO: Resuming triggers.
[11:24:08.639] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[11:24:38.003] INFO: Resuming triggers.
[11:24:45.436] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[11:25:15.827] INFO: Resuming triggers.
[11:25:22.258] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[11:25:52.634] INFO: Resuming triggers.
[11:25:59.064] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[11:26:29.445] INFO: Resuming triggers.
[11:26:35.878] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[11:27:06.310] INFO: Resuming triggers.
[11:27:12.746] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[11:27:42.978] INFO: Resuming triggers.
[11:27:49.415] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[11:28:18.530] INFO: Resuming triggers.
[11:28:24.966] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[11:28:55.604] INFO: Resuming triggers.
[11:29:02.039] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[11:29:31.960] INFO: Resuming triggers.
[11:29:38.397] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[11:30:09.250] INFO: Resuming triggers.
[11:30:15.687] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[11:30:46.266] INFO: Resuming triggers.
[11:30:52.705] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[11:31:22.546] INFO: Resuming triggers.
[11:31:28.982] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[11:31:59.966] INFO: Resuming triggers.
[11:32:06.398] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[11:32:37.151] INFO: Resuming triggers.
[11:32:40.990] INFO: data taking finished, elapsed time: 100 seconds.
[11:32:59.667] INFO: PixTest:: pg_setup set to default.
[11:32:59.670] INFO: PixTestXray::doPhRun() done
[11:32:59.823] INFO: enter test to run
[11:33:46.240] INFO: test: HighRate no parameter change
[11:33:46.240] INFO: running: highrate
[11:33:46.253] INFO: ----------------------------------------------------------------------
[11:33:46.253] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:33:46.276] INFO: ----------------------------------------------------------------------
[11:33:46.434] INFO: Expecting 768 events.
[11:33:47.567] INFO: 768 events read in total (417ms).
[11:33:47.567] INFO: Test took 1268ms.
[11:33:48.370] INFO: Expecting 41600 events.
[11:33:51.445] INFO: 41600 events read in total (2548ms).
[11:33:51.446] INFO: Test took 3852ms.
[11:33:51.478] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:52.205] INFO: Expecting 41600 events.
[11:33:55.399] INFO: 41600 events read in total (2667ms).
[11:33:55.400] INFO: Test took 3904ms.
[11:33:55.433] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:33:56.159] INFO: Expecting 41600 events.
[11:33:59.383] INFO: 41600 events read in total (2698ms).
[11:33:59.384] INFO: Test took 3934ms.
[11:33:59.417] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:00.142] INFO: Expecting 41600 events.
[11:34:03.375] INFO: 41600 events read in total (2706ms).
[11:34:03.376] INFO: Test took 3942ms.
[11:34:03.412] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:04.129] INFO: Expecting 41600 events.
[11:34:07.349] INFO: 41600 events read in total (2694ms).
[11:34:07.350] INFO: Test took 3919ms.
[11:34:07.384] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:08.105] INFO: Expecting 41600 events.
[11:34:11.321] INFO: 41600 events read in total (2689ms).
[11:34:11.322] INFO: Test took 3921ms.
[11:34:11.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:12.078] INFO: Expecting 41600 events.
[11:34:15.307] INFO: 41600 events read in total (2702ms).
[11:34:15.308] INFO: Test took 3935ms.
[11:34:15.341] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:16.067] INFO: Expecting 41600 events.
[11:34:19.301] INFO: 41600 events read in total (2707ms).
[11:34:19.302] INFO: Test took 3943ms.
[11:34:19.336] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:20.058] INFO: Expecting 41600 events.
[11:34:23.302] INFO: 41600 events read in total (2717ms).
[11:34:23.303] INFO: Test took 3948ms.
[11:34:23.337] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:24.062] INFO: Expecting 41600 events.
[11:34:27.304] INFO: 41600 events read in total (2715ms).
[11:34:27.305] INFO: Test took 3951ms.
[11:34:27.339] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:28.061] INFO: Expecting 41600 events.
[11:34:31.292] INFO: 41600 events read in total (2705ms).
[11:34:31.293] INFO: Test took 3936ms.
[11:34:31.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:32.053] INFO: Expecting 41600 events.
[11:34:35.288] INFO: 41600 events read in total (2708ms).
[11:34:35.289] INFO: Test took 3944ms.
[11:34:35.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:36.048] INFO: Expecting 41600 events.
[11:34:39.283] INFO: 41600 events read in total (2708ms).
[11:34:39.284] INFO: Test took 3943ms.
[11:34:39.317] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:40.041] INFO: Expecting 41600 events.
[11:34:43.241] INFO: 41600 events read in total (2673ms).
[11:34:43.242] INFO: Test took 3906ms.
[11:34:43.276] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:43.999] INFO: Expecting 41600 events.
[11:34:47.238] INFO: 41600 events read in total (2712ms).
[11:34:47.239] INFO: Test took 3945ms.
[11:34:47.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:47.996] INFO: Expecting 41600 events.
[11:34:51.245] INFO: 41600 events read in total (2722ms).
[11:34:51.246] INFO: Test took 3955ms.
[11:34:51.280] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:51.002] INFO: Expecting 41600 events.
[11:34:55.242] INFO: 41600 events read in total (2714ms).
[11:34:55.243] INFO: Test took 3944ms.
[11:34:55.278] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:55.999] INFO: Expecting 41600 events.
[11:34:59.224] INFO: 41600 events read in total (2698ms).
[11:34:59.225] INFO: Test took 3929ms.
[11:34:59.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:34:59.981] INFO: Expecting 41600 events.
[11:35:03.200] INFO: 41600 events read in total (2692ms).
[11:35:03.201] INFO: Test took 3925ms.
[11:35:03.235] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:03.962] INFO: Expecting 41600 events.
[11:35:07.037] INFO: 41600 events read in total (2548ms).
[11:35:07.038] INFO: Test took 3784ms.
[11:35:07.071] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:07.436] INFO: enter test to run
[11:35:27.855] INFO: test: HighRate no parameter change
[11:35:27.855] INFO: running: highrate
[11:35:27.857] INFO: ----------------------------------------------------------------------
[11:35:27.857] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:35:27.857] INFO: ----------------------------------------------------------------------
[11:35:28.474] INFO: Expecting 208000 events.
[11:35:40.284] INFO: 208000 events read in total (11283ms).
[11:35:40.287] INFO: Test took 12422ms.
[11:35:40.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:35:40.682] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[11:35:40.683] INFO: number of red-efficiency pixels: 77 58 78 99 115 155 129 101 84 120 86 81 97 58 23 27
[11:35:40.683] INFO: number of X-ray hits detected: 61103 43696 67830 103412 113871 116191 117543 81956 78392 95552 91055 80459 85262 50148 21349 25040
[11:35:40.683] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:35:40.683] INFO: number of Vcal hits detected: 207921 207939 207918 207899 207883 207839 207868 207895 207916 207878 207913 207918 207899 207891 207977 207973
[11:35:40.683] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[11:35:40.683] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0 99.9 100.0 100.0
[11:35:40.683] INFO: X-ray hit rate [MHz/cm2]: 17.9 12.8 19.9 30.3 33.4 34.1 34.5 24.0 23.0 28.0 26.7 23.6 25.0 14.7 6.3 7.3
[11:35:40.683] INFO: PixTestHighRate::doXPixelAlive() done
[11:35:40.727] INFO: PixTest:: pg_setup set to default.
[11:35:40.740] INFO: enter test to run
[11:36:16.031] INFO: test: HighRate no parameter change
[11:36:16.031] INFO: running: highrate
[11:36:16.032] INFO: ----------------------------------------------------------------------
[11:36:16.032] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:36:16.032] INFO: ----------------------------------------------------------------------
[11:36:16.647] INFO: Expecting 208000 events.
[11:36:30.460] INFO: 208000 events read in total (13286ms).
[11:36:30.465] INFO: Test took 14424ms.
[11:36:30.786] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:36:31.094] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[11:36:31.094] INFO: number of red-efficiency pixels: 231 161 330 419 415 645 449 285 250 454 315 321 359 205 61 61
[11:36:31.094] INFO: number of X-ray hits detected: 134617 96052 151200 229712 251115 258123 259795 181588 175521 211630 202540 178151 189355 111147 47096 55308
[11:36:31.094] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:36:31.094] INFO: number of Vcal hits detected: 207749 207834 207619 207551 207548 207271 207504 207686 207739 207507 207660 207660 207616 207730 207938 207938
[11:36:31.094] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[11:36:31.094] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.6 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[11:36:31.094] INFO: X-ray hit rate [MHz/cm2]: 39.5 28.2 44.3 67.3 73.6 75.7 76.1 53.2 51.4 62.0 59.4 52.2 55.5 32.6 13.8 16.2
[11:36:31.094] INFO: PixTestHighRate::doXPixelAlive() done
[11:36:31.151] INFO: PixTest:: pg_setup set to default.
[11:36:31.165] INFO: enter test to run
[11:36:50.511] INFO: test: HighRate no parameter change
[11:36:50.511] INFO: running: highrate
[11:36:50.512] INFO: ----------------------------------------------------------------------
[11:36:50.512] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:36:50.512] INFO: ----------------------------------------------------------------------
[11:36:51.129] INFO: Expecting 208000 events.
[11:37:07.095] INFO: 208000 events read in total (15439ms).
[11:37:07.103] INFO: Test took 16580ms.
[11:37:07.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:37:07.962] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0
[11:37:07.962] INFO: number of red-efficiency pixels: 517 320 764 1137 1082 1519 1189 643 574 1052 776 797 917 418 86 112
[11:37:07.962] INFO: number of X-ray hits detected: 206595 147992 233182 349723 386423 395332 398227 278449 268013 323705 311739 272729 291022 171800 72089 85009
[11:37:07.962] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:37:07.962] INFO: number of Vcal hits detected: 207381 207640 206894 206569 206661 205803 206503 207194 207347 206694 207081 207066 206925 207472 207912 207888
[11:37:07.962] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.5 99.4 99.4 99.1 99.4 99.7 99.7 99.4 99.6 99.6 99.5 99.8 100.0 99.9
[11:37:07.963] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.3 99.4 98.9 99.3 99.6 99.7 99.4 99.6 99.6 99.5 99.7 100.0 99.9
[11:37:07.963] INFO: X-ray hit rate [MHz/cm2]: 60.6 43.4 68.3 102.5 113.3 115.9 116.7 81.6 78.6 94.9 91.4 79.9 85.3 50.4 21.1 24.9
[11:37:07.963] INFO: PixTestHighRate::doXPixelAlive() done
[11:37:08.011] INFO: PixTest:: pg_setup set to default.
[11:37:08.028] INFO: enter test to run
[11:37:12.950] INFO: test: exit no parameter change
[11:37:13.331] QUIET: Connection to board 33 closed.
[11:37:13.341] INFO: pXar: this is the end, my friend