[15:07:44.899] INFO: *** Welcome to pxar ***
[15:07:44.900] INFO: *** Today: 2016/05/30
[15:07:44.919] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:07:44.919] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//dacParameters35_C15.dat
[15:07:44.952] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:07:44.952] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//defaultMaskFile.dat
[15:07:44.959] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C15.dat
[15:07:45.070] INFO: clk: 4
[15:07:45.070] INFO: ctr: 4
[15:07:45.070] INFO: sda: 19
[15:07:45.070] INFO: tin: 9
[15:07:45.070] INFO: level: 15
[15:07:45.070] INFO: triggerdelay: 0
[15:07:45.070] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:07:45.070] INFO: Log level: INFO
[15:07:45.088] QUIET: Connection to board DTB_WREKRL opened.
[15:07:45.091] 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:07:45.094] INFO: RPC call hashes of host and DTB match: 398089610
[15:07:46.625] INFO: DUT info:
[15:07:46.625] INFO: The DUT currently contains the following objects:
[15:07:46.625] INFO: 2 TBM Cores tbm08c (2 ON)
[15:07:46.625] INFO: TBM Core alpha (0): 7 registers set
[15:07:46.625] INFO: TBM Core beta (1): 7 registers set
[15:07:46.625] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:07:46.625] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:46.625] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:07:47.028] INFO: enter 'restricted' command line mode
[15:07:47.028] INFO: enter test to run
[15:07:50.514] INFO: test: PixelAlive no parameter change
[15:07:50.514] INFO: running: pixelalive
[15:07:50.523] INFO: ----------------------------------------------------------------------
[15:07:50.523] 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:07:50.523] INFO: ----------------------------------------------------------------------
[15:07:50.846] INFO: Expecting 41600 events.
[15:07:55.018] INFO: 41600 events read in total (3454ms).
[15:07:55.187] INFO: Test took 4662ms.
[15:07:55.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:55.465] INFO: PixTestAlive::aliveTest() done
[15:07:55.465] INFO: number of dead pixels (per ROC): 0 0 0 1 0 1 0 0 0 0 0 0 0 0 0 0
[15:07:55.497] INFO: enter test to run
[15:08:16.913] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:08:16.914] INFO: running: highrate
[15:08:16.914] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:08:17.206] INFO: ----------------------------------------------------------------------
[15:08:17.206] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:08:17.206] INFO: ----------------------------------------------------------------------
[15:08:17.206] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:08:17.206] INFO: edge/corner pixel THR is adjusted
[15:08:17.206] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:08:18.166] INFO: Collecting data for 5 seconds...
[15:08:23.182] INFO: Done with hot pixel readout
[15:08:34.800] INFO: PixTest:: pg_setup set to default.
[15:08:34.801] INFO: 11 hot pixels found in step 0
[15:08:35.791] INFO: Collecting data for 5 seconds...
[15:08:40.806] INFO: Done with hot pixel readout
[15:08:52.411] INFO: PixTest:: pg_setup set to default.
[15:08:52.412] INFO: 12 hot pixels found in step 1
[15:08:53.403] INFO: Collecting data for 5 seconds...
[15:08:58.419] INFO: Done with hot pixel readout
[15:09:10.039] INFO: PixTest:: pg_setup set to default.
[15:09:10.040] INFO: 11 hot pixels found in step 2
[15:09:11.031] INFO: Collecting data for 5 seconds...
[15:09:16.047] INFO: Done with hot pixel readout
[15:09:27.680] INFO: PixTest:: pg_setup set to default.
[15:09:27.680] INFO: 4 hot pixels found in step 3
[15:09:28.671] INFO: Collecting data for 5 seconds...
[15:09:33.687] INFO: Done with hot pixel readout
[15:09:45.321] INFO: PixTest:: pg_setup set to default.
[15:09:45.322] INFO: 6 hot pixels found in step 4
[15:09:46.313] INFO: Collecting data for 5 seconds...
[15:09:51.329] INFO: Done with hot pixel readout
[15:10:02.947] INFO: PixTest:: pg_setup set to default.
[15:10:02.947] INFO: 6 hot pixels found in step 5
[15:10:03.938] INFO: Collecting data for 5 seconds...
[15:10:08.954] INFO: Done with hot pixel readout
[15:10:20.600] INFO: PixTest:: pg_setup set to default.
[15:10:20.601] INFO: 7 hot pixels found in step 6
[15:10:21.591] INFO: Collecting data for 5 seconds...
[15:10:26.608] INFO: Done with hot pixel readout
[15:10:38.213] INFO: PixTest:: pg_setup set to default.
[15:10:38.214] INFO: 3 hot pixels found in step 7
[15:10:39.204] INFO: Collecting data for 5 seconds...
[15:10:44.220] INFO: Done with hot pixel readout
[15:10:55.837] INFO: PixTest:: pg_setup set to default.
[15:10:55.837] INFO: 3 hot pixels found in step 8
[15:10:56.828] INFO: Collecting data for 5 seconds...
[15:11:01.844] INFO: Done with hot pixel readout
[15:11:13.490] INFO: PixTest:: pg_setup set to default.
[15:11:13.490] INFO: 4 hot pixels found in step 9
[15:11:14.482] INFO: Collecting data for 5 seconds...
[15:11:19.498] INFO: Done with hot pixel readout
[15:11:31.146] INFO: PixTest:: pg_setup set to default.
[15:11:31.147] INFO: 2 hot pixels found in step 10
[15:11:32.137] INFO: Collecting data for 5 seconds...
[15:11:37.153] INFO: Done with hot pixel readout
[15:11:48.770] INFO: PixTest:: pg_setup set to default.
[15:11:48.770] INFO: 0 hot pixels found in step 11
[15:11:48.805] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:11:48.808] INFO: PixTest::trimHotPixels() done
[15:11:48.808] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C0.dat
[15:11:48.814] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C1.dat
[15:11:48.820] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C2.dat
[15:11:48.826] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C3.dat
[15:11:48.831] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C4.dat
[15:11:48.836] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C5.dat
[15:11:48.842] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C6.dat
[15:11:48.847] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C7.dat
[15:11:48.852] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C8.dat
[15:11:48.857] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C9.dat
[15:11:48.863] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C10.dat
[15:11:48.868] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C11.dat
[15:11:48.873] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C12.dat
[15:11:48.878] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C13.dat
[15:11:48.883] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C14.dat
[15:11:48.889] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C15.dat
[15:11:48.894] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//defaultMaskFile.dat
[15:11:48.904] INFO: enter test to run
[15:12:22.776] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:12:22.776] INFO: running: highrate
[15:12:22.780] INFO: ----------------------------------------------------------------------
[15:12:22.780] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:12:22.780] INFO: ----------------------------------------------------------------------
[15:12:22.780] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:12:22.780] INFO: edge/corner pixel THR is adjusted
[15:12:22.780] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:12:23.738] INFO: Collecting data for 1 seconds...
[15:12:24.741] INFO: Done with hot pixel readout
[15:12:28.739] INFO: PixTest:: pg_setup set to default.
[15:12:28.740] INFO: 0 hot pixels found in step 0
[15:12:28.745] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:12:28.837] INFO: PixTest::trimHotPixels() done
[15:12:28.837] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C0.dat
[15:12:28.847] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C1.dat
[15:12:28.852] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C2.dat
[15:12:28.857] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C3.dat
[15:12:28.863] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C4.dat
[15:12:28.868] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C5.dat
[15:12:28.873] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C6.dat
[15:12:28.878] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C7.dat
[15:12:28.883] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C8.dat
[15:12:28.889] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C9.dat
[15:12:28.894] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C10.dat
[15:12:28.899] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C11.dat
[15:12:28.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C12.dat
[15:12:28.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C13.dat
[15:12:28.914] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C14.dat
[15:12:28.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//trimParameters35_C15.dat
[15:12:28.925] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-O-1-16_FPIXTest-17C-FNAL-160524-1120_2016-05-24_11h20m_1464106816/000_FPIXTest_p17//defaultMaskFile.dat
[15:12:28.936] INFO: enter test to run
[15:13:13.391] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:13:13.391] INFO: running: xray
[15:13:13.392] INFO: ----------------------------------------------------------------------
[15:13:13.392] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:13:13.392] INFO: ----------------------------------------------------------------------
[15:13:14.356] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:13:25.603] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:13:55.042] INFO: Resuming triggers.
[15:14:06.295] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:14:35.752] INFO: Resuming triggers.
[15:14:46.002] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:15:16.515] INFO: Resuming triggers.
[15:15:27.763] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[15:15:57.195] INFO: Resuming triggers.
[15:16:08.447] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:16:37.829] INFO: Resuming triggers.
[15:16:49.081] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:17:18.559] INFO: Resuming triggers.
[15:17:29.809] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[15:17:59.227] INFO: Resuming triggers.
[15:18:10.481] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[15:18:39.785] INFO: Resuming triggers.
[15:18:50.097] INFO: data taking finished, elapsed time: 100 seconds.
[15:19:17.046] INFO: PixTest:: pg_setup set to default.
[15:19:17.049] INFO: PixTestXray::doPhRun() done
[15:19:17.228] INFO: enter test to run
[15:20:13.188] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:20:13.188] INFO: running: xray
[15:20:13.189] INFO: ----------------------------------------------------------------------
[15:20:13.189] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:20:13.189] INFO: ----------------------------------------------------------------------
[15:20:14.161] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:20:20.893] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:20:50.897] INFO: Resuming triggers.
[15:20:57.628] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:21:27.530] INFO: Resuming triggers.
[15:21:34.257] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:22:04.253] INFO: Resuming triggers.
[15:22:10.982] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:22:40.924] INFO: Resuming triggers.
[15:22:47.654] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:23:17.565] INFO: Resuming triggers.
[15:23:24.292] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[15:23:54.238] INFO: Resuming triggers.
[15:24:00.966] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:24:30.935] INFO: Resuming triggers.
[15:24:37.663] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:25:07.468] INFO: Resuming triggers.
[15:25:14.197] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[15:25:44.147] INFO: Resuming triggers.
[15:25:50.875] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:26:20.861] INFO: Resuming triggers.
[15:26:27.592] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[15:26:57.558] INFO: Resuming triggers.
[15:27:04.290] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[15:27:34.280] INFO: Resuming triggers.
[15:27:41.010] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[15:28:11.046] INFO: Resuming triggers.
[15:28:17.775] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:28:47.716] INFO: Resuming triggers.
[15:28:53.820] INFO: data taking finished, elapsed time: 100 seconds.
[15:29:21.280] INFO: PixTest:: pg_setup set to default.
[15:29:21.283] INFO: PixTestXray::doPhRun() done
[15:29:21.431] INFO: enter test to run
[15:30:39.135] INFO: test: HighRate no parameter change
[15:30:39.135] INFO: running: highrate
[15:30:39.136] INFO: ----------------------------------------------------------------------
[15:30:39.136] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:30:39.136] INFO: ----------------------------------------------------------------------
[15:30:39.277] INFO: Expecting 768 events.
[15:30:40.411] INFO: 768 events read in total (418ms).
[15:30:40.412] INFO: Test took 1269ms.
[15:30:41.215] INFO: Expecting 41600 events.
[15:30:44.319] INFO: 41600 events read in total (2577ms).
[15:30:44.320] INFO: Test took 3900ms.
[15:30:44.352] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:45.082] INFO: Expecting 41600 events.
[15:30:48.255] INFO: 41600 events read in total (2646ms).
[15:30:48.256] INFO: Test took 3885ms.
[15:30:48.289] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:49.014] INFO: Expecting 41600 events.
[15:30:52.233] INFO: 41600 events read in total (2692ms).
[15:30:52.234] INFO: Test took 3927ms.
[15:30:52.268] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:52.996] INFO: Expecting 41600 events.
[15:30:56.224] INFO: 41600 events read in total (2701ms).
[15:30:56.225] INFO: Test took 3939ms.
[15:30:56.258] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:56.981] INFO: Expecting 41600 events.
[15:31:00.200] INFO: 41600 events read in total (2692ms).
[15:31:00.201] INFO: Test took 3925ms.
[15:31:00.234] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:00.961] INFO: Expecting 41600 events.
[15:31:04.204] INFO: 41600 events read in total (2716ms).
[15:31:04.205] INFO: Test took 3954ms.
[15:31:04.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:04.962] INFO: Expecting 41600 events.
[15:31:08.191] INFO: 41600 events read in total (2702ms).
[15:31:08.192] INFO: Test took 3936ms.
[15:31:08.225] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:08.950] INFO: Expecting 41600 events.
[15:31:12.177] INFO: 41600 events read in total (2701ms).
[15:31:12.178] INFO: Test took 3935ms.
[15:31:12.211] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:12.939] INFO: Expecting 41600 events.
[15:31:16.161] INFO: 41600 events read in total (2695ms).
[15:31:16.162] INFO: Test took 3934ms.
[15:31:16.195] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:16.924] INFO: Expecting 41600 events.
[15:31:20.156] INFO: 41600 events read in total (2705ms).
[15:31:20.157] INFO: Test took 3944ms.
[15:31:20.190] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:20.916] INFO: Expecting 41600 events.
[15:31:24.148] INFO: 41600 events read in total (2705ms).
[15:31:24.149] INFO: Test took 3941ms.
[15:31:24.182] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:24.905] INFO: Expecting 41600 events.
[15:31:28.133] INFO: 41600 events read in total (2701ms).
[15:31:28.134] INFO: Test took 3933ms.
[15:31:28.167] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:28.891] INFO: Expecting 41600 events.
[15:31:32.132] INFO: 41600 events read in total (2714ms).
[15:31:32.133] INFO: Test took 3948ms.
[15:31:32.165] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:32.894] INFO: Expecting 41600 events.
[15:31:36.126] INFO: 41600 events read in total (2706ms).
[15:31:36.127] INFO: Test took 3945ms.
[15:31:36.160] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:36.885] INFO: Expecting 41600 events.
[15:31:40.121] INFO: 41600 events read in total (2709ms).
[15:31:40.122] INFO: Test took 3944ms.
[15:31:40.156] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:40.879] INFO: Expecting 41600 events.
[15:31:44.121] INFO: 41600 events read in total (2715ms).
[15:31:44.122] INFO: Test took 3948ms.
[15:31:44.155] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:44.884] INFO: Expecting 41600 events.
[15:31:48.117] INFO: 41600 events read in total (2706ms).
[15:31:48.118] INFO: Test took 3944ms.
[15:31:48.151] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:48.877] INFO: Expecting 41600 events.
[15:31:52.101] INFO: 41600 events read in total (2697ms).
[15:31:52.102] INFO: Test took 3934ms.
[15:31:52.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:52.864] INFO: Expecting 41600 events.
[15:31:56.081] INFO: 41600 events read in total (2691ms).
[15:31:56.082] INFO: Test took 3929ms.
[15:31:56.115] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:31:56.840] INFO: Expecting 41600 events.
[15:31:59.921] INFO: 41600 events read in total (2554ms).
[15:31:59.922] INFO: Test took 3788ms.
[15:31:59.954] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:00.319] INFO: enter test to run
[15:32:11.471] INFO: test: HighRate no parameter change
[15:32:11.471] INFO: running: highrate
[15:32:11.472] INFO: ----------------------------------------------------------------------
[15:32:11.472] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:32:11.472] INFO: ----------------------------------------------------------------------
[15:32:12.089] INFO: Expecting 208000 events.
[15:32:23.905] INFO: 208000 events read in total (11289ms).
[15:32:23.908] INFO: Test took 12427ms.
[15:32:24.050] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:24.300] INFO: number of dead pixels (per ROC): 0 0 0 1 0 1 0 0 0 0 0 0 0 0 0 0
[15:32:24.300] INFO: number of red-efficiency pixels: 67 33 77 118 141 138 140 95 77 107 111 90 72 61 25 24
[15:32:24.300] INFO: number of X-ray hits detected: 59469 39342 63641 105402 111296 121209 113945 85415 74182 91330 93384 78362 80428 47538 21999 23982
[15:32:24.300] 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:32:24.300] INFO: number of Vcal hits detected: 207933 207967 207923 207831 207857 207808 207843 207902 207922 207891 207887 207907 207927 207939 207975 207975
[15:32:24.300] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[15:32:24.300] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[15:32:24.300] INFO: X-ray hit rate [MHz/cm2]: 17.4 11.5 18.7 30.9 32.6 35.5 33.4 25.0 21.7 26.8 27.4 23.0 23.6 13.9 6.4 7.0
[15:32:24.300] INFO: PixTestHighRate::doXPixelAlive() done
[15:32:24.349] INFO: PixTest:: pg_setup set to default.
[15:32:24.361] INFO: enter test to run
[15:32:38.079] INFO: test: HighRate no parameter change
[15:32:38.079] INFO: running: highrate
[15:32:38.080] INFO: ----------------------------------------------------------------------
[15:32:38.080] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:32:38.080] INFO: ----------------------------------------------------------------------
[15:32:38.699] INFO: Expecting 208000 events.
[15:32:52.301] INFO: 208000 events read in total (13076ms).
[15:32:52.306] INFO: Test took 14218ms.
[15:32:52.598] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:32:52.898] INFO: number of dead pixels (per ROC): 0 0 0 1 0 1 0 0 0 0 0 0 0 0 0 0
[15:32:52.898] INFO: number of red-efficiency pixels: 202 131 267 391 493 478 439 366 245 400 412 253 235 152 58 41
[15:32:52.898] INFO: number of X-ray hits detected: 125626 83963 135347 222781 234870 256325 241162 180866 157409 192609 197135 166103 170599 101415 47054 51018
[15:32:52.898] 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:32:52.898] INFO: number of Vcal hits detected: 207780 207863 207713 207522 207460 207439 207511 207606 207748 207572 207555 207732 207760 207842 207941 207956
[15:32:52.898] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:32:52.898] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:32:52.898] INFO: X-ray hit rate [MHz/cm2]: 36.8 24.6 39.7 65.3 68.8 75.1 70.7 53.0 46.1 56.5 57.8 48.7 50.0 29.7 13.8 15.0
[15:32:52.898] INFO: PixTestHighRate::doXPixelAlive() done
[15:32:52.947] INFO: PixTest:: pg_setup set to default.
[15:32:52.965] INFO: enter test to run
[15:33:16.326] INFO: test: HighRate no parameter change
[15:33:16.326] INFO: running: highrate
[15:33:16.327] INFO: ----------------------------------------------------------------------
[15:33:16.327] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:33:16.327] INFO: ----------------------------------------------------------------------
[15:33:16.943] INFO: Expecting 208000 events.
[15:33:32.387] INFO: 208000 events read in total (14917ms).
[15:33:32.394] INFO: Test took 16057ms.
[15:33:32.823] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:33:33.166] INFO: number of dead pixels (per ROC): 0 0 0 1 0 1 0 0 0 0 0 0 0 0 0 0
[15:33:33.166] INFO: number of red-efficiency pixels: 430 232 590 835 1174 1107 1050 848 531 819 959 538 441 283 107 95
[15:33:33.166] INFO: number of X-ray hits detected: 188782 125558 204820 335867 354353 384419 364028 273286 237540 290840 297374 249754 257078 153523 71716 77245
[15:33:33.166] 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:33:33.166] INFO: number of Vcal hits detected: 207508 207753 207232 206982 206508 206563 206649 206954 207409 207014 206856 207404 207515 207692 207890 207903
[15:33:33.166] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.3 99.4 99.4 99.5 99.7 99.6 99.5 99.7 99.8 99.9 99.9 100.0
[15:33:33.166] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.6 99.5 99.3 99.3 99.4 99.5 99.7 99.5 99.5 99.7 99.8 99.9 99.9 100.0
[15:33:33.166] INFO: X-ray hit rate [MHz/cm2]: 55.3 36.8 60.0 98.4 103.9 112.7 106.7 80.1 69.6 85.2 87.2 73.2 75.4 45.0 21.0 22.6
[15:33:33.166] INFO: PixTestHighRate::doXPixelAlive() done
[15:33:33.212] INFO: PixTest:: pg_setup set to default.
[15:33:33.228] INFO: enter test to run
[15:33:37.774] INFO: test: exit no parameter change
[15:33:38.123] QUIET: Connection to board 33 closed.
[15:33:38.124] INFO: pXar: this is the end, my friend