[13:36:18.603] INFO: *** Welcome to pxar ***
[13:36:18.603] INFO: *** Today: 2016/03/31
[13:36:18.666] INFO: *** Version: v1.9.0-793-ge521
[13:36:18.667] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/dacParameters35_C15.dat
[13:36:18.689] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/tbmParameters_C0b.dat
[13:36:18.689] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/defaultMaskFile.dat
[13:36:18.707] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C15.dat
[13:36:18.790] INFO: clk: 4
[13:36:18.790] INFO: ctr: 4
[13:36:18.790] INFO: sda: 19
[13:36:18.790] INFO: tin: 9
[13:36:18.790] INFO: level: 15
[13:36:18.790] INFO: triggerdelay: 0
[13:36:18.790] QUIET: Instanciating API for pxar v1.9.0+788~g8b11555
[13:36:18.790] INFO: Log level: INFO
[13:36:18.805] QUIET: Connection to board DTB_WREKRL opened.
[13:36:18.808] 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:
------------------------------------------------------
[13:36:18.811] INFO: RPC call hashes of host and DTB match: 398089610
[13:36:20.342] INFO: DUT info:
[13:36:20.342] INFO: The DUT currently contains the following objects:
[13:36:20.342] INFO: 2 TBM Cores tbm08c (2 ON)
[13:36:20.342] INFO: TBM Core alpha (0): 7 registers set
[13:36:20.343] INFO: TBM Core beta (1): 7 registers set
[13:36:20.343] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:36:20.343] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.343] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:36:20.752] INFO: enter 'restricted' command line mode
[13:36:20.752] INFO: enter test to run
[13:36:27.618] INFO: test: PixelAlive no parameter change
[13:36:27.618] INFO: running: pixelalive
[13:36:27.627] INFO: ----------------------------------------------------------------------
[13:36:27.627] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:36:27.628] INFO: ----------------------------------------------------------------------
[13:36:27.949] INFO: Expecting 41600 events.
[13:36:32.276] INFO: 41600 events read in total (3608ms).
[13:36:32.445] INFO: Test took 4815ms.
[13:36:32.456] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:36:32.721] INFO: PixTestAlive::aliveTest() done
[13:36:32.721] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 2 0 0 0
[13:36:32.750] INFO: enter test to run
[13:37:02.585] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:37:02.586] INFO: running: highrate
[13:37:02.586] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/phCalibrationFitErr35_C15.dat
[13:37:02.907] INFO: ----------------------------------------------------------------------
[13:37:02.907] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:37:02.907] INFO: ----------------------------------------------------------------------
[13:37:02.907] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:37:02.907] INFO: edge/corner pixel THR is adjusted
[13:37:02.907] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:37:03.866] INFO: Collecting data for 5 seconds...
[13:37:08.883] INFO: Done with hot pixel readout
[13:37:20.971] INFO: PixTest:: pg_setup set to default.



[13:37:20.972] INFO: 5 hot pixels found in step 0
[13:37:21.964] INFO: Collecting data for 5 seconds...
[13:37:26.981] INFO: Done with hot pixel readout
[13:37:39.033] INFO: PixTest:: pg_setup set to default.

[13:37:39.034] INFO: 7 hot pixels found in step 1
[13:37:40.030] INFO: Collecting data for 5 seconds...
[13:37:45.048] INFO: Done with hot pixel readout
[13:37:57.090] INFO: PixTest:: pg_setup set to default.
[13:37:57.090] INFO: 4 hot pixels found in step 2
[13:37:58.086] INFO: Collecting data for 5 seconds...
[13:38:03.103] INFO: Done with hot pixel readout
[13:38:13.402] INFO: PixTest:: pg_setup set to default.
[13:38:13.402] INFO: 3 hot pixels found in step 3
[13:38:14.398] INFO: Collecting data for 5 seconds...
[13:38:19.415] INFO: Done with hot pixel readout
[13:38:31.526] INFO: PixTest:: pg_setup set to default.

[13:38:31.526] INFO: 8 hot pixels found in step 4
[13:38:32.521] INFO: Collecting data for 5 seconds...
[13:38:37.538] INFO: Done with hot pixel readout
[13:38:49.594] INFO: PixTest:: pg_setup set to default.

[13:38:49.595] INFO: 3 hot pixels found in step 5
[13:38:50.590] INFO: Collecting data for 5 seconds...
[13:38:55.607] INFO: Done with hot pixel readout
[13:39:07.672] INFO: PixTest:: pg_setup set to default.
[13:39:07.673] INFO: 3 hot pixels found in step 6
[13:39:08.669] INFO: Collecting data for 5 seconds...
[13:39:13.686] INFO: Done with hot pixel readout
[13:39:25.762] INFO: PixTest:: pg_setup set to default.
[13:39:25.763] INFO: 7 hot pixels found in step 7
[13:39:26.759] INFO: Collecting data for 5 seconds...
[13:39:31.775] INFO: Done with hot pixel readout
[13:39:43.885] INFO: PixTest:: pg_setup set to default.
[13:39:43.886] INFO: 3 hot pixels found in step 8
[13:39:44.881] INFO: Collecting data for 5 seconds...
[13:39:49.897] INFO: Done with hot pixel readout
[13:40:01.933] INFO: PixTest:: pg_setup set to default.
[13:40:01.934] INFO: 2 hot pixels found in step 9
[13:40:02.929] INFO: Collecting data for 5 seconds...
[13:40:07.946] INFO: Done with hot pixel readout
[13:40:20.019] INFO: PixTest:: pg_setup set to default.
[13:40:20.020] INFO: 3 hot pixels found in step 10
[13:40:21.016] INFO: Collecting data for 5 seconds...
[13:40:26.033] INFO: Done with hot pixel readout
[13:40:38.104] INFO: PixTest:: pg_setup set to default.
[13:40:38.105] INFO: 2 hot pixels found in step 11
[13:40:39.100] INFO: Collecting data for 5 seconds...
[13:40:44.117] INFO: Done with hot pixel readout
[13:40:56.176] INFO: PixTest:: pg_setup set to default.

[13:40:56.177] INFO: 6 hot pixels found in step 12
[13:40:57.172] INFO: Collecting data for 5 seconds...
[13:41:02.188] INFO: Done with hot pixel readout
[13:41:14.262] INFO: PixTest:: pg_setup set to default.
[13:41:14.263] INFO: 3 hot pixels found in step 13
[13:41:15.258] INFO: Collecting data for 5 seconds...
[13:41:20.274] INFO: Done with hot pixel readout
[13:41:32.330] INFO: PixTest:: pg_setup set to default.
[13:41:32.331] INFO: 3 hot pixels found in step 14
[13:41:32.370] INFO: 3 hot pixels could not be trimmed and have been masked.
[13:41:32.373] INFO: PixTest::trimHotPixels() done
[13:41:32.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C0.dat
[13:41:32.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C1.dat
[13:41:32.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C2.dat
[13:41:32.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C3.dat
[13:41:32.397] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C4.dat
[13:41:32.402] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C5.dat
[13:41:32.407] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C6.dat
[13:41:32.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C7.dat
[13:41:32.418] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C8.dat
[13:41:32.423] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C9.dat
[13:41:32.428] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C10.dat
[13:41:32.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C11.dat
[13:41:32.439] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C12.dat
[13:41:32.444] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C13.dat
[13:41:32.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C14.dat
[13:41:32.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C15.dat
[13:41:32.460] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/defaultMaskFile.dat
[13:41:32.470] INFO: enter test to run
[13:42:36.223] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:42:36.223] INFO: running: highrate
[13:42:36.228] INFO: ----------------------------------------------------------------------
[13:42:36.228] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:42:36.228] INFO: ----------------------------------------------------------------------
[13:42:36.228] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:42:36.228] INFO: edge/corner pixel THR is adjusted
[13:42:36.228] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:42:37.186] INFO: Collecting data for 1 seconds...
[13:42:38.189] INFO: Done with hot pixel readout
[13:42:42.422] INFO: PixTest:: pg_setup set to default.
[13:42:42.423] INFO: 0 hot pixels found in step 0
[13:42:42.428] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:42:42.507] INFO: PixTest::trimHotPixels() done
[13:42:42.507] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C0.dat
[13:42:42.519] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C1.dat
[13:42:42.526] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C2.dat
[13:42:42.531] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C3.dat
[13:42:42.536] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C4.dat
[13:42:42.541] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C5.dat
[13:42:42.547] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C6.dat
[13:42:42.552] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C7.dat
[13:42:42.557] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C8.dat
[13:42:42.562] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C9.dat
[13:42:42.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C10.dat
[13:42:42.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C11.dat
[13:42:42.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C12.dat
[13:42:42.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C13.dat
[13:42:42.588] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C14.dat
[13:42:42.593] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/trimParameters35_C15.dat
[13:42:42.598] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-50_FPIXTest-17C-FNAL-160330-1306_2016-03-30_13h06m_1459361182/000_FPIXTest_p17/defaultMaskFile.dat
[13:42:42.610] INFO: enter test to run
[13:43:43.294] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:43:43.294] INFO: running: xray
[13:43:43.296] INFO: ----------------------------------------------------------------------
[13:43:43.296] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:43:43.296] INFO: ----------------------------------------------------------------------
[13:43:44.259] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:43:55.113] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:44:24.856] INFO: Resuming triggers.
[13:44:35.714] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:45:05.547] INFO: Resuming triggers.
[13:45:16.410] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[13:45:46.197] INFO: Resuming triggers.
[13:45:57.058] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[13:46:24.968] INFO: Resuming triggers.
[13:46:35.831] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:47:05.585] INFO: Resuming triggers.
[13:47:16.447] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[13:47:46.191] INFO: Resuming triggers.
[13:47:57.056] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[13:48:25.025] INFO: Resuming triggers.
[13:48:35.890] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:49:05.712] INFO: Resuming triggers.
[13:49:16.582] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[13:49:46.373] INFO: Resuming triggers.
[13:49:48.951] INFO: data taking finished, elapsed time: 100 seconds.
[13:49:56.317] INFO: PixTest:: pg_setup set to default.
[13:49:56.321] INFO: PixTestXray::doPhRun() done
[13:49:56.458] INFO: enter test to run
[13:50:58.971] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:50:58.971] INFO: running: xray
[13:50:58.972] INFO: ----------------------------------------------------------------------
[13:50:58.973] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:50:58.973] INFO: ----------------------------------------------------------------------
[13:50:59.940] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:51:06.094] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:51:36.709] INFO: Resuming triggers.
[13:51:42.866] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[13:52:13.296] INFO: Resuming triggers.
[13:52:19.455] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[13:52:49.927] INFO: Resuming triggers.
[13:52:56.088] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[13:53:26.609] INFO: Resuming triggers.
[13:53:32.770] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[13:54:03.600] INFO: Resuming triggers.
[13:54:09.762] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[13:54:40.222] INFO: Resuming triggers.
[13:54:46.386] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[13:55:16.817] INFO: Resuming triggers.
[13:55:22.984] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[13:55:53.505] INFO: Resuming triggers.
[13:55:59.672] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:56:30.160] INFO: Resuming triggers.
[13:56:36.331] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:57:06.833] INFO: Resuming triggers.
[13:57:12.002] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:57:43.457] INFO: Resuming triggers.
[13:57:49.629] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[13:58:20.114] INFO: Resuming triggers.
[13:58:26.282] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[13:58:56.790] INFO: Resuming triggers.
[13:59:02.960] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[13:59:33.362] INFO: Resuming triggers.
[13:59:39.529] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:00:09.934] INFO: Resuming triggers.
[14:00:16.104] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:00:46.563] INFO: Resuming triggers.
[14:00:48.255] INFO: data taking finished, elapsed time: 100 seconds.
[14:00:56.918] INFO: PixTest:: pg_setup set to default.
[14:00:56.921] INFO: PixTestXray::doPhRun() done
[14:00:57.071] INFO: enter test to run
[14:01:24.943] INFO: test: HighRate no parameter change
[14:01:24.943] INFO: running: highrate
[14:01:24.944] INFO: ----------------------------------------------------------------------
[14:01:24.944] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:01:24.944] INFO: ----------------------------------------------------------------------
[14:01:25.086] INFO: Expecting 768 events.
[14:01:26.220] INFO: 768 events read in total (418ms).
[14:01:26.221] INFO: Test took 1270ms.
[14:01:27.024] INFO: Expecting 41600 events.
[14:01:30.171] INFO: 41600 events read in total (2620ms).
[14:01:30.172] INFO: Test took 3943ms.
[14:01:30.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:30.928] INFO: Expecting 41600 events.
[14:01:34.162] INFO: 41600 events read in total (2707ms).
[14:01:34.163] INFO: Test took 3934ms.
[14:01:34.201] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:34.920] INFO: Expecting 41600 events.
[14:01:38.193] INFO: 41600 events read in total (2746ms).
[14:01:38.194] INFO: Test took 3973ms.
[14:01:38.232] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:38.950] INFO: Expecting 41600 events.
[14:01:42.225] INFO: 41600 events read in total (2748ms).
[14:01:42.226] INFO: Test took 3975ms.
[14:01:42.266] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:42.982] INFO: Expecting 41600 events.
[14:01:46.254] INFO: 41600 events read in total (2745ms).
[14:01:46.255] INFO: Test took 3971ms.
[14:01:46.293] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:47.006] INFO: Expecting 41600 events.
[14:01:50.290] INFO: 41600 events read in total (2757ms).
[14:01:50.292] INFO: Test took 3980ms.
[14:01:50.338] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:51.041] INFO: Expecting 41600 events.
[14:01:54.330] INFO: 41600 events read in total (2762ms).
[14:01:54.331] INFO: Test took 3972ms.
[14:01:54.370] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:55.083] INFO: Expecting 41600 events.
[14:01:58.355] INFO: 41600 events read in total (2745ms).
[14:01:58.356] INFO: Test took 3967ms.
[14:01:58.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:01:59.111] INFO: Expecting 41600 events.
[14:02:02.374] INFO: 41600 events read in total (2736ms).
[14:02:02.375] INFO: Test took 3962ms.
[14:02:02.413] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:03.131] INFO: Expecting 41600 events.
[14:02:06.428] INFO: 41600 events read in total (2770ms).
[14:02:06.429] INFO: Test took 3996ms.
[14:02:06.468] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:07.184] INFO: Expecting 41600 events.
[14:02:10.474] INFO: 41600 events read in total (2763ms).
[14:02:10.474] INFO: Test took 3987ms.
[14:02:10.513] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:11.231] INFO: Expecting 41600 events.
[14:02:14.517] INFO: 41600 events read in total (2759ms).
[14:02:14.518] INFO: Test took 3987ms.
[14:02:14.557] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:15.275] INFO: Expecting 41600 events.
[14:02:18.560] INFO: 41600 events read in total (2758ms).
[14:02:18.561] INFO: Test took 3984ms.
[14:02:18.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:19.316] INFO: Expecting 41600 events.
[14:02:22.593] INFO: 41600 events read in total (2750ms).
[14:02:22.594] INFO: Test took 3975ms.
[14:02:22.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:23.349] INFO: Expecting 41600 events.
[14:02:26.635] INFO: 41600 events read in total (2759ms).
[14:02:26.636] INFO: Test took 3985ms.
[14:02:26.674] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:27.388] INFO: Expecting 41600 events.
[14:02:30.666] INFO: 41600 events read in total (2751ms).
[14:02:30.667] INFO: Test took 3972ms.
[14:02:30.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:31.420] INFO: Expecting 41600 events.
[14:02:34.722] INFO: 41600 events read in total (2775ms).
[14:02:34.723] INFO: Test took 3999ms.
[14:02:34.762] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:35.475] INFO: Expecting 41600 events.
[14:02:38.766] INFO: 41600 events read in total (2764ms).
[14:02:38.767] INFO: Test took 3984ms.
[14:02:38.805] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:39.520] INFO: Expecting 41600 events.
[14:02:42.796] INFO: 41600 events read in total (2749ms).
[14:02:42.797] INFO: Test took 3971ms.
[14:02:42.835] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:43.549] INFO: Expecting 41600 events.
[14:02:46.660] INFO: 41600 events read in total (2584ms).
[14:02:46.661] INFO: Test took 3807ms.
[14:02:46.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:02:47.055] INFO: enter test to run
[14:03:16.438] INFO: test: HighRate no parameter change
[14:03:16.438] INFO: running: highrate
[14:03:16.439] INFO: ----------------------------------------------------------------------
[14:03:16.439] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:03:16.439] INFO: ----------------------------------------------------------------------
[14:03:17.052] INFO: Expecting 208000 events.
[14:03:29.151] INFO: 208000 events read in total (11572ms).
[14:03:29.155] INFO: Test took 12707ms.
[14:03:29.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:29.580] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 2 0 0 0
[14:03:29.580] INFO: number of red-efficiency pixels: 80 61 78 152 163 174 189 128 114 112 130 151 115 87 23 24
[14:03:29.580] INFO: number of X-ray hits detected: 77136 48449 76663 123875 128372 137505 138265 100204 90382 116846 110398 97279 99233 59982 24743 24037
[14:03:29.580] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:03:29.580] INFO: number of Vcal hits detected: 207916 207939 207920 207844 207829 207823 207807 207869 207884 207882 207819 207849 207784 207913 207977 207976
[14:03:29.580] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 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
[14:03:29.580] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 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
[14:03:29.580] INFO: X-ray hit rate [MHz/cm2]: 22.6 14.2 22.5 36.3 37.6 40.3 40.5 29.4 26.5 34.2 32.4 28.5 29.1 17.6 7.3 7.0
[14:03:29.580] INFO: PixTestHighRate::doXPixelAlive() done
[14:03:29.631] INFO: PixTest:: pg_setup set to default.
[14:03:29.647] INFO: enter test to run
[14:04:07.973] INFO: test: HighRate no parameter change
[14:04:07.974] INFO: running: highrate
[14:04:07.975] INFO: ----------------------------------------------------------------------
[14:04:07.975] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:04:07.975] INFO: ----------------------------------------------------------------------
[14:04:08.591] INFO: Expecting 208000 events.
[14:04:22.621] INFO: 208000 events read in total (13503ms).
[14:04:22.627] INFO: Test took 14644ms.
[14:04:22.950] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:04:23.261] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 2 0 0 0
[14:04:23.261] INFO: number of red-efficiency pixels: 248 190 267 420 517 523 605 372 278 442 386 407 328 255 58 69
[14:04:23.261] INFO: number of X-ray hits detected: 153253 97554 152314 244921 255111 271320 273706 199065 179968 231858 219829 193285 197119 120274 49804 47976
[14:04:23.262] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:04:23.262] INFO: number of Vcal hits detected: 207743 207801 207706 207539 207434 207423 207309 207580 207711 207528 207537 207555 207556 207726 207942 207931
[14:04:23.262] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[14:04:23.262] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:04:23.262] INFO: X-ray hit rate [MHz/cm2]: 44.9 28.6 44.6 71.8 74.8 79.5 80.2 58.3 52.7 68.0 64.4 56.7 57.8 35.3 14.6 14.1
[14:04:23.262] INFO: PixTestHighRate::doXPixelAlive() done
[14:04:23.310] INFO: PixTest:: pg_setup set to default.
[14:04:23.326] INFO: enter test to run
[14:05:16.741] INFO: test: HighRate no parameter change
[14:05:16.741] INFO: running: highrate
[14:05:16.742] INFO: ----------------------------------------------------------------------
[14:05:16.742] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:05:16.742] INFO: ----------------------------------------------------------------------
[14:05:17.357] INFO: Expecting 208000 events.
[14:05:33.680] INFO: 208000 events read in total (15796ms).
[14:05:33.689] INFO: Test took 16936ms.
[14:05:34.189] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:05:34.555] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 1 0 2 0 0 0
[14:05:34.555] INFO: number of red-efficiency pixels: 459 333 594 1151 1198 1281 1479 836 570 987 883 1017 733 544 112 91
[14:05:34.555] INFO: number of X-ray hits detected: 236872 150192 234976 377540 392851 418902 422076 306734 279631 357921 339826 298511 305702 185532 77089 74292
[14:05:34.555] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:05:34.555] INFO: number of Vcal hits detected: 207444 207610 207213 206540 206403 206247 205953 206918 207358 206792 206896 206727 207052 207319 207880 207905
[14:05:34.555] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.7 99.4 99.3 99.3 99.1 99.5 99.7 99.5 99.5 99.5 99.6 99.7 99.9 100.0
[14:05:34.555] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 99.3 99.2 99.2 99.0 99.5 99.7 99.4 99.5 99.4 99.5 99.7 99.9 100.0
[14:05:34.555] INFO: X-ray hit rate [MHz/cm2]: 69.4 44.0 68.9 110.7 115.1 122.8 123.7 89.9 82.0 104.9 99.6 87.5 89.6 54.4 22.6 21.8
[14:05:34.555] INFO: PixTestHighRate::doXPixelAlive() done
[14:05:34.605] INFO: PixTest:: pg_setup set to default.
[14:05:34.620] INFO: enter test to run
[14:05:58.269] INFO: test: exit no parameter change
[14:05:58.613] QUIET: Connection to board 33 closed.
[14:05:58.614] INFO: pXar: this is the end, my friend