[15:10:15.555] INFO: *** Welcome to pxar ***
[15:10:15.555] INFO: *** Today: 2016/05/16
[15:10:15.581] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:10:15.581] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//dacParameters35_C15.dat
[15:10:15.613] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:10:15.614] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//defaultMaskFile.dat
[15:10:15.625] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C15.dat
[15:10:15.703] INFO: clk: 4
[15:10:15.703] INFO: ctr: 4
[15:10:15.703] INFO: sda: 19
[15:10:15.703] INFO: tin: 9
[15:10:15.703] INFO: level: 15
[15:10:15.703] INFO: triggerdelay: 0
[15:10:15.704] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:10:15.704] INFO: Log level: INFO
[15:10:15.720] QUIET: Connection to board DTB_WREKRL opened.
[15:10:15.723] 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:
------------------------------------------------------
[15:10:15.726] INFO: RPC call hashes of host and DTB match: 398089610
[15:10:17.260] INFO: DUT info:
[15:10:17.260] INFO: The DUT currently contains the following objects:
[15:10:17.260] INFO: 2 TBM Cores tbm08c (2 ON)
[15:10:17.260] INFO: TBM Core alpha (0): 7 registers set
[15:10:17.260] INFO: TBM Core beta (1): 7 registers set
[15:10:17.260] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:10:17.260] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.260] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.260] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.260] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.260] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.260] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.261] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:10:17.664] INFO: enter 'restricted' command line mode
[15:10:17.664] INFO: enter test to run
[15:10:20.465] INFO: test: PixelAlive no parameter change
[15:10:20.465] INFO: running: pixelalive
[15:10:20.474] INFO: ----------------------------------------------------------------------
[15:10:20.474] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:10:20.474] INFO: ----------------------------------------------------------------------
[15:10:20.791] INFO: Expecting 41600 events.
[15:10:25.119] INFO: 41600 events read in total (3610ms).
[15:10:25.287] INFO: Test took 4810ms.
[15:10:25.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:10:25.572] INFO: PixTestAlive::aliveTest() done
[15:10:25.572] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:10:25.606] INFO: enter test to run
[15:11:25.760] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:11:25.760] INFO: running: highrate
[15:11:25.761] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:11:25.974] INFO: ----------------------------------------------------------------------
[15:11:25.974] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:11:25.974] INFO: ----------------------------------------------------------------------
[15:11:25.974] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:11:25.974] INFO: edge/corner pixel THR is adjusted
[15:11:25.974] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:11:26.934] INFO: Collecting data for 5 seconds...
[15:11:31.950] INFO: Done with hot pixel readout
[15:11:43.676] INFO: PixTest:: pg_setup set to default.
[15:11:43.677] INFO: 5 hot pixels found in step 0
[15:11:44.691] INFO: Collecting data for 5 seconds...
[15:11:49.708] INFO: Done with hot pixel readout
[15:12:01.474] INFO: PixTest:: pg_setup set to default.
[15:12:01.475] INFO: 6 hot pixels found in step 1
[15:12:02.471] INFO: Collecting data for 5 seconds...
[15:12:07.488] INFO: Done with hot pixel readout
[15:12:19.246] INFO: PixTest:: pg_setup set to default.
[15:12:19.247] INFO: 8 hot pixels found in step 2
[15:12:20.240] INFO: Collecting data for 5 seconds...
[15:12:25.256] INFO: Done with hot pixel readout
[15:12:37.042] INFO: PixTest:: pg_setup set to default.
[15:12:37.043] INFO: 6 hot pixels found in step 3
[15:12:38.036] INFO: Collecting data for 5 seconds...
[15:12:43.052] INFO: Done with hot pixel readout
[15:12:54.825] INFO: PixTest:: pg_setup set to default.
[15:12:54.826] INFO: 5 hot pixels found in step 4
[15:12:55.818] INFO: Collecting data for 5 seconds...
[15:13:00.834] INFO: Done with hot pixel readout
[15:13:12.584] INFO: PixTest:: pg_setup set to default.
[15:13:12.585] INFO: 3 hot pixels found in step 5
[15:13:13.578] INFO: Collecting data for 5 seconds...
[15:13:18.594] INFO: Done with hot pixel readout
[15:13:30.386] INFO: PixTest:: pg_setup set to default.
[15:13:30.387] INFO: 1 hot pixels found in step 6
[15:13:31.379] INFO: Collecting data for 5 seconds...
[15:13:36.397] INFO: Done with hot pixel readout
[15:13:47.985] INFO: PixTest:: pg_setup set to default.
[15:13:47.986] INFO: 2 hot pixels found in step 7
[15:13:48.980] INFO: Collecting data for 5 seconds...
[15:13:53.998] INFO: Done with hot pixel readout
[15:14:05.761] INFO: PixTest:: pg_setup set to default.
[15:14:05.762] INFO: 1 hot pixels found in step 8
[15:14:06.754] INFO: Collecting data for 5 seconds...
[15:14:11.772] INFO: Done with hot pixel readout
[15:14:23.365] INFO: PixTest:: pg_setup set to default.
[15:14:23.366] INFO: 3 hot pixels found in step 9
[15:14:24.358] INFO: Collecting data for 5 seconds...
[15:14:29.378] INFO: Done with hot pixel readout
[15:14:41.076] INFO: PixTest:: pg_setup set to default.
[15:14:41.077] INFO: 1 hot pixels found in step 10
[15:14:42.070] INFO: Collecting data for 5 seconds...
[15:14:47.088] INFO: Done with hot pixel readout
[15:14:58.829] INFO: PixTest:: pg_setup set to default.
[15:14:58.830] INFO: 3 hot pixels found in step 11
[15:14:59.823] INFO: Collecting data for 5 seconds...
[15:15:04.840] INFO: Done with hot pixel readout
[15:15:16.618] INFO: PixTest:: pg_setup set to default.
[15:15:16.619] INFO: 1 hot pixels found in step 12
[15:15:17.612] INFO: Collecting data for 5 seconds...
[15:15:22.630] INFO: Done with hot pixel readout
[15:15:34.385] INFO: PixTest:: pg_setup set to default.
[15:15:34.385] INFO: 1 hot pixels found in step 13
[15:15:35.378] INFO: Collecting data for 5 seconds...
[15:15:40.399] INFO: Done with hot pixel readout
[15:15:51.937] INFO: PixTest:: pg_setup set to default.
[15:15:51.938] INFO: 0 hot pixels found in step 14
[15:15:51.975] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:15:51.979] INFO: PixTest::trimHotPixels() done
[15:15:51.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C0.dat
[15:15:51.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C1.dat
[15:15:51.990] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C2.dat
[15:15:51.997] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C3.dat
[15:15:52.002] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C4.dat
[15:15:52.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C5.dat
[15:15:52.013] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C6.dat
[15:15:52.018] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C7.dat
[15:15:52.024] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C8.dat
[15:15:52.030] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C9.dat
[15:15:52.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C10.dat
[15:15:52.041] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C11.dat
[15:15:52.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C12.dat
[15:15:52.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C13.dat
[15:15:52.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C14.dat
[15:15:52.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C15.dat
[15:15:52.068] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//defaultMaskFile.dat
[15:15:52.078] INFO: enter test to run
[15:16:26.254] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:16:26.254] INFO: running: highrate
[15:16:26.259] INFO: ----------------------------------------------------------------------
[15:16:26.259] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:16:26.259] INFO: ----------------------------------------------------------------------
[15:16:26.259] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:16:26.259] INFO: edge/corner pixel THR is adjusted
[15:16:26.259] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:16:27.216] INFO: Collecting data for 1 seconds...
[15:16:28.220] INFO: Done with hot pixel readout
[15:16:32.366] INFO: PixTest:: pg_setup set to default.
[15:16:32.367] INFO: 0 hot pixels found in step 0
[15:16:32.373] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:16:32.454] INFO: PixTest::trimHotPixels() done
[15:16:32.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C0.dat
[15:16:32.465] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C1.dat
[15:16:32.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C2.dat
[15:16:32.480] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C3.dat
[15:16:32.485] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C4.dat
[15:16:32.491] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C5.dat
[15:16:32.496] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C6.dat
[15:16:32.502] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C7.dat
[15:16:32.507] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C8.dat
[15:16:32.513] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C9.dat
[15:16:32.518] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C10.dat
[15:16:32.523] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C11.dat
[15:16:32.529] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C12.dat
[15:16:32.534] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C13.dat
[15:16:32.540] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C14.dat
[15:16:32.545] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//trimParameters35_C15.dat
[15:16:32.550] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NB_FPIXTest-17C-FNAL-160509-1152_2016-05-09_11h53m_1462812787/000_FPIXTest_p17//defaultMaskFile.dat
[15:16:32.564] INFO: enter test to run
[15:16:56.318] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:16:56.318] INFO: running: xray
[15:16:56.319] INFO: ----------------------------------------------------------------------
[15:16:56.319] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:16:56.319] INFO: ----------------------------------------------------------------------
[15:16:57.282] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:17:08.667] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:17:37.950] INFO: Resuming triggers.
[15:17:49.337] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:18:18.783] INFO: Resuming triggers.
[15:18:30.165] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:18:59.498] INFO: Resuming triggers.
[15:19:10.888] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:19:40.277] INFO: Resuming triggers.
[15:19:51.663] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:20:20.742] INFO: Resuming triggers.
[15:20:32.126] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[15:21:00.876] INFO: Resuming triggers.
[15:21:12.267] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:21:40.416] INFO: Resuming triggers.
[15:21:51.800] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:22:20.476] INFO: Resuming triggers.
[15:22:29.713] INFO: data taking finished, elapsed time: 100 seconds.
[15:22:53.204] INFO: PixTest:: pg_setup set to default.
[15:22:53.207] INFO: PixTestXray::doPhRun() done
[15:22:53.344] INFO: enter test to run
[15:23:17.395] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:23:17.395] INFO: running: xray
[15:23:17.396] INFO: ----------------------------------------------------------------------
[15:23:17.396] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:23:17.396] INFO: ----------------------------------------------------------------------
[15:23:18.360] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:23:24.940] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:23:54.561] INFO: Resuming triggers.
[15:24:01.147] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:24:30.802] INFO: Resuming triggers.
[15:24:37.386] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:25:07.474] INFO: Resuming triggers.
[15:25:14.057] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:25:43.513] INFO: Resuming triggers.
[15:25:50.096] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[15:26:19.762] INFO: Resuming triggers.
[15:26:26.350] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:26:56.111] INFO: Resuming triggers.
[15:27:02.698] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:27:32.859] INFO: Resuming triggers.
[15:27:39.443] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:28:09.216] INFO: Resuming triggers.
[15:28:15.798] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:28:45.434] INFO: Resuming triggers.
[15:28:52.021] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[15:29:21.619] INFO: Resuming triggers.
[15:29:28.203] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[15:29:57.804] INFO: Resuming triggers.
[15:30:04.393] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:30:33.950] INFO: Resuming triggers.
[15:30:40.534] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[15:31:10.597] INFO: Resuming triggers.
[15:31:17.181] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[15:31:47.266] INFO: Resuming triggers.
[15:31:53.851] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[15:32:23.903] INFO: Resuming triggers.
[15:32:25.456] INFO: data taking finished, elapsed time: 100 seconds.
[15:32:32.886] INFO: PixTest:: pg_setup set to default.
[15:32:32.890] INFO: PixTestXray::doPhRun() done
[15:32:33.040] INFO: enter test to run
[15:32:56.487] INFO: test: HighRate no parameter change
[15:32:56.487] INFO: running: highrate
[15:32:56.488] INFO: ----------------------------------------------------------------------
[15:32:56.488] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:32:56.488] INFO: ----------------------------------------------------------------------
[15:32:56.630] INFO: Expecting 768 events.
[15:32:57.764] INFO: 768 events read in total (418ms).
[15:32:57.765] INFO: Test took 1269ms.
[15:32:58.567] INFO: Expecting 41600 events.
[15:33:01.637] INFO: 41600 events read in total (2543ms).
[15:33:01.639] INFO: Test took 3867ms.
[15:33:01.677] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:02.396] INFO: Expecting 41600 events.
[15:33:05.583] INFO: 41600 events read in total (2660ms).
[15:33:05.584] INFO: Test took 3888ms.
[15:33:05.621] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:06.344] INFO: Expecting 41600 events.
[15:33:09.588] INFO: 41600 events read in total (2717ms).
[15:33:09.589] INFO: Test took 3949ms.
[15:33:09.625] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:10.346] INFO: Expecting 41600 events.
[15:33:13.595] INFO: 41600 events read in total (2722ms).
[15:33:13.596] INFO: Test took 3952ms.
[15:33:13.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:14.349] INFO: Expecting 41600 events.
[15:33:17.594] INFO: 41600 events read in total (2718ms).
[15:33:17.595] INFO: Test took 3945ms.
[15:33:17.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:18.354] INFO: Expecting 41600 events.
[15:33:21.613] INFO: 41600 events read in total (2732ms).
[15:33:21.614] INFO: Test took 3964ms.
[15:33:21.650] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:22.369] INFO: Expecting 41600 events.
[15:33:25.632] INFO: 41600 events read in total (2737ms).
[15:33:25.633] INFO: Test took 3965ms.
[15:33:25.669] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:26.388] INFO: Expecting 41600 events.
[15:33:29.630] INFO: 41600 events read in total (2715ms).
[15:33:29.631] INFO: Test took 3943ms.
[15:33:29.667] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:30.389] INFO: Expecting 41600 events.
[15:33:33.647] INFO: 41600 events read in total (2731ms).
[15:33:33.648] INFO: Test took 3963ms.
[15:33:33.684] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:34.402] INFO: Expecting 41600 events.
[15:33:37.669] INFO: 41600 events read in total (2740ms).
[15:33:37.670] INFO: Test took 3967ms.
[15:33:37.706] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:38.426] INFO: Expecting 41600 events.
[15:33:41.686] INFO: 41600 events read in total (2733ms).
[15:33:41.687] INFO: Test took 3963ms.
[15:33:41.724] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:42.441] INFO: Expecting 41600 events.
[15:33:45.676] INFO: 41600 events read in total (2708ms).
[15:33:45.677] INFO: Test took 3934ms.
[15:33:45.713] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:46.436] INFO: Expecting 41600 events.
[15:33:49.684] INFO: 41600 events read in total (2721ms).
[15:33:49.685] INFO: Test took 3954ms.
[15:33:49.720] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:50.444] INFO: Expecting 41600 events.
[15:33:53.703] INFO: 41600 events read in total (2732ms).
[15:33:53.704] INFO: Test took 3966ms.
[15:33:53.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:54.462] INFO: Expecting 41600 events.
[15:33:57.709] INFO: 41600 events read in total (2720ms).
[15:33:57.710] INFO: Test took 3951ms.
[15:33:57.746] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:58.467] INFO: Expecting 41600 events.
[15:34:01.729] INFO: 41600 events read in total (2735ms).
[15:34:01.730] INFO: Test took 3965ms.
[15:34:01.765] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:02.487] INFO: Expecting 41600 events.
[15:34:05.749] INFO: 41600 events read in total (2735ms).
[15:34:05.750] INFO: Test took 3965ms.
[15:34:05.786] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:06.507] INFO: Expecting 41600 events.
[15:34:09.767] INFO: 41600 events read in total (2733ms).
[15:34:09.768] INFO: Test took 3963ms.
[15:34:09.803] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:10.521] INFO: Expecting 41600 events.
[15:34:13.764] INFO: 41600 events read in total (2716ms).
[15:34:13.765] INFO: Test took 3942ms.
[15:34:13.801] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:14.523] INFO: Expecting 41600 events.
[15:34:17.713] INFO: 41600 events read in total (2664ms).
[15:34:17.714] INFO: Test took 3894ms.
[15:34:17.750] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:18.108] INFO: enter test to run
[15:34:25.886] INFO: test: HighRate no parameter change
[15:34:25.886] INFO: running: highrate
[15:34:25.887] INFO: ----------------------------------------------------------------------
[15:34:25.887] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:34:25.888] INFO: ----------------------------------------------------------------------
[15:34:26.504] INFO: Expecting 208000 events.
[15:34:38.445] INFO: 208000 events read in total (11415ms).
[15:34:38.449] INFO: Test took 12555ms.
[15:34:38.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:34:38.857] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:34:38.857] INFO: number of red-efficiency pixels: 75 46 85 135 136 159 159 112 104 158 129 97 103 73 37 40
[15:34:38.857] INFO: number of X-ray hits detected: 69404 48488 64479 105963 111457 113417 117772 90414 89245 107232 107616 90874 95081 57111 25774 29806
[15:34:38.857] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:34:38.857] INFO: number of Vcal hits detected: 207924 207954 207914 207864 207860 207836 207835 207887 207890 207836 207869 207902 207892 207925 207963 207960
[15:34:38.857] 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
[15:34:38.857] 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 100.0 99.9 100.0 100.0 100.0
[15:34:38.857] INFO: X-ray hit rate [MHz/cm2]: 20.3 14.2 18.9 31.1 32.7 33.2 34.5 26.5 26.2 31.4 31.5 26.6 27.9 16.7 7.6 8.7
[15:34:38.857] INFO: PixTestHighRate::doXPixelAlive() done
[15:34:38.902] INFO: PixTest:: pg_setup set to default.
[15:34:38.918] INFO: enter test to run
[15:34:55.246] INFO: test: HighRate no parameter change
[15:34:55.246] INFO: running: highrate
[15:34:55.247] INFO: ----------------------------------------------------------------------
[15:34:55.247] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:34:55.247] INFO: ----------------------------------------------------------------------
[15:34:55.859] INFO: Expecting 208000 events.
[15:35:09.544] INFO: 208000 events read in total (13158ms).
[15:35:09.549] INFO: Test took 14293ms.
[15:35:09.854] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:10.156] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:35:10.156] INFO: number of red-efficiency pixels: 269 150 232 339 416 505 540 368 329 451 490 281 348 173 53 81
[15:35:10.156] INFO: number of X-ray hits detected: 137224 96054 129074 211774 222483 225574 234695 180588 178751 215351 215435 181578 189951 113627 51377 59901
[15:35:10.156] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:35:10.156] INFO: number of Vcal hits detected: 207710 207841 207746 207641 207552 207453 207396 207609 207643 207503 207480 207694 207628 207815 207946 207917
[15:35:10.156] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[15:35:10.156] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.8 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[15:35:10.156] INFO: X-ray hit rate [MHz/cm2]: 40.2 28.2 37.8 62.1 65.2 66.1 68.8 52.9 52.4 63.1 63.1 53.2 55.7 33.3 15.1 17.6
[15:35:10.156] INFO: PixTestHighRate::doXPixelAlive() done
[15:35:10.205] INFO: PixTest:: pg_setup set to default.
[15:35:10.219] INFO: enter test to run
[15:35:28.846] INFO: test: HighRate no parameter change
[15:35:28.846] INFO: running: highrate
[15:35:28.847] INFO: ----------------------------------------------------------------------
[15:35:28.847] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:35:28.847] INFO: ----------------------------------------------------------------------
[15:35:29.459] INFO: Expecting 208000 events.
[15:35:45.142] INFO: 208000 events read in total (15156ms).
[15:35:45.150] INFO: Test took 16295ms.
[15:35:45.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:35:45.956] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:35:45.956] INFO: number of red-efficiency pixels: 489 296 603 744 1021 1198 1280 816 723 1127 1136 610 936 363 113 158
[15:35:45.956] INFO: number of X-ray hits detected: 209233 146505 196239 322605 337923 343020 357778 275150 271994 327978 328112 276731 289872 172972 79185 91499
[15:35:45.956] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:35:45.956] INFO: number of Vcal hits detected: 207406 207683 207253 207138 206729 206469 206343 206992 207132 206583 206596 207292 206892 207577 207882 207832
[15:35:45.956] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.6 99.5 99.3 99.3 99.6 99.6 99.4 99.4 99.7 99.5 99.8 99.9 99.9
[15:35:45.956] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 99.6 99.4 99.3 99.2 99.5 99.6 99.3 99.3 99.7 99.5 99.8 99.9 99.9
[15:35:45.956] INFO: X-ray hit rate [MHz/cm2]: 61.3 42.9 57.5 94.6 99.0 100.5 104.9 80.6 79.7 96.1 96.2 81.1 85.0 50.7 23.2 26.8
[15:35:45.956] INFO: PixTestHighRate::doXPixelAlive() done
[15:35:46.005] INFO: PixTest:: pg_setup set to default.
[15:35:46.017] INFO: enter test to run
[15:35:51.030] INFO: test: exit no parameter change
[15:35:51.437] QUIET: Connection to board 33 closed.
[15:35:51.438] INFO: pXar: this is the end, my friend