[10:58:16.875] INFO: *** Welcome to pxar ***
[10:58:16.875] INFO: *** Today: 2016/05/04
[10:58:17.020] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:58:17.020] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//dacParameters35_C15.dat
[10:58:17.048] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:58:17.048] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//defaultMaskFile.dat
[10:58:17.049] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C15.dat
[10:58:17.168] INFO: clk: 4
[10:58:17.168] INFO: ctr: 4
[10:58:17.168] INFO: sda: 19
[10:58:17.168] INFO: tin: 9
[10:58:17.168] INFO: level: 15
[10:58:17.168] INFO: triggerdelay: 0
[10:58:17.168] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:58:17.168] INFO: Log level: INFO
[10:58:17.186] QUIET: Connection to board DTB_WREK4U opened.
[10:58:17.189] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[10:58:17.192] INFO: RPC call hashes of host and DTB match: 398089610
[10:58:18.720] INFO: DUT info:
[10:58:18.720] INFO: The DUT currently contains the following objects:
[10:58:18.720] INFO: 2 TBM Cores tbm08c (2 ON)
[10:58:18.720] INFO: TBM Core alpha (0): 7 registers set
[10:58:18.720] INFO: TBM Core beta (1): 7 registers set
[10:58:18.721] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:58:18.721] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:18.721] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:58:19.124] INFO: enter 'restricted' command line mode
[10:58:19.124] INFO: enter test to run
[11:01:09.775] INFO: test: PixelAlive no parameter change
[11:01:09.775] INFO: running: pixelalive
[11:01:09.784] INFO: ----------------------------------------------------------------------
[11:01:09.784] 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:01:09.784] INFO: ----------------------------------------------------------------------
[11:01:10.100] INFO: Expecting 41600 events.
[11:01:14.438] INFO: 41600 events read in total (3620ms).
[11:01:14.605] INFO: Test took 4819ms.
[11:01:14.618] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:01:14.879] INFO: PixTestAlive::aliveTest() done
[11:01:14.879] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 6 0 0 0 0 0 0
[11:01:14.913] INFO: enter test to run
[11:02:44.622] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:02:44.622] INFO: running: highrate
[11:02:44.622] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:02:44.951] INFO: ----------------------------------------------------------------------
[11:02:44.951] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:02:44.951] INFO: ----------------------------------------------------------------------
[11:02:44.951] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:02:44.952] INFO: edge/corner pixel THR is adjusted
[11:02:44.952] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:02:45.910] INFO: Collecting data for 5 seconds...
[11:02:50.926] INFO: Done with hot pixel readout
[11:03:03.514] INFO: PixTest:: pg_setup set to default.
[11:03:03.515] INFO: 38 hot pixels found in step 0
[11:03:04.509] INFO: Collecting data for 5 seconds...
[11:03:09.526] INFO: Done with hot pixel readout
[11:03:22.074] INFO: PixTest:: pg_setup set to default.

[11:03:22.075] INFO: 35 hot pixels found in step 1
[11:03:23.076] INFO: Collecting data for 5 seconds...
[11:03:28.091] INFO: Done with hot pixel readout
[11:03:40.680] INFO: PixTest:: pg_setup set to default.
[11:03:40.681] INFO: 37 hot pixels found in step 2
[11:03:41.680] INFO: Collecting data for 5 seconds...
[11:03:46.703] INFO: Done with hot pixel readout
[11:03:59.444] INFO: PixTest:: pg_setup set to default.


[11:03:59.445] INFO: 29 hot pixels found in step 3
[11:04:00.444] INFO: Collecting data for 5 seconds...
[11:04:05.464] INFO: Done with hot pixel readout
[11:04:18.176] INFO: PixTest:: pg_setup set to default.


[11:04:18.177] INFO: 30 hot pixels found in step 4
[11:04:19.175] INFO: Collecting data for 5 seconds...
[11:04:24.192] INFO: Done with hot pixel readout
[11:04:36.743] INFO: PixTest:: pg_setup set to default.
[11:04:36.744] INFO: 30 hot pixels found in step 5
[11:04:37.743] INFO: Collecting data for 5 seconds...
[11:04:42.761] INFO: Done with hot pixel readout
[11:04:55.475] INFO: PixTest:: pg_setup set to default.
[11:04:55.476] INFO: 31 hot pixels found in step 6
[11:04:56.475] INFO: Collecting data for 5 seconds...
[11:05:01.494] INFO: Done with hot pixel readout
[11:05:14.330] INFO: PixTest:: pg_setup set to default.

[11:05:14.331] INFO: 13 hot pixels found in step 7
[11:05:15.329] INFO: Collecting data for 5 seconds...
[11:05:20.349] INFO: Done with hot pixel readout
[11:05:32.945] INFO: PixTest:: pg_setup set to default.



[11:05:32.948] INFO: 30 hot pixels found in step 8
[11:05:33.949] INFO: Collecting data for 5 seconds...
[11:05:38.966] INFO: Done with hot pixel readout
[11:05:51.535] INFO: PixTest:: pg_setup set to default.

[11:05:51.536] INFO: 20 hot pixels found in step 9
[11:05:52.533] INFO: Collecting data for 5 seconds...
[11:05:57.550] INFO: Done with hot pixel readout
[11:06:10.113] INFO: PixTest:: pg_setup set to default.


[11:06:10.114] INFO: 22 hot pixels found in step 10
[11:06:11.113] INFO: Collecting data for 5 seconds...
[11:06:16.130] INFO: Done with hot pixel readout
[11:06:28.712] INFO: PixTest:: pg_setup set to default.
[11:06:28.713] INFO: 20 hot pixels found in step 11
[11:06:29.712] INFO: Collecting data for 5 seconds...
[11:06:34.728] INFO: Done with hot pixel readout
[11:06:47.433] INFO: PixTest:: pg_setup set to default.



[11:06:47.434] INFO: 21 hot pixels found in step 12
[11:06:48.432] INFO: Collecting data for 5 seconds...
[11:06:53.450] INFO: Done with hot pixel readout
[11:07:05.892] INFO: PixTest:: pg_setup set to default.

[11:07:05.893] INFO: 15 hot pixels found in step 13
[11:07:06.892] INFO: Collecting data for 5 seconds...
[11:07:11.909] INFO: Done with hot pixel readout
[11:07:24.276] INFO: PixTest:: pg_setup set to default.

[11:07:24.277] INFO: 14 hot pixels found in step 14
[11:07:24.319] INFO: 14 hot pixels could not be trimmed and have been masked.
[11:07:24.323] INFO: PixTest::trimHotPixels() done
[11:07:24.338] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C0.dat
[11:07:24.350] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C1.dat
[11:07:24.356] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C2.dat
[11:07:24.362] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C3.dat
[11:07:24.368] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C4.dat
[11:07:24.373] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C5.dat
[11:07:24.378] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C6.dat
[11:07:24.384] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C7.dat
[11:07:24.389] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C8.dat
[11:07:24.395] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C9.dat
[11:07:24.400] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C10.dat
[11:07:24.406] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C11.dat
[11:07:24.411] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C12.dat
[11:07:24.416] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C13.dat
[11:07:24.422] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C14.dat
[11:07:24.427] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C15.dat
[11:07:24.433] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//defaultMaskFile.dat
[11:07:24.443] INFO: enter test to run
[11:08:53.499] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:08:53.499] INFO: running: highrate
[11:08:53.504] INFO: ----------------------------------------------------------------------
[11:08:53.504] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:08:53.504] INFO: ----------------------------------------------------------------------
[11:08:53.504] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:08:53.504] INFO: edge/corner pixel THR is adjusted
[11:08:53.504] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:08:54.462] INFO: Collecting data for 1 seconds...
[11:08:55.466] INFO: Done with hot pixel readout
[11:08:59.935] INFO: PixTest:: pg_setup set to default.
[11:08:59.936] INFO: 0 hot pixels found in step 0
[11:08:59.941] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:09:00.015] INFO: PixTest::trimHotPixels() done
[11:09:00.015] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C0.dat
[11:09:00.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C1.dat
[11:09:00.031] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C2.dat
[11:09:00.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C3.dat
[11:09:00.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C4.dat
[11:09:00.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C5.dat
[11:09:00.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C6.dat
[11:09:00.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C7.dat
[11:09:00.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C8.dat
[11:09:00.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C9.dat
[11:09:00.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C10.dat
[11:09:00.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C11.dat
[11:09:00.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C12.dat
[11:09:00.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C13.dat
[11:09:00.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C14.dat
[11:09:00.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//trimParameters35_C15.dat
[11:09:00.104] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-B-NP_FPIXTest-17C-FNAL-160502-0930_2016-05-02_09h30m_1462199444/000_FPIXTest_p17//defaultMaskFile.dat
[11:09:00.114] INFO: enter test to run
[11:09:19.515] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:09:19.515] INFO: running: xray
[11:09:19.516] INFO: ----------------------------------------------------------------------
[11:09:19.516] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:09:19.516] INFO: ----------------------------------------------------------------------
[11:09:20.479] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:09:31.142] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[11:10:00.728] INFO: Resuming triggers.
[11:10:11.390] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[11:10:41.126] INFO: Resuming triggers.
[11:10:51.786] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[11:11:21.468] INFO: Resuming triggers.
[11:11:32.128] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[11:12:01.788] INFO: Resuming triggers.
[11:12:12.444] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[11:12:42.194] INFO: Resuming triggers.
[11:12:52.853] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[11:13:22.314] INFO: Resuming triggers.
[11:13:32.974] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[11:14:02.634] INFO: Resuming triggers.
[11:14:13.292] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[11:14:43.470] INFO: Resuming triggers.
[11:14:54.132] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[11:15:24.432] INFO: Resuming triggers.
[11:15:28.832] INFO: data taking finished, elapsed time: 100 seconds.
[11:15:41.924] INFO: PixTest:: pg_setup set to default.
[11:15:41.927] INFO: PixTestXray::doPhRun() done
[11:15:42.076] INFO: enter test to run
[11:16:22.904] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:16:22.904] INFO: running: xray
[11:16:22.905] INFO: ----------------------------------------------------------------------
[11:16:22.905] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:16:22.905] INFO: ----------------------------------------------------------------------
[11:16:23.868] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:16:29.711] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[11:16:59.890] INFO: Resuming triggers.
[11:17:05.733] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:17:35.946] INFO: Resuming triggers.
[11:17:41.790] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[11:18:12.646] INFO: Resuming triggers.
[11:18:18.490] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[11:18:48.515] INFO: Resuming triggers.
[11:18:54.361] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[11:19:24.517] INFO: Resuming triggers.
[11:19:30.358] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[11:20:00.481] INFO: Resuming triggers.
[11:20:06.324] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[11:20:36.539] INFO: Resuming triggers.
[11:20:42.380] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[11:21:12.606] INFO: Resuming triggers.
[11:21:18.446] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[11:21:48.638] INFO: Resuming triggers.
[11:21:54.481] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[11:22:24.736] INFO: Resuming triggers.
[11:22:30.579] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[11:23:00.858] INFO: Resuming triggers.
[11:23:06.700] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[11:23:36.954] INFO: Resuming triggers.
[11:23:42.797] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[11:24:12.973] INFO: Resuming triggers.
[11:24:18.815] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:24:48.953] INFO: Resuming triggers.
[11:24:54.795] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[11:25:25.079] INFO: Resuming triggers.
[11:25:30.920] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[11:26:02.195] INFO: Resuming triggers.
[11:26:08.039] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[11:26:39.808] INFO: Resuming triggers.
[11:26:40.816] INFO: data taking finished, elapsed time: 100 seconds.
[11:26:46.590] INFO: PixTest:: pg_setup set to default.
[11:26:46.593] INFO: PixTestXray::doPhRun() done
[11:26:46.748] INFO: enter test to run
[11:27:20.147] INFO: test: HighRate no parameter change
[11:27:20.147] INFO: running: highrate
[11:27:20.148] INFO: ----------------------------------------------------------------------
[11:27:20.148] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:27:20.148] INFO: ----------------------------------------------------------------------
[11:27:20.321] INFO: Expecting 768 events.
[11:27:21.455] INFO: 768 events read in total (419ms).
[11:27:21.455] INFO: Test took 1268ms.
[11:27:22.258] INFO: Expecting 41600 events.
[11:27:25.444] INFO: 41600 events read in total (2659ms).
[11:27:25.445] INFO: Test took 3963ms.
[11:27:25.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:26.203] INFO: Expecting 41600 events.
[11:27:29.479] INFO: 41600 events read in total (2750ms).
[11:27:29.481] INFO: Test took 3977ms.
[11:27:29.521] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:30.236] INFO: Expecting 41600 events.
[11:27:33.547] INFO: 41600 events read in total (2784ms).
[11:27:33.549] INFO: Test took 4009ms.
[11:27:33.589] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:34.303] INFO: Expecting 41600 events.
[11:27:37.612] INFO: 41600 events read in total (2782ms).
[11:27:37.613] INFO: Test took 4004ms.
[11:27:37.653] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:38.363] INFO: Expecting 41600 events.
[11:27:41.660] INFO: 41600 events read in total (2770ms).
[11:27:41.661] INFO: Test took 3988ms.
[11:27:41.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:42.415] INFO: Expecting 41600 events.
[11:27:45.714] INFO: 41600 events read in total (2773ms).
[11:27:45.715] INFO: Test took 3993ms.
[11:27:45.756] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:46.468] INFO: Expecting 41600 events.
[11:27:49.770] INFO: 41600 events read in total (2775ms).
[11:27:49.771] INFO: Test took 3994ms.
[11:27:49.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:50.524] INFO: Expecting 41600 events.
[11:27:53.834] INFO: 41600 events read in total (2783ms).
[11:27:53.836] INFO: Test took 4006ms.
[11:27:53.876] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:54.586] INFO: Expecting 41600 events.
[11:27:57.880] INFO: 41600 events read in total (2767ms).
[11:27:57.881] INFO: Test took 3984ms.
[11:27:57.921] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:58.633] INFO: Expecting 41600 events.
[11:28:01.938] INFO: 41600 events read in total (2779ms).
[11:28:01.939] INFO: Test took 3998ms.
[11:28:01.980] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:02.692] INFO: Expecting 41600 events.
[11:28:06.007] INFO: 41600 events read in total (2788ms).
[11:28:06.008] INFO: Test took 4007ms.
[11:28:06.048] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:06.761] INFO: Expecting 41600 events.
[11:28:10.059] INFO: 41600 events read in total (2771ms).
[11:28:10.060] INFO: Test took 3990ms.
[11:28:10.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:10.810] INFO: Expecting 41600 events.
[11:28:14.119] INFO: 41600 events read in total (2782ms).
[11:28:14.120] INFO: Test took 3997ms.
[11:28:14.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:14.872] INFO: Expecting 41600 events.
[11:28:18.173] INFO: 41600 events read in total (2774ms).
[11:28:18.174] INFO: Test took 3994ms.
[11:28:18.214] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:18.927] INFO: Expecting 41600 events.
[11:28:22.231] INFO: 41600 events read in total (2777ms).
[11:28:22.232] INFO: Test took 3998ms.
[11:28:22.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:22.986] INFO: Expecting 41600 events.
[11:28:26.286] INFO: 41600 events read in total (2774ms).
[11:28:26.287] INFO: Test took 3992ms.
[11:28:26.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:27.041] INFO: Expecting 41600 events.
[11:28:30.363] INFO: 41600 events read in total (2795ms).
[11:28:30.364] INFO: Test took 4018ms.
[11:28:30.405] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:31.115] INFO: Expecting 41600 events.
[11:28:34.432] INFO: 41600 events read in total (2790ms).
[11:28:34.433] INFO: Test took 4008ms.
[11:28:34.474] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:35.183] INFO: Expecting 41600 events.
[11:28:38.480] INFO: 41600 events read in total (2770ms).
[11:28:38.481] INFO: Test took 3987ms.
[11:28:38.521] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:39.236] INFO: Expecting 41600 events.
[11:28:42.410] INFO: 41600 events read in total (2647ms).
[11:28:42.411] INFO: Test took 3870ms.
[11:28:42.451] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:42.803] INFO: enter test to run
[11:29:02.490] INFO: test: HighRate no parameter change
[11:29:02.490] INFO: running: highrate
[11:29:02.492] INFO: ----------------------------------------------------------------------
[11:29:02.492] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:29:02.492] INFO: ----------------------------------------------------------------------
[11:29:03.116] INFO: Expecting 208000 events.
[11:29:15.388] INFO: 208000 events read in total (11746ms).
[11:29:15.391] INFO: Test took 12891ms.
[11:29:15.576] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:15.841] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 6 0 0 0 0 0 0
[11:29:15.841] INFO: number of red-efficiency pixels: 80 78 119 132 178 155 163 125 131 153 178 130 119 72 30 42
[11:29:15.841] INFO: number of X-ray hits detected: 78958 55819 82616 126325 134912 135454 137781 109180 107239 122360 120673 107301 106322 63385 28245 31612
[11:29:15.841] 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:29:15.841] INFO: number of Vcal hits detected: 207918 207917 207880 207866 207818 207845 207836 207873 207862 207504 207819 207865 207877 207928 207970 207958
[11:29:15.841] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[11:29:15.841] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0 100.0
[11:29:15.841] INFO: X-ray hit rate [MHz/cm2]: 23.1 16.4 24.2 37.0 39.5 39.7 40.4 32.0 31.4 35.9 35.4 31.5 31.2 18.6 8.3 9.3
[11:29:15.841] INFO: PixTestHighRate::doXPixelAlive() done
[11:29:15.890] INFO: PixTest:: pg_setup set to default.
[11:29:15.904] INFO: enter test to run
[11:30:45.010] INFO: test: HighRate no parameter change
[11:30:45.010] INFO: running: highrate
[11:30:45.011] INFO: ----------------------------------------------------------------------
[11:30:45.011] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:30:45.011] INFO: ----------------------------------------------------------------------
[11:30:45.622] INFO: Expecting 208000 events.
[11:30:59.961] INFO: 208000 events read in total (13812ms).
[11:30:59.967] INFO: Test took 14948ms.
[11:31:00.320] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:00.643] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 6 0 0 0 0 0 0
[11:31:00.643] INFO: number of red-efficiency pixels: 266 213 409 444 654 570 619 409 374 549 669 528 346 206 96 78
[11:31:00.643] INFO: number of X-ray hits detected: 162283 115222 170039 261137 277163 279779 283653 226415 221491 251932 248211 222313 218512 131188 57564 65781
[11:31:00.643] 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:31:00.643] INFO: number of Vcal hits detected: 207716 207764 207545 207503 207262 207357 207320 207558 207572 207077 207261 207418 207629 207779 207901 207921
[11:31:00.643] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.7 99.8 99.8 99.7 99.7 99.7 99.8 99.9 100.0 100.0
[11:31:00.643] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.6 99.7 99.7 99.8 99.8 99.6 99.6 99.7 99.8 99.9 100.0 100.0
[11:31:00.643] INFO: X-ray hit rate [MHz/cm2]: 47.6 33.8 49.8 76.5 81.2 82.0 83.1 66.4 64.9 73.8 72.8 65.2 64.0 38.5 16.9 19.3
[11:31:00.643] INFO: PixTestHighRate::doXPixelAlive() done
[11:31:00.691] INFO: PixTest:: pg_setup set to default.
[11:31:00.703] INFO: enter test to run
[11:31:37.081] INFO: test: HighRate no parameter change
[11:31:37.081] INFO: running: highrate
[11:31:37.082] INFO: ----------------------------------------------------------------------
[11:31:37.082] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:31:37.082] INFO: ----------------------------------------------------------------------
[11:31:37.698] INFO: Expecting 208000 events.
[11:31:54.714] INFO: 208000 events read in total (16489ms).
[11:31:54.723] INFO: Test took 17632ms.
[11:31:55.274] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:31:55.654] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 6 0 0 0 0 0 0
[11:31:55.654] INFO: number of red-efficiency pixels: 624 440 911 1170 1563 1483 1424 950 894 1299 1570 1244 812 503 145 146
[11:31:55.654] INFO: number of X-ray hits detected: 248375 175962 257353 395933 418781 424238 431719 344565 337238 382802 378291 338638 332188 199507 88473 101160
[11:31:55.654] 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:31:55.654] INFO: number of Vcal hits detected: 207237 207510 206617 206503 205812 205959 206033 206736 206892 206004 205831 206343 207026 207371 207851 207852
[11:31:55.654] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.4 99.4 99.1 99.1 99.2 99.4 99.5 99.3 99.0 99.3 99.6 99.7 99.9 99.9
[11:31:55.654] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.3 99.3 98.9 99.0 99.1 99.4 99.5 99.0 99.0 99.2 99.5 99.7 99.9 99.9
[11:31:55.655] INFO: X-ray hit rate [MHz/cm2]: 72.8 51.6 75.4 116.1 122.7 124.3 126.5 101.0 98.8 112.2 110.9 99.3 97.4 58.5 25.9 29.7
[11:31:55.655] INFO: PixTestHighRate::doXPixelAlive() done
[11:31:55.703] INFO: PixTest:: pg_setup set to default.
[11:31:55.721] INFO: enter test to run
[11:31:58.673] INFO: test: exit no parameter change
[11:31:59.025] QUIET: Connection to board 32 closed.
[11:31:59.026] INFO: pXar: this is the end, my friend