[15:49:29.683] INFO: *** Welcome to pxar ***
[15:49:29.683] INFO: *** Today: 2016/04/13
[15:49:29.711] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:49:29.711] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//dacParameters35_C15.dat
[15:49:29.736] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:49:29.736] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//defaultMaskFile.dat
[15:49:29.736] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C15.dat
[15:49:29.832] INFO: clk: 4
[15:49:29.832] INFO: ctr: 4
[15:49:29.832] INFO: sda: 19
[15:49:29.832] INFO: tin: 9
[15:49:29.832] INFO: level: 15
[15:49:29.832] INFO: triggerdelay: 0
[15:49:29.832] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:49:29.832] INFO: Log level: INFO
[15:49:29.850] QUIET: Connection to board DTB_WREKRL opened.
[15:49:29.854] 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:49:29.857] INFO: RPC call hashes of host and DTB match: 398089610
[15:49:31.385] INFO: DUT info:
[15:49:31.385] INFO: The DUT currently contains the following objects:
[15:49:31.386] INFO: 2 TBM Cores tbm08c (2 ON)
[15:49:31.386] INFO: TBM Core alpha (0): 7 registers set
[15:49:31.386] INFO: TBM Core beta (1): 7 registers set
[15:49:31.386] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:49:31.386] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.386] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:49:31.789] INFO: enter 'restricted' command line mode
[15:49:31.789] INFO: enter test to run
[15:49:38.086] INFO: test: PixelAlive no parameter change
[15:49:38.086] INFO: running: pixelalive
[15:49:38.096] INFO: ----------------------------------------------------------------------
[15:49:38.096] 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:49:38.096] INFO: ----------------------------------------------------------------------
[15:49:38.412] INFO: Expecting 41600 events.
[15:49:42.742] INFO: 41600 events read in total (3612ms).
[15:49:42.911] INFO: Test took 4813ms.
[15:49:42.925] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:43.190] INFO: PixTestAlive::aliveTest() done
[15:49:43.190] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:49:43.225] INFO: enter test to run
[15:51:21.558] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:51:21.558] INFO: running: highrate
[15:51:21.558] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:51:21.783] INFO: ----------------------------------------------------------------------
[15:51:21.783] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:51:21.783] INFO: ----------------------------------------------------------------------
[15:51:21.783] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:51:21.783] INFO: edge/corner pixel THR is adjusted
[15:51:21.783] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:51:22.742] INFO: Collecting data for 5 seconds...
[15:51:27.759] INFO: Done with hot pixel readout
[15:51:39.955] INFO: PixTest:: pg_setup set to default.
[15:51:39.956] INFO: 1 hot pixels found in step 0
[15:51:40.977] INFO: Collecting data for 5 seconds...
[15:51:45.994] INFO: Done with hot pixel readout
[15:51:58.068] INFO: PixTest:: pg_setup set to default.
[15:51:58.069] INFO: 3 hot pixels found in step 1
[15:51:59.065] INFO: Collecting data for 5 seconds...
[15:52:04.082] INFO: Done with hot pixel readout
[15:52:16.223] INFO: PixTest:: pg_setup set to default.
[15:52:16.224] INFO: 6 hot pixels found in step 2
[15:52:17.219] INFO: Collecting data for 5 seconds...
[15:52:22.235] INFO: Done with hot pixel readout
[15:52:34.218] INFO: PixTest:: pg_setup set to default.
[15:52:34.219] INFO: 6 hot pixels found in step 3
[15:52:35.217] INFO: Collecting data for 5 seconds...
[15:52:40.233] INFO: Done with hot pixel readout
[15:52:52.386] INFO: PixTest:: pg_setup set to default.
[15:52:52.387] INFO: 8 hot pixels found in step 4
[15:52:53.384] INFO: Collecting data for 5 seconds...
[15:52:58.401] INFO: Done with hot pixel readout
[15:53:10.464] INFO: PixTest:: pg_setup set to default.
[15:53:10.465] INFO: 3 hot pixels found in step 5
[15:53:11.463] INFO: Collecting data for 5 seconds...
[15:53:16.480] INFO: Done with hot pixel readout
[15:53:28.624] INFO: PixTest:: pg_setup set to default.
[15:53:28.625] INFO: 5 hot pixels found in step 6
[15:53:29.621] INFO: Collecting data for 5 seconds...
[15:53:34.638] INFO: Done with hot pixel readout
[15:53:46.896] INFO: PixTest:: pg_setup set to default.
[15:53:46.897] INFO: 7 hot pixels found in step 7
[15:53:47.894] INFO: Collecting data for 5 seconds...
[15:53:52.912] INFO: Done with hot pixel readout
[15:54:05.121] INFO: PixTest:: pg_setup set to default.
[15:54:05.122] INFO: 2 hot pixels found in step 8
[15:54:06.118] INFO: Collecting data for 5 seconds...
[15:54:11.135] INFO: Done with hot pixel readout
[15:54:23.351] INFO: PixTest:: pg_setup set to default.
[15:54:23.352] INFO: 3 hot pixels found in step 9
[15:54:24.349] INFO: Collecting data for 5 seconds...
[15:54:29.364] INFO: Done with hot pixel readout
[15:54:41.581] INFO: PixTest:: pg_setup set to default.
[15:54:41.582] INFO: 3 hot pixels found in step 10
[15:54:42.579] INFO: Collecting data for 5 seconds...
[15:54:47.594] INFO: Done with hot pixel readout
[15:54:59.854] INFO: PixTest:: pg_setup set to default.

[15:54:59.855] INFO: 2 hot pixels found in step 11
[15:55:00.850] INFO: Collecting data for 5 seconds...
[15:55:05.866] INFO: Done with hot pixel readout
[15:55:18.073] INFO: PixTest:: pg_setup set to default.
[15:55:18.074] INFO: 4 hot pixels found in step 12
[15:55:19.070] INFO: Collecting data for 5 seconds...
[15:55:24.086] INFO: Done with hot pixel readout
[15:55:36.352] INFO: PixTest:: pg_setup set to default.
[15:55:36.353] INFO: 4 hot pixels found in step 13
[15:55:37.350] INFO: Collecting data for 5 seconds...
[15:55:42.366] INFO: Done with hot pixel readout
[15:55:54.615] INFO: PixTest:: pg_setup set to default.
[15:55:54.616] INFO: 7 hot pixels found in step 14
[15:55:54.656] INFO: 7 hot pixels could not be trimmed and have been masked.
[15:55:54.660] INFO: PixTest::trimHotPixels() done
[15:55:54.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C0.dat
[15:55:54.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C1.dat
[15:55:54.672] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C2.dat
[15:55:54.679] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C3.dat
[15:55:54.684] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C4.dat
[15:55:54.689] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C5.dat
[15:55:54.694] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C6.dat
[15:55:54.700] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C7.dat
[15:55:54.705] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C8.dat
[15:55:54.710] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C9.dat
[15:55:54.716] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C10.dat
[15:55:54.721] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C11.dat
[15:55:54.726] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C12.dat
[15:55:54.732] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C13.dat
[15:55:54.737] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C14.dat
[15:55:54.742] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C15.dat
[15:55:54.748] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//defaultMaskFile.dat
[15:55:54.766] INFO: enter test to run
[15:56:39.955] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:56:39.955] INFO: running: highrate
[15:56:39.960] INFO: ----------------------------------------------------------------------
[15:56:39.960] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:56:39.960] INFO: ----------------------------------------------------------------------
[15:56:39.960] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:56:39.960] INFO: edge/corner pixel THR is adjusted
[15:56:39.960] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:56:40.918] INFO: Collecting data for 1 seconds...
[15:56:41.921] INFO: Done with hot pixel readout
[15:56:46.445] INFO: PixTest:: pg_setup set to default.
[15:56:46.446] INFO: 0 hot pixels found in step 0
[15:56:46.451] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:56:46.524] INFO: PixTest::trimHotPixels() done
[15:56:46.524] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C0.dat
[15:56:46.533] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C1.dat
[15:56:46.538] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C2.dat
[15:56:46.543] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C3.dat
[15:56:46.549] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C4.dat
[15:56:46.554] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C5.dat
[15:56:46.559] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C6.dat
[15:56:46.565] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C7.dat
[15:56:46.570] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C8.dat
[15:56:46.575] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C9.dat
[15:56:46.581] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C10.dat
[15:56:46.586] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C11.dat
[15:56:46.591] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C12.dat
[15:56:46.597] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C13.dat
[15:56:46.602] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C14.dat
[15:56:46.607] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//trimParameters35_C15.dat
[15:56:46.613] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-3-22_FPIXTest-17C-FNAL-160408-1212_2016-04-08_12h12m_1460135548/000_FPIXTest_p17//defaultMaskFile.dat
[15:56:46.623] INFO: enter test to run
[15:57:10.083] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:57:10.083] INFO: running: xray
[15:57:10.084] INFO: ----------------------------------------------------------------------
[15:57:10.084] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:57:10.084] INFO: ----------------------------------------------------------------------
[15:57:11.047] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:57:21.665] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[15:57:51.231] INFO: Resuming triggers.
[15:58:01.849] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[15:58:31.428] INFO: Resuming triggers.
[15:58:42.048] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[15:59:08.495] INFO: Resuming triggers.
[15:59:19.114] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[15:59:48.621] INFO: Resuming triggers.
[15:59:59.242] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[16:00:28.780] INFO: Resuming triggers.
[16:00:39.400] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[16:01:08.850] INFO: Resuming triggers.
[16:01:19.470] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[16:01:49.038] INFO: Resuming triggers.
[16:01:59.657] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[16:02:29.152] INFO: Resuming triggers.
[16:02:39.770] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[16:03:09.286] INFO: Resuming triggers.
[16:03:14.031] INFO: data taking finished, elapsed time: 100 seconds.
[16:03:27.532] INFO: PixTest:: pg_setup set to default.
[16:03:27.535] INFO: PixTestXray::doPhRun() done
[16:03:27.672] INFO: enter test to run
[16:04:24.664] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:04:24.664] INFO: running: xray
[16:04:24.665] INFO: ----------------------------------------------------------------------
[16:04:24.665] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:04:24.665] INFO: ----------------------------------------------------------------------
[16:04:25.628] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:04:31.230] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[16:05:01.506] INFO: Resuming triggers.
[16:05:07.109] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:05:37.346] INFO: Resuming triggers.
[16:05:42.947] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[16:06:13.053] INFO: Resuming triggers.
[16:06:18.652] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:06:48.911] INFO: Resuming triggers.
[16:06:54.510] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[16:07:24.740] INFO: Resuming triggers.
[16:07:30.342] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:08:00.550] INFO: Resuming triggers.
[16:08:06.154] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[16:08:36.360] INFO: Resuming triggers.
[16:08:41.962] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[16:09:07.495] INFO: Resuming triggers.
[16:09:13.099] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[16:09:43.331] INFO: Resuming triggers.
[16:09:48.935] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[16:10:19.193] INFO: Resuming triggers.
[16:10:24.798] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[16:10:55.054] INFO: Resuming triggers.
[16:11:00.659] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:11:31.329] INFO: Resuming triggers.
[16:11:36.935] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[16:12:06.901] INFO: Resuming triggers.
[16:12:12.509] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[16:12:42.699] INFO: Resuming triggers.
[16:12:48.304] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[16:13:18.531] INFO: Resuming triggers.
[16:13:24.136] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[16:13:54.353] INFO: Resuming triggers.
[16:13:59.955] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[16:14:30.222] INFO: Resuming triggers.
[16:14:35.298] INFO: data taking finished, elapsed time: 100 seconds.
[16:15:02.820] INFO: PixTest:: pg_setup set to default.
[16:15:02.823] INFO: PixTestXray::doPhRun() done
[16:15:02.972] INFO: enter test to run
[16:15:40.395] INFO: test: HighRate no parameter change
[16:15:40.395] INFO: running: highrate
[16:15:40.396] INFO: ----------------------------------------------------------------------
[16:15:40.396] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:15:40.396] INFO: ----------------------------------------------------------------------
[16:15:40.536] INFO: Expecting 768 events.
[16:15:41.670] INFO: 768 events read in total (418ms).
[16:15:41.670] INFO: Test took 1268ms.
[16:15:42.474] INFO: Expecting 41600 events.
[16:15:45.591] INFO: 41600 events read in total (2590ms).
[16:15:45.592] INFO: Test took 3915ms.
[16:15:45.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:15:46.346] INFO: Expecting 41600 events.
[16:15:49.604] INFO: 41600 events read in total (2731ms).
[16:15:49.605] INFO: Test took 3953ms.
[16:15:49.645] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:15:50.356] INFO: Expecting 41600 events.
[16:15:53.674] INFO: 41600 events read in total (2791ms).
[16:15:53.675] INFO: Test took 4011ms.
[16:15:53.716] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:15:54.427] INFO: Expecting 41600 events.
[16:15:57.731] INFO: 41600 events read in total (2777ms).
[16:15:57.732] INFO: Test took 3997ms.
[16:15:57.773] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:15:58.485] INFO: Expecting 41600 events.
[16:16:01.788] INFO: 41600 events read in total (2776ms).
[16:16:01.789] INFO: Test took 3994ms.
[16:16:01.829] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:02.543] INFO: Expecting 41600 events.
[16:16:05.840] INFO: 41600 events read in total (2770ms).
[16:16:05.841] INFO: Test took 3991ms.
[16:16:05.881] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:06.592] INFO: Expecting 41600 events.
[16:16:09.913] INFO: 41600 events read in total (2794ms).
[16:16:09.914] INFO: Test took 4012ms.
[16:16:09.955] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:10.667] INFO: Expecting 41600 events.
[16:16:13.979] INFO: 41600 events read in total (2785ms).
[16:16:13.981] INFO: Test took 4006ms.
[16:16:14.021] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:14.734] INFO: Expecting 41600 events.
[16:16:18.044] INFO: 41600 events read in total (2783ms).
[16:16:18.045] INFO: Test took 4003ms.
[16:16:18.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:18.793] INFO: Expecting 41600 events.
[16:16:22.115] INFO: 41600 events read in total (2796ms).
[16:16:22.116] INFO: Test took 4010ms.
[16:16:22.157] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:22.868] INFO: Expecting 41600 events.
[16:16:26.172] INFO: 41600 events read in total (2777ms).
[16:16:26.174] INFO: Test took 3997ms.
[16:16:26.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:26.928] INFO: Expecting 41600 events.
[16:16:30.237] INFO: 41600 events read in total (2782ms).
[16:16:30.238] INFO: Test took 4003ms.
[16:16:30.278] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:30.988] INFO: Expecting 41600 events.
[16:16:34.318] INFO: 41600 events read in total (2803ms).
[16:16:34.319] INFO: Test took 4020ms.
[16:16:34.361] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:35.072] INFO: Expecting 41600 events.
[16:16:38.385] INFO: 41600 events read in total (2786ms).
[16:16:38.386] INFO: Test took 4005ms.
[16:16:38.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:39.137] INFO: Expecting 41600 events.
[16:16:42.444] INFO: 41600 events read in total (2780ms).
[16:16:42.445] INFO: Test took 3997ms.
[16:16:42.485] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:43.198] INFO: Expecting 41600 events.
[16:16:46.521] INFO: 41600 events read in total (2796ms).
[16:16:46.522] INFO: Test took 4017ms.
[16:16:46.562] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:47.271] INFO: Expecting 41600 events.
[16:16:50.590] INFO: 41600 events read in total (2792ms).
[16:16:50.591] INFO: Test took 4008ms.
[16:16:50.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:51.344] INFO: Expecting 41600 events.
[16:16:54.657] INFO: 41600 events read in total (2786ms).
[16:16:54.658] INFO: Test took 4005ms.
[16:16:54.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:55.409] INFO: Expecting 41600 events.
[16:16:58.714] INFO: 41600 events read in total (2778ms).
[16:16:58.715] INFO: Test took 3995ms.
[16:16:58.756] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:16:59.466] INFO: Expecting 41600 events.
[16:17:02.672] INFO: 41600 events read in total (2679ms).
[16:17:02.674] INFO: Test took 3898ms.
[16:17:02.714] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:17:03.062] INFO: enter test to run
[16:17:58.730] INFO: test: HighRate no parameter change
[16:17:58.730] INFO: running: highrate
[16:17:58.731] INFO: ----------------------------------------------------------------------
[16:17:58.731] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:17:58.731] INFO: ----------------------------------------------------------------------
[16:17:59.342] INFO: Expecting 208000 events.
[16:18:11.747] INFO: 208000 events read in total (11879ms).
[16:18:11.750] INFO: Test took 13010ms.
[16:18:11.931] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:18:12.195] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:18:12.195] INFO: number of red-efficiency pixels: 115 68 126 166 171 253 201 109 114 167 226 150 165 107 26 34
[16:18:12.195] INFO: number of X-ray hits detected: 79963 53883 84158 131314 137165 144177 147170 97034 96238 127942 129620 111777 117910 69869 28909 30884
[16:18:12.195] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:18:12.195] INFO: number of Vcal hits detected: 207881 207931 207869 207831 207824 207740 207792 207885 207883 207829 207764 207848 207833 207888 207974 207964
[16:18:12.196] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[16:18:12.196] INFO: Vcal hit overall efficiency (%): 99.9 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[16:18:12.196] INFO: X-ray hit rate [MHz/cm2]: 23.4 15.8 24.7 38.5 40.2 42.3 43.1 28.4 28.2 37.5 38.0 32.8 34.6 20.5 8.5 9.1
[16:18:12.196] INFO: PixTestHighRate::doXPixelAlive() done
[16:18:12.240] INFO: PixTest:: pg_setup set to default.
[16:18:12.251] INFO: enter test to run
[16:18:30.170] INFO: test: HighRate no parameter change
[16:18:30.170] INFO: running: highrate
[16:18:30.171] INFO: ----------------------------------------------------------------------
[16:18:30.171] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:18:30.171] INFO: ----------------------------------------------------------------------
[16:18:30.785] INFO: Expecting 208000 events.
[16:18:45.449] INFO: 208000 events read in total (14137ms).
[16:18:45.455] INFO: Test took 15273ms.
[16:18:45.819] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:18:46.143] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:18:46.143] INFO: number of red-efficiency pixels: 310 145 347 524 580 870 679 363 322 480 698 435 562 301 68 83
[16:18:46.143] INFO: number of X-ray hits detected: 163117 112035 172323 268666 282486 295703 303198 197434 199067 264054 267448 231447 242197 143271 60174 64281
[16:18:46.143] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:18:46.143] INFO: number of Vcal hits detected: 207656 207848 207599 207428 207354 206958 207214 207600 207653 207469 207206 207528 207378 207669 207930 207915
[16:18:46.143] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.5 99.7 99.8 99.9 99.8 99.7 99.8 99.7 99.9 100.0 100.0
[16:18:46.143] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.5 99.6 99.8 99.8 99.7 99.6 99.8 99.7 99.8 100.0 100.0
[16:18:46.143] INFO: X-ray hit rate [MHz/cm2]: 47.8 32.8 50.5 78.7 82.8 86.7 88.9 57.9 58.3 77.4 78.4 67.8 71.0 42.0 17.6 18.8
[16:18:46.143] INFO: PixTestHighRate::doXPixelAlive() done
[16:18:46.195] INFO: PixTest:: pg_setup set to default.
[16:18:46.210] INFO: enter test to run
[16:19:01.145] INFO: test: HighRate no parameter change
[16:19:01.145] INFO: running: highrate
[16:19:01.146] INFO: ----------------------------------------------------------------------
[16:19:01.146] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:19:01.146] INFO: ----------------------------------------------------------------------
[16:19:01.753] INFO: Expecting 208000 events.
[16:19:19.179] INFO: 208000 events read in total (16900ms).
[16:19:19.188] INFO: Test took 18035ms.
[16:19:19.751] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:19:20.138] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:19:20.138] INFO: number of red-efficiency pixels: 744 305 845 1299 1448 1999 1748 772 735 1270 1692 1001 1380 772 119 133
[16:19:20.138] INFO: number of X-ray hits detected: 250487 169978 264115 412261 432344 453912 463888 303385 304957 402942 409710 354197 371283 219169 92610 98863
[16:19:20.138] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:19:20.138] INFO: number of Vcal hits detected: 207040 207665 206724 206271 205984 204790 205347 207003 207083 206367 205574 206737 206122 206938 207876 207865
[16:19:20.138] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.5 99.3 99.1 98.6 98.9 99.6 99.6 99.3 98.9 99.5 99.2 99.5 99.9 99.9
[16:19:20.138] INFO: Vcal hit overall efficiency (%): 99.5 99.8 99.4 99.2 99.0 98.5 98.7 99.5 99.6 99.2 98.8 99.4 99.1 99.5 99.9 99.9
[16:19:20.138] INFO: X-ray hit rate [MHz/cm2]: 73.4 49.8 77.4 120.8 126.7 133.0 136.0 88.9 89.4 118.1 120.1 103.8 108.8 64.2 27.1 29.0
[16:19:20.138] INFO: PixTestHighRate::doXPixelAlive() done
[16:19:20.186] INFO: PixTest:: pg_setup set to default.
[16:19:20.203] INFO: enter test to run
[16:19:58.777] INFO: test: exit no parameter change
[16:19:59.016] QUIET: Connection to board 33 closed.
[16:19:59.017] INFO: pXar: this is the end, my friend