[10:59:45.902] INFO: *** Welcome to pxar ***
[10:59:45.902] INFO: *** Today: 2016/04/22
[10:59:45.923] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:59:45.923] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//dacParameters35_C15.dat
[10:59:45.949] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:59:45.949] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//defaultMaskFile.dat
[10:59:45.949] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C15.dat
[10:59:46.059] INFO: clk: 4
[10:59:46.059] INFO: ctr: 4
[10:59:46.059] INFO: sda: 19
[10:59:46.059] INFO: tin: 9
[10:59:46.059] INFO: level: 15
[10:59:46.059] INFO: triggerdelay: 0
[10:59:46.059] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:59:46.059] INFO: Log level: INFO
[10:59:46.076] QUIET: Connection to board DTB_WREK4U opened.
[10:59:46.080] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[10:59:46.083] INFO: RPC call hashes of host and DTB match: 398089610
[10:59:47.621] INFO: DUT info:
[10:59:47.621] INFO: The DUT currently contains the following objects:
[10:59:47.621] INFO: 2 TBM Cores tbm08c (2 ON)
[10:59:47.621] INFO: TBM Core alpha (0): 7 registers set
[10:59:47.621] INFO: TBM Core beta (1): 7 registers set
[10:59:47.621] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:59:47.621] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.621] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:47.622] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:59:48.026] INFO: enter 'restricted' command line mode
[10:59:48.026] INFO: enter test to run
[10:59:51.351] INFO: test: PixelAlive no parameter change
[10:59:51.364] INFO: running: pixelalive
[10:59:51.373] INFO: ----------------------------------------------------------------------
[10:59:51.373] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:59:51.373] INFO: ----------------------------------------------------------------------
[10:59:51.694] INFO: Expecting 41600 events.
[10:59:55.988] INFO: 41600 events read in total (3575ms).
[10:59:56.155] INFO: Test took 4779ms.
[10:59:56.166] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:59:56.427] INFO: PixTestAlive::aliveTest() done
[10:59:56.427] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[10:59:56.462] INFO: enter test to run
[11:00:45.175] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:00:45.175] INFO: running: highrate
[11:00:45.176] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:00:45.391] INFO: ----------------------------------------------------------------------
[11:00:45.391] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:00:45.391] INFO: ----------------------------------------------------------------------
[11:00:45.391] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:00:45.391] INFO: edge/corner pixel THR is adjusted
[11:00:45.391] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:00:46.350] INFO: Collecting data for 5 seconds...
[11:00:51.367] INFO: Done with hot pixel readout
[11:01:03.448] INFO: PixTest:: pg_setup set to default.
[11:01:03.449] INFO: 17 hot pixels found in step 0
[11:01:04.444] INFO: Collecting data for 5 seconds...
[11:01:09.461] INFO: Done with hot pixel readout
[11:01:20.938] INFO: PixTest:: pg_setup set to default.
[11:01:20.939] INFO: 18 hot pixels found in step 1
[11:01:21.934] INFO: Collecting data for 5 seconds...
[11:01:26.950] INFO: Done with hot pixel readout
[11:01:38.912] INFO: PixTest:: pg_setup set to default.
[11:01:38.913] INFO: 17 hot pixels found in step 2
[11:01:39.909] INFO: Collecting data for 5 seconds...
[11:01:44.925] INFO: Done with hot pixel readout
[11:01:56.975] INFO: PixTest:: pg_setup set to default.
[11:01:56.976] INFO: 22 hot pixels found in step 3
[11:01:57.972] INFO: Collecting data for 5 seconds...
[11:02:02.988] INFO: Done with hot pixel readout
[11:02:15.085] INFO: PixTest:: pg_setup set to default.

[11:02:15.086] INFO: 24 hot pixels found in step 4
[11:02:16.080] INFO: Collecting data for 5 seconds...
[11:02:21.096] INFO: Done with hot pixel readout
[11:02:33.184] INFO: PixTest:: pg_setup set to default.
[11:02:33.185] INFO: 16 hot pixels found in step 5
[11:02:34.180] INFO: Collecting data for 5 seconds...
[11:02:39.196] INFO: Done with hot pixel readout
[11:02:51.273] INFO: PixTest:: pg_setup set to default.


[11:02:51.274] INFO: 17 hot pixels found in step 6
[11:02:52.269] INFO: Collecting data for 5 seconds...
[11:02:57.285] INFO: Done with hot pixel readout
[11:03:09.386] INFO: PixTest:: pg_setup set to default.




[11:03:09.387] INFO: 16 hot pixels found in step 7
[11:03:10.382] INFO: Collecting data for 5 seconds...
[11:03:15.398] INFO: Done with hot pixel readout
[11:03:27.471] INFO: PixTest:: pg_setup set to default.





[11:03:27.471] INFO: 17 hot pixels found in step 8
[11:03:28.466] INFO: Collecting data for 5 seconds...
[11:03:33.482] INFO: Done with hot pixel readout
[11:03:45.553] INFO: PixTest:: pg_setup set to default.




[11:03:45.554] INFO: 5 hot pixels found in step 9
[11:03:46.549] INFO: Collecting data for 5 seconds...
[11:03:51.565] INFO: Done with hot pixel readout
[11:04:03.627] INFO: PixTest:: pg_setup set to default.





[11:04:03.628] INFO: 9 hot pixels found in step 10
[11:04:04.623] INFO: Collecting data for 5 seconds...
[11:04:09.639] INFO: Done with hot pixel readout
[11:04:21.708] INFO: PixTest:: pg_setup set to default.




[11:04:21.709] INFO: 13 hot pixels found in step 11
[11:04:22.704] INFO: Collecting data for 5 seconds...
[11:04:27.720] INFO: Done with hot pixel readout
[11:04:39.850] INFO: PixTest:: pg_setup set to default.




[11:04:39.851] INFO: 8 hot pixels found in step 12
[11:04:40.845] INFO: Collecting data for 5 seconds...
[11:04:45.861] INFO: Done with hot pixel readout
[11:04:57.938] INFO: PixTest:: pg_setup set to default.




[11:04:57.939] INFO: 13 hot pixels found in step 13
[11:04:58.934] INFO: Collecting data for 5 seconds...
[11:05:03.950] INFO: Done with hot pixel readout
[11:05:15.986] INFO: PixTest:: pg_setup set to default.




[11:05:15.987] INFO: 11 hot pixels found in step 14
[11:05:16.026] INFO: 11 hot pixels could not be trimmed and have been masked.
[11:05:16.029] INFO: PixTest::trimHotPixels() done
[11:05:16.029] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C0.dat
[11:05:16.034] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C1.dat
[11:05:16.040] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C2.dat
[11:05:16.046] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C3.dat
[11:05:16.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C4.dat
[11:05:16.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C5.dat
[11:05:16.062] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C6.dat
[11:05:16.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C7.dat
[11:05:16.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C8.dat
[11:05:16.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C9.dat
[11:05:16.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C10.dat
[11:05:16.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C11.dat
[11:05:16.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C12.dat
[11:05:16.098] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C13.dat
[11:05:16.104] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C14.dat
[11:05:16.109] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C15.dat
[11:05:16.114] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//defaultMaskFile.dat
[11:05:16.124] INFO: enter test to run
[11:05:39.349] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:05:39.349] INFO: running: highrate
[11:05:39.354] INFO: ----------------------------------------------------------------------
[11:05:39.354] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:05:39.354] INFO: ----------------------------------------------------------------------
[11:05:39.354] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:05:39.354] INFO: edge/corner pixel THR is adjusted
[11:05:39.354] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:05:40.312] INFO: Collecting data for 1 seconds...
[11:05:41.315] INFO: Done with hot pixel readout
[11:05:45.518] INFO: PixTest:: pg_setup set to default.
[11:05:45.519] INFO: 0 hot pixels found in step 0
[11:05:45.524] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:05:45.606] INFO: PixTest::trimHotPixels() done
[11:05:45.607] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C0.dat
[11:05:45.618] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C1.dat
[11:05:45.623] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C2.dat
[11:05:45.629] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C3.dat
[11:05:45.634] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C4.dat
[11:05:45.639] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C5.dat
[11:05:45.644] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C6.dat
[11:05:45.650] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C7.dat
[11:05:45.655] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C8.dat
[11:05:45.660] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C9.dat
[11:05:45.665] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C10.dat
[11:05:45.671] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C11.dat
[11:05:45.676] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C12.dat
[11:05:45.681] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C13.dat
[11:05:45.686] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C14.dat
[11:05:45.691] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//trimParameters35_C15.dat
[11:05:45.697] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-35_FPIXTest-17C-FNAL-160419-1248_2016-04-19_12h48m_1461088125/000_FPIXTest_p17//defaultMaskFile.dat
[11:05:45.707] INFO: enter test to run
[11:07:24.388] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:07:24.388] INFO: running: xray
[11:07:24.389] INFO: ----------------------------------------------------------------------
[11:07:24.390] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:07:24.390] INFO: ----------------------------------------------------------------------
[11:07:25.353] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:07:36.457] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:08:03.093] INFO: Resuming triggers.
[11:08:14.195] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[11:08:43.624] INFO: Resuming triggers.
[11:08:54.727] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[11:09:24.065] INFO: Resuming triggers.
[11:09:35.168] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[11:10:04.523] INFO: Resuming triggers.
[11:10:15.626] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[11:10:44.988] INFO: Resuming triggers.
[11:10:56.090] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[11:11:25.543] INFO: Resuming triggers.
[11:11:36.643] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[11:12:06.146] INFO: Resuming triggers.
[11:12:17.249] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[11:12:46.707] INFO: Resuming triggers.
[11:12:57.811] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[11:13:27.219] INFO: Resuming triggers.
[11:13:27.605] INFO: data taking finished, elapsed time: 100 seconds.
[11:13:29.108] INFO: PixTest:: pg_setup set to default.
[11:13:29.111] INFO: PixTestXray::doPhRun() done
[11:13:29.257] INFO: enter test to run
[11:14:37.297] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:14:37.297] INFO: running: xray
[11:14:37.298] INFO: ----------------------------------------------------------------------
[11:14:37.298] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:14:37.298] INFO: ----------------------------------------------------------------------
[11:14:38.263] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:14:44.546] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[11:15:14.726] INFO: Resuming triggers.
[11:15:21.007] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[11:15:51.015] INFO: Resuming triggers.
[11:15:57.297] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[11:16:27.447] INFO: Resuming triggers.
[11:16:33.732] INFO: run duration 25 seconds, buffer almost full (81%), pausing triggers.
[11:17:03.769] INFO: Resuming triggers.
[11:17:10.054] INFO: run duration 31 seconds, buffer almost full (81%), pausing triggers.
[11:17:40.299] INFO: Resuming triggers.
[11:17:46.578] INFO: run duration 37 seconds, buffer almost full (81%), pausing triggers.
[11:18:15.181] INFO: Resuming triggers.
[11:18:21.460] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[11:18:51.417] INFO: Resuming triggers.
[11:18:57.696] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[11:19:27.778] INFO: Resuming triggers.
[11:19:34.061] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[11:20:04.052] INFO: Resuming triggers.
[11:20:10.332] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[11:20:40.376] INFO: Resuming triggers.
[11:20:46.653] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[11:21:16.699] INFO: Resuming triggers.
[11:21:22.979] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[11:21:53.009] INFO: Resuming triggers.
[11:21:59.287] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[11:22:29.372] INFO: Resuming triggers.
[11:22:35.657] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[11:23:05.747] INFO: Resuming triggers.
[11:23:12.032] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[11:23:42.167] INFO: Resuming triggers.
[11:23:48.259] INFO: data taking finished, elapsed time: 100 seconds.
[11:24:17.730] INFO: PixTest:: pg_setup set to default.
[11:24:17.733] INFO: PixTestXray::doPhRun() done
[11:24:17.882] INFO: enter test to run
[11:25:02.812] INFO: test: HighRate no parameter change
[11:25:02.812] INFO: running: highrate
[11:25:02.814] INFO: ----------------------------------------------------------------------
[11:25:02.814] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:25:02.814] INFO: ----------------------------------------------------------------------
[11:25:02.956] INFO: Expecting 768 events.
[11:25:04.090] INFO: 768 events read in total (418ms).
[11:25:04.091] INFO: Test took 1270ms.
[11:25:04.894] INFO: Expecting 41600 events.
[11:25:08.082] INFO: 41600 events read in total (2661ms).
[11:25:08.083] INFO: Test took 3984ms.
[11:25:08.119] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:08.844] INFO: Expecting 41600 events.
[11:25:12.067] INFO: 41600 events read in total (2696ms).
[11:25:12.068] INFO: Test took 3930ms.
[11:25:12.104] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:12.826] INFO: Expecting 41600 events.
[11:25:16.086] INFO: 41600 events read in total (2733ms).
[11:25:16.087] INFO: Test took 3964ms.
[11:25:16.124] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:16.844] INFO: Expecting 41600 events.
[11:25:20.116] INFO: 41600 events read in total (2745ms).
[11:25:20.117] INFO: Test took 3974ms.
[11:25:20.154] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:20.871] INFO: Expecting 41600 events.
[11:25:24.138] INFO: 41600 events read in total (2740ms).
[11:25:24.139] INFO: Test took 3966ms.
[11:25:24.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:24.896] INFO: Expecting 41600 events.
[11:25:28.171] INFO: 41600 events read in total (2748ms).
[11:25:28.172] INFO: Test took 3976ms.
[11:25:28.209] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:28.928] INFO: Expecting 41600 events.
[11:25:32.200] INFO: 41600 events read in total (2745ms).
[11:25:32.201] INFO: Test took 3972ms.
[11:25:32.237] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:32.953] INFO: Expecting 41600 events.
[11:25:36.234] INFO: 41600 events read in total (2754ms).
[11:25:36.235] INFO: Test took 3979ms.
[11:25:36.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:36.991] INFO: Expecting 41600 events.
[11:25:40.258] INFO: 41600 events read in total (2740ms).
[11:25:40.259] INFO: Test took 3968ms.
[11:25:40.296] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:41.015] INFO: Expecting 41600 events.
[11:25:44.277] INFO: 41600 events read in total (2735ms).
[11:25:44.278] INFO: Test took 3963ms.
[11:25:44.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:45.036] INFO: Expecting 41600 events.
[11:25:48.296] INFO: 41600 events read in total (2734ms).
[11:25:48.297] INFO: Test took 3964ms.
[11:25:48.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:49.055] INFO: Expecting 41600 events.
[11:25:52.312] INFO: 41600 events read in total (2730ms).
[11:25:52.313] INFO: Test took 3959ms.
[11:25:52.349] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:53.065] INFO: Expecting 41600 events.
[11:25:56.324] INFO: 41600 events read in total (2732ms).
[11:25:56.325] INFO: Test took 3958ms.
[11:25:56.361] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:25:57.083] INFO: Expecting 41600 events.
[11:26:00.343] INFO: 41600 events read in total (2733ms).
[11:26:00.344] INFO: Test took 3964ms.
[11:26:00.381] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:01.103] INFO: Expecting 41600 events.
[11:26:04.372] INFO: 41600 events read in total (2743ms).
[11:26:04.373] INFO: Test took 3973ms.
[11:26:04.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:05.127] INFO: Expecting 41600 events.
[11:26:08.404] INFO: 41600 events read in total (2751ms).
[11:26:08.405] INFO: Test took 3976ms.
[11:26:08.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:09.160] INFO: Expecting 41600 events.
[11:26:12.405] INFO: 41600 events read in total (2718ms).
[11:26:12.406] INFO: Test took 3944ms.
[11:26:12.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:13.164] INFO: Expecting 41600 events.
[11:26:16.411] INFO: 41600 events read in total (2720ms).
[11:26:16.412] INFO: Test took 3951ms.
[11:26:16.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:17.168] INFO: Expecting 41600 events.
[11:26:20.417] INFO: 41600 events read in total (2722ms).
[11:26:20.418] INFO: Test took 3950ms.
[11:26:20.455] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:21.175] INFO: Expecting 41600 events.
[11:26:24.254] INFO: 41600 events read in total (2553ms).
[11:26:24.255] INFO: Test took 3780ms.
[11:26:24.290] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:26:24.649] INFO: enter test to run
[11:27:47.268] INFO: test: HighRate no parameter change
[11:27:47.268] INFO: running: highrate
[11:27:47.269] INFO: ----------------------------------------------------------------------
[11:27:47.269] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:27:47.269] INFO: ----------------------------------------------------------------------
[11:27:47.885] INFO: Expecting 208000 events.
[11:27:58.390] INFO: 208000 events read in total (9978ms).
[11:27:58.394] INFO: Test took 11115ms.
[11:27:58.551] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:27:58.807] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:27:58.807] INFO: number of red-efficiency pixels: 96 74 99 131 186 176 132 133 136 136 124 128 124 56 22 27
[11:27:58.807] INFO: number of X-ray hits detected: 76588 50531 70944 110731 119599 121582 121165 95557 89874 108328 108019 93797 96779 54328 24047 25403
[11:27:58.807] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:27:58.807] INFO: number of Vcal hits detected: 207904 207924 207898 207864 207810 207821 207867 207863 207862 207859 207872 207866 207872 207941 207978 207973
[11:27:58.807] 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
[11:27:58.807] 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
[11:27:58.807] INFO: X-ray hit rate [MHz/cm2]: 22.4 14.8 20.8 32.5 35.1 35.6 35.5 28.0 26.3 31.8 31.7 27.5 28.4 15.9 7.0 7.4
[11:27:58.807] INFO: PixTestHighRate::doXPixelAlive() done
[11:27:58.857] INFO: PixTest:: pg_setup set to default.
[11:27:58.870] INFO: enter test to run
[11:28:37.955] INFO: test: HighRate no parameter change
[11:28:37.955] INFO: running: highrate
[11:28:37.956] INFO: ----------------------------------------------------------------------
[11:28:37.956] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:28:37.956] INFO: ----------------------------------------------------------------------
[11:28:38.575] INFO: Expecting 208000 events.
[11:28:52.626] INFO: 208000 events read in total (13524ms).
[11:28:52.632] INFO: Test took 14667ms.
[11:28:52.951] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:28:53.261] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:28:53.261] INFO: number of red-efficiency pixels: 350 201 357 392 715 637 446 472 378 398 456 374 422 214 70 63
[11:28:53.261] INFO: number of X-ray hits detected: 161117 107269 149981 234865 252887 257196 254507 203294 191434 229005 226854 199563 206565 114383 51138 54125
[11:28:53.261] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:28:53.261] INFO: number of Vcal hits detected: 207617 207787 207597 207590 207199 207271 207510 207470 207594 207572 207500 207598 207546 207771 207927 207937
[11:28:53.261] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.8 99.6 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[11:28:53.262] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.8 99.6 99.6 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[11:28:53.262] INFO: X-ray hit rate [MHz/cm2]: 47.2 31.4 44.0 68.8 74.1 75.4 74.6 59.6 56.1 67.1 66.5 58.5 60.5 33.5 15.0 15.9
[11:28:53.262] INFO: PixTestHighRate::doXPixelAlive() done
[11:28:53.307] INFO: PixTest:: pg_setup set to default.
[11:28:53.316] INFO: enter test to run
[11:29:23.874] INFO: test: HighRate no parameter change
[11:29:23.875] INFO: running: highrate
[11:29:23.876] INFO: ----------------------------------------------------------------------
[11:29:23.876] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:29:23.876] INFO: ----------------------------------------------------------------------
[11:29:24.491] INFO: Expecting 208000 events.
[11:29:40.639] INFO: 208000 events read in total (15621ms).
[11:29:40.647] INFO: Test took 16763ms.
[11:29:41.144] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:29:41.510] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:29:41.510] INFO: number of red-efficiency pixels: 684 404 755 927 1543 1495 1083 1032 855 925 1031 928 921 501 91 91
[11:29:41.510] INFO: number of X-ray hits detected: 241670 161006 226480 353017 381239 384765 383574 305441 285570 345559 341634 300511 310866 174021 77545 81399
[11:29:41.510] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:29:41.510] INFO: number of Vcal hits detected: 207122 207532 206944 206886 205824 205916 206641 206583 207006 206904 206737 206849 206899 207393 207907 207908
[11:29:41.510] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.5 99.5 99.1 99.1 99.4 99.4 99.6 99.5 99.4 99.5 99.5 99.7 100.0 100.0
[11:29:41.510] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.5 99.0 99.0 99.3 99.3 99.5 99.5 99.4 99.4 99.5 99.7 100.0 100.0
[11:29:41.510] INFO: X-ray hit rate [MHz/cm2]: 70.8 47.2 66.4 103.5 111.7 112.8 112.4 89.5 83.7 101.3 100.1 88.1 91.1 51.0 22.7 23.9
[11:29:41.510] INFO: PixTestHighRate::doXPixelAlive() done
[11:29:41.558] INFO: PixTest:: pg_setup set to default.
[11:29:41.576] INFO: enter test to run
[11:29:43.698] INFO: test: exit no parameter change
[11:29:44.057] QUIET: Connection to board 32 closed.
[11:29:44.058] INFO: pXar: this is the end, my friend