[11:51:26.518] INFO: *** Welcome to pxar ***
[11:51:26.518] INFO: *** Today: 2016/05/30
[11:51:26.994] INFO: *** Version: v1.9.0-796-gef167-dirty
[11:51:26.994] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//dacParameters35_C15.dat
[11:51:27.073] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:51:27.073] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//defaultMaskFile.dat
[11:51:27.084] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C15.dat
[11:51:27.256] INFO: clk: 4
[11:51:27.256] INFO: ctr: 4
[11:51:27.256] INFO: sda: 19
[11:51:27.256] INFO: tin: 9
[11:51:27.256] INFO: level: 15
[11:51:27.256] INFO: triggerdelay: 0
[11:51:27.256] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[11:51:27.256] INFO: Log level: INFO
[11:51:27.274] QUIET: Connection to board DTB_WREKRL opened.
[11:51:27.277] 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:51:27.280] INFO: RPC call hashes of host and DTB match: 398089610
[11:51:28.828] INFO: DUT info:
[11:51:28.828] INFO: The DUT currently contains the following objects:
[11:51:28.828] INFO: 2 TBM Cores tbm08c (2 ON)
[11:51:28.840] INFO: TBM Core alpha (0): 7 registers set
[11:51:28.841] INFO: TBM Core beta (1): 7 registers set
[11:51:28.841] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:51:28.841] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:28.841] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:51:29.303] INFO: enter 'restricted' command line mode
[11:51:29.304] INFO: enter test to run
[11:51:45.889] INFO: test: PixelAlive no parameter change
[11:51:45.889] INFO: running: pixelalive
[11:51:45.954] INFO: ----------------------------------------------------------------------
[11:51:45.954] 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:51:45.954] INFO: ----------------------------------------------------------------------
[11:51:46.271] INFO: Expecting 41600 events.
[11:51:50.630] INFO: 41600 events read in total (3641ms).
[11:51:50.798] INFO: Test took 4842ms.
[11:51:50.811] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:51:51.317] INFO: PixTestAlive::aliveTest() done
[11:51:51.317] INFO: number of dead pixels (per ROC): 0 0 0 160 0 0 0 0 0 0 0 1 0 0 0 0
[11:51:51.462] INFO: enter test to run
[11:52:09.439] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:52:09.439] INFO: running: highrate
[11:52:09.439] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:52:09.739] INFO: ----------------------------------------------------------------------
[11:52:09.739] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:52:09.739] INFO: ----------------------------------------------------------------------
[11:52:09.739] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:52:09.739] INFO: edge/corner pixel THR is adjusted
[11:52:09.739] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:52:10.697] INFO: Collecting data for 5 seconds...
[11:52:15.711] INFO: Done with hot pixel readout
[11:52:27.393] INFO: PixTest:: pg_setup set to default.
[11:52:27.394] INFO: 18 hot pixels found in step 0
[11:52:28.383] INFO: Collecting data for 5 seconds...
[11:52:33.399] INFO: Done with hot pixel readout
[11:52:44.504] INFO: PixTest:: pg_setup set to default.
[11:52:44.505] INFO: 17 hot pixels found in step 1
[11:52:45.498] INFO: Collecting data for 5 seconds...
[11:52:50.514] INFO: Done with hot pixel readout
[11:53:02.202] INFO: PixTest:: pg_setup set to default.
[11:53:02.203] INFO: 17 hot pixels found in step 2
[11:53:03.195] INFO: Collecting data for 5 seconds...
[11:53:08.211] INFO: Done with hot pixel readout
[11:53:19.903] INFO: PixTest:: pg_setup set to default.
[11:53:19.904] INFO: 15 hot pixels found in step 3
[11:53:20.896] INFO: Collecting data for 5 seconds...
[11:53:25.912] INFO: Done with hot pixel readout
[11:53:37.628] INFO: PixTest:: pg_setup set to default.
[11:53:37.629] INFO: 18 hot pixels found in step 4
[11:53:38.621] INFO: Collecting data for 5 seconds...
[11:53:43.636] INFO: Done with hot pixel readout
[11:53:54.510] INFO: PixTest:: pg_setup set to default.
[11:53:54.510] INFO: 16 hot pixels found in step 5
[11:53:55.503] INFO: Collecting data for 5 seconds...
[11:54:00.510] INFO: Done with hot pixel readout
[11:54:08.899] INFO: PixTest:: pg_setup set to default.
[11:54:08.900] INFO: 12 hot pixels found in step 6
[11:54:09.891] INFO: Collecting data for 5 seconds...
[11:54:14.906] INFO: Done with hot pixel readout
[11:54:26.598] INFO: PixTest:: pg_setup set to default.

[11:54:26.599] INFO: 8 hot pixels found in step 7
[11:54:27.591] INFO: Collecting data for 5 seconds...
[11:54:32.607] INFO: Done with hot pixel readout
[11:54:44.379] INFO: PixTest:: pg_setup set to default.

[11:54:44.379] INFO: 12 hot pixels found in step 8
[11:54:45.372] INFO: Collecting data for 5 seconds...
[11:54:50.390] INFO: Done with hot pixel readout
[11:55:02.088] INFO: PixTest:: pg_setup set to default.

[11:55:02.089] INFO: 10 hot pixels found in step 9
[11:55:03.081] INFO: Collecting data for 5 seconds...
[11:55:08.102] INFO: Done with hot pixel readout
[11:55:19.738] INFO: PixTest:: pg_setup set to default.




[11:55:19.739] INFO: 8 hot pixels found in step 10
[11:55:20.731] INFO: Collecting data for 5 seconds...
[11:55:25.749] INFO: Done with hot pixel readout
[11:55:37.165] INFO: PixTest:: pg_setup set to default.



[11:55:37.166] INFO: 7 hot pixels found in step 11
[11:55:38.158] INFO: Collecting data for 5 seconds...
[11:55:43.176] INFO: Done with hot pixel readout
[11:55:54.458] INFO: PixTest:: pg_setup set to default.




[11:55:54.459] INFO: 11 hot pixels found in step 12
[11:55:55.453] INFO: Collecting data for 5 seconds...
[11:56:00.469] INFO: Done with hot pixel readout
[11:56:11.856] INFO: PixTest:: pg_setup set to default.


[11:56:11.857] INFO: 11 hot pixels found in step 13
[11:56:12.849] INFO: Collecting data for 5 seconds...
[11:56:17.866] INFO: Done with hot pixel readout
[11:56:29.484] INFO: PixTest:: pg_setup set to default.



[11:56:29.485] INFO: 10 hot pixels found in step 14
[11:56:29.521] INFO: 10 hot pixels could not be trimmed and have been masked.
[11:56:29.537] INFO: PixTest::trimHotPixels() done
[11:56:29.538] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C0.dat
[11:56:29.544] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C1.dat
[11:56:29.550] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C2.dat
[11:56:29.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C3.dat
[11:56:29.561] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C4.dat
[11:56:29.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C5.dat
[11:56:29.573] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C6.dat
[11:56:29.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C7.dat
[11:56:29.601] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C8.dat
[11:56:29.606] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C9.dat
[11:56:29.612] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C10.dat
[11:56:29.617] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C11.dat
[11:56:29.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C12.dat
[11:56:29.628] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C13.dat
[11:56:29.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C14.dat
[11:56:29.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C15.dat
[11:56:29.645] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//defaultMaskFile.dat
[11:56:29.655] INFO: enter test to run
[11:58:39.500] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:58:39.500] INFO: running: highrate
[11:58:39.504] INFO: ----------------------------------------------------------------------
[11:58:39.504] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:58:39.504] INFO: ----------------------------------------------------------------------
[11:58:39.504] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:58:39.504] INFO: edge/corner pixel THR is adjusted
[11:58:39.504] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:58:40.462] INFO: Collecting data for 1 seconds...
[11:58:41.465] INFO: Done with hot pixel readout
[11:58:45.409] INFO: PixTest:: pg_setup set to default.
[11:58:45.410] INFO: 0 hot pixels found in step 0
[11:58:45.415] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:58:45.509] INFO: PixTest::trimHotPixels() done
[11:58:45.510] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C0.dat
[11:58:45.522] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C1.dat
[11:58:45.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C2.dat
[11:58:45.537] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C3.dat
[11:58:45.542] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C4.dat
[11:58:45.548] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C5.dat
[11:58:45.553] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C6.dat
[11:58:45.558] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C7.dat
[11:58:45.564] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C8.dat
[11:58:45.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C9.dat
[11:58:45.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C10.dat
[11:58:45.580] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C11.dat
[11:58:45.586] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C12.dat
[11:58:45.591] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C13.dat
[11:58:45.596] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C14.dat
[11:58:45.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//trimParameters35_C15.dat
[11:58:45.607] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-02_FPIXTest-17C-FNAL-160526-1044_2016-05-26_10h44m_1464277493/000_FPIXTest_p17//defaultMaskFile.dat
[11:58:45.617] INFO: enter test to run
[11:59:19.011] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:59:19.011] INFO: running: xray
[11:59:19.012] INFO: ----------------------------------------------------------------------
[11:59:19.012] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:59:19.012] INFO: ----------------------------------------------------------------------
[11:59:19.987] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:59:31.535] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[12:00:00.986] INFO: Resuming triggers.
[12:00:12.539] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[12:00:41.527] INFO: Resuming triggers.
[12:00:53.076] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[12:01:21.790] INFO: Resuming triggers.
[12:01:33.340] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:02:02.089] INFO: Resuming triggers.
[12:02:13.640] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[12:02:42.374] INFO: Resuming triggers.
[12:02:53.926] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[12:03:22.605] INFO: Resuming triggers.
[12:03:34.159] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:04:02.837] INFO: Resuming triggers.
[12:04:14.387] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[12:04:42.109] INFO: Resuming triggers.
[12:04:50.003] INFO: data taking finished, elapsed time: 100 seconds.
[12:05:09.145] INFO: PixTest:: pg_setup set to default.
[12:05:09.148] INFO: PixTestXray::doPhRun() done
[12:05:09.290] INFO: enter test to run
[12:06:33.312] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[12:06:33.312] INFO: running: xray
[12:06:33.313] INFO: ----------------------------------------------------------------------
[12:06:33.313] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:06:33.313] INFO: ----------------------------------------------------------------------
[12:06:34.277] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[12:06:41.004] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[12:07:09.653] INFO: Resuming triggers.
[12:07:16.385] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[12:07:45.490] INFO: Resuming triggers.
[12:07:52.221] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[12:08:21.984] INFO: Resuming triggers.
[12:08:28.715] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[12:08:58.296] INFO: Resuming triggers.
[12:09:05.026] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[12:09:34.536] INFO: Resuming triggers.
[12:09:41.267] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[12:10:10.892] INFO: Resuming triggers.
[12:10:17.625] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[12:10:48.154] INFO: Resuming triggers.
[12:10:54.889] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[12:11:25.002] INFO: Resuming triggers.
[12:11:31.738] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[12:12:01.811] INFO: Resuming triggers.
[12:12:08.545] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[12:12:38.666] INFO: Resuming triggers.
[12:12:45.398] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[12:13:15.446] INFO: Resuming triggers.
[12:13:22.180] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[12:13:52.274] INFO: Resuming triggers.
[12:13:59.005] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[12:14:29.036] INFO: Resuming triggers.
[12:14:35.767] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[12:15:06.106] INFO: Resuming triggers.
[12:15:12.179] INFO: data taking finished, elapsed time: 100 seconds.
[12:15:39.548] INFO: PixTest:: pg_setup set to default.
[12:15:39.551] INFO: PixTestXray::doPhRun() done
[12:15:39.699] INFO: enter test to run
[12:17:16.139] INFO: test: HighRate no parameter change
[12:17:16.139] INFO: running: highrate
[12:17:16.140] INFO: ----------------------------------------------------------------------
[12:17:16.140] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[12:17:16.140] INFO: ----------------------------------------------------------------------
[12:17:16.280] INFO: Expecting 768 events.
[12:17:17.415] INFO: 768 events read in total (419ms).
[12:17:17.415] INFO: Test took 1269ms.
[12:17:18.218] INFO: Expecting 41600 events.
[12:17:21.320] INFO: 41600 events read in total (2575ms).
[12:17:21.321] INFO: Test took 3898ms.
[12:17:21.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:22.083] INFO: Expecting 41600 events.
[12:17:25.285] INFO: 41600 events read in total (2675ms).
[12:17:25.286] INFO: Test took 3915ms.
[12:17:25.319] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:26.047] INFO: Expecting 41600 events.
[12:17:29.254] INFO: 41600 events read in total (2680ms).
[12:17:29.255] INFO: Test took 3918ms.
[12:17:29.289] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:30.011] INFO: Expecting 41600 events.
[12:17:33.286] INFO: 41600 events read in total (2748ms).
[12:17:33.287] INFO: Test took 3980ms.
[12:17:33.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:34.041] INFO: Expecting 41600 events.
[12:17:37.294] INFO: 41600 events read in total (2727ms).
[12:17:37.295] INFO: Test took 3956ms.
[12:17:37.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:38.049] INFO: Expecting 41600 events.
[12:17:41.255] INFO: 41600 events read in total (2679ms).
[12:17:41.256] INFO: Test took 3910ms.
[12:17:41.290] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:42.008] INFO: Expecting 41600 events.
[12:17:45.218] INFO: 41600 events read in total (2683ms).
[12:17:45.219] INFO: Test took 3911ms.
[12:17:45.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:45.979] INFO: Expecting 41600 events.
[12:17:49.265] INFO: 41600 events read in total (2759ms).
[12:17:49.266] INFO: Test took 3994ms.
[12:17:49.303] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:50.020] INFO: Expecting 41600 events.
[12:17:53.305] INFO: 41600 events read in total (2758ms).
[12:17:53.305] INFO: Test took 3985ms.
[12:17:53.339] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:54.064] INFO: Expecting 41600 events.
[12:17:57.274] INFO: 41600 events read in total (2683ms).
[12:17:57.275] INFO: Test took 3919ms.
[12:17:57.309] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:17:58.031] INFO: Expecting 41600 events.
[12:18:01.267] INFO: 41600 events read in total (2709ms).
[12:18:01.268] INFO: Test took 3942ms.
[12:18:01.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:02.024] INFO: Expecting 41600 events.
[12:18:05.259] INFO: 41600 events read in total (2709ms).
[12:18:05.260] INFO: Test took 3940ms.
[12:18:05.294] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:06.019] INFO: Expecting 41600 events.
[12:18:09.222] INFO: 41600 events read in total (2676ms).
[12:18:09.223] INFO: Test took 3912ms.
[12:18:09.258] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:09.978] INFO: Expecting 41600 events.
[12:18:13.141] INFO: 41600 events read in total (2637ms).
[12:18:13.142] INFO: Test took 3866ms.
[12:18:13.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:13.904] INFO: Expecting 41600 events.
[12:18:17.216] INFO: 41600 events read in total (2785ms).
[12:18:17.217] INFO: Test took 4024ms.
[12:18:17.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:17.955] INFO: Expecting 41600 events.
[12:18:21.188] INFO: 41600 events read in total (2707ms).
[12:18:21.188] INFO: Test took 3914ms.
[12:18:21.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:21.940] INFO: Expecting 41600 events.
[12:18:25.173] INFO: 41600 events read in total (2706ms).
[12:18:25.174] INFO: Test took 3933ms.
[12:18:25.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:25.928] INFO: Expecting 41600 events.
[12:18:29.138] INFO: 41600 events read in total (2683ms).
[12:18:29.139] INFO: Test took 3913ms.
[12:18:29.174] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:29.898] INFO: Expecting 41600 events.
[12:18:33.086] INFO: 41600 events read in total (2662ms).
[12:18:33.087] INFO: Test took 3896ms.
[12:18:33.121] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:33.847] INFO: Expecting 41600 events.
[12:18:36.921] INFO: 41600 events read in total (2547ms).
[12:18:36.922] INFO: Test took 3781ms.
[12:18:36.956] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:18:37.318] INFO: enter test to run
[12:19:28.619] INFO: test: HighRate no parameter change
[12:19:28.619] INFO: running: highrate
[12:19:28.620] INFO: ----------------------------------------------------------------------
[12:19:28.620] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:19:28.620] INFO: ----------------------------------------------------------------------
[12:19:29.243] INFO: Expecting 208000 events.
[12:19:41.351] INFO: 208000 events read in total (11581ms).
[12:19:41.354] INFO: Test took 12724ms.
[12:19:41.496] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:19:41.748] INFO: number of dead pixels (per ROC): 0 0 0 160 0 0 0 0 0 0 0 1 0 0 0 0
[12:19:41.748] INFO: number of red-efficiency pixels: 78 31 92 294 139 136 151 111 100 110 110 80 82 51 28 27
[12:19:41.748] INFO: number of X-ray hits detected: 62152 40428 65247 96673 113697 118027 120763 88813 80279 92459 87157 74798 79658 47062 23560 26818
[12:19:41.748] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:19:41.748] INFO: number of Vcal hits detected: 207914 207969 207903 199860 207856 207863 207847 207884 207900 207888 207886 207870 207917 207949 207972 207973
[12:19:41.748] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[12:19:41.748] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 96.1 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[12:19:41.748] INFO: X-ray hit rate [MHz/cm2]: 18.2 11.8 19.1 28.3 33.3 34.6 35.4 26.0 23.5 27.1 25.5 21.9 23.3 13.8 6.9 7.9
[12:19:41.748] INFO: PixTestHighRate::doXPixelAlive() done
[12:19:41.793] INFO: PixTest:: pg_setup set to default.
[12:19:41.802] INFO: enter test to run
[12:20:32.458] INFO: test: HighRate no parameter change
[12:20:32.458] INFO: running: highrate
[12:20:32.459] INFO: ----------------------------------------------------------------------
[12:20:32.459] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:20:32.459] INFO: ----------------------------------------------------------------------
[12:20:33.075] INFO: Expecting 208000 events.
[12:20:46.463] INFO: 208000 events read in total (12862ms).
[12:20:46.468] INFO: Test took 14000ms.
[12:20:46.773] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:20:47.088] INFO: number of dead pixels (per ROC): 0 0 0 160 0 0 0 0 0 0 0 1 0 0 0 0
[12:20:47.088] INFO: number of red-efficiency pixels: 210 106 290 604 585 551 467 309 297 370 265 242 238 158 60 67
[12:20:47.088] INFO: number of X-ray hits detected: 132460 86230 137938 204084 237332 248185 254557 186480 168912 193079 184111 158305 168010 100249 49481 56276
[12:20:47.088] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:20:47.088] INFO: number of Vcal hits detected: 207771 207890 207673 199516 207356 207388 207483 207655 207694 207618 207719 207699 207752 207837 207938 207933
[12:20:47.088] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.7 99.7 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[12:20:47.088] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 95.9 99.7 99.7 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[12:20:47.088] INFO: X-ray hit rate [MHz/cm2]: 38.8 25.3 40.4 59.8 69.6 72.7 74.6 54.7 49.5 56.6 54.0 46.4 49.2 29.4 14.5 16.5
[12:20:47.088] INFO: PixTestHighRate::doXPixelAlive() done
[12:20:47.136] INFO: PixTest:: pg_setup set to default.
[12:20:47.152] INFO: enter test to run
[12:21:27.586] INFO: test: HighRate no parameter change
[12:21:27.586] INFO: running: highrate
[12:21:27.587] INFO: ----------------------------------------------------------------------
[12:21:27.587] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[12:21:27.587] INFO: ----------------------------------------------------------------------
[12:21:28.193] INFO: Expecting 208000 events.
[12:21:43.284] INFO: 208000 events read in total (14564ms).
[12:21:43.292] INFO: Test took 15698ms.
[12:21:43.718] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:21:44.066] INFO: number of dead pixels (per ROC): 0 0 0 160 0 0 0 0 0 0 0 1 0 0 0 0
[12:21:44.066] INFO: number of red-efficiency pixels: 391 249 662 1159 1285 1284 1064 732 687 830 568 596 481 376 106 99
[12:21:44.066] INFO: number of X-ray hits detected: 200862 129075 209733 309182 359969 376736 383860 282397 255537 291883 277322 240245 254770 151655 74775 85375
[12:21:44.066] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[12:21:44.066] INFO: number of Vcal hits detected: 207541 207728 207111 198792 206339 206362 206633 207093 207216 207031 207368 207265 207472 207576 207892 207899
[12:21:44.066] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.5 99.3 99.3 99.4 99.6 99.7 99.6 99.7 99.7 99.8 99.8 100.0 100.0
[12:21:44.066] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 95.6 99.2 99.2 99.3 99.6 99.6 99.5 99.7 99.6 99.7 99.8 99.9 100.0
[12:21:44.066] INFO: X-ray hit rate [MHz/cm2]: 58.9 37.8 61.5 90.6 105.5 110.4 112.5 82.8 74.9 85.6 81.3 70.4 74.7 44.5 21.9 25.0
[12:21:44.066] INFO: PixTestHighRate::doXPixelAlive() done
[12:21:44.112] INFO: PixTest:: pg_setup set to default.
[12:21:44.129] INFO: enter test to run
[12:22:04.433] INFO: test: exit no parameter change
[12:22:04.772] QUIET: Connection to board 33 closed.
[12:22:04.773] INFO: pXar: this is the end, my friend