[13:47:01.179] INFO: *** Welcome to pxar ***
[13:47:01.179] INFO: *** Today: 2016/09/08
[13:47:02.013] INFO: *** Version: v1.9.0-818-g96727
[13:47:02.013] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//dacParameters35_C15.dat
[13:47:02.026] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:47:02.026] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//defaultMaskFile.dat
[13:47:02.035] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C15.dat
[13:47:02.124] INFO: clk: 4
[13:47:02.124] INFO: ctr: 4
[13:47:02.124] INFO: sda: 19
[13:47:02.124] INFO: tin: 9
[13:47:02.124] INFO: level: 15
[13:47:02.124] INFO: triggerdelay: 0
[13:47:02.124] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:47:02.124] INFO: Log level: INFO
[13:47:02.143] QUIET: Connection to board DTB_WREKRL opened.
[13:47:02.146] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[13:47:02.149] INFO: RPC call hashes of host and DTB match: 398089610
[13:47:03.674] INFO: DUT info:
[13:47:03.674] INFO: The DUT currently contains the following objects:
[13:47:03.674] INFO: 2 TBM Cores tbm08c (2 ON)
[13:47:03.674] INFO: TBM Core alpha (0): 7 registers set
[13:47:03.674] INFO: TBM Core beta (1): 7 registers set
[13:47:03.674] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:47:03.674] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.674] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.675] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.675] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.675] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.675] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:03.675] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:04.085] INFO: enter 'restricted' command line mode
[13:47:04.085] INFO: enter test to run
[13:47:27.835] INFO: test: PixelAlive no parameter change
[13:47:27.835] INFO: running: pixelalive
[13:47:27.856] INFO: ----------------------------------------------------------------------
[13:47:27.856] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:47:27.856] INFO: ----------------------------------------------------------------------
[13:47:28.173] INFO: Expecting 41600 events.
[13:47:32.502] INFO: 41600 events read in total (3610ms).
[13:47:32.671] INFO: Test took 4811ms.
[13:47:32.681] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:47:32.946] INFO: PixTestAlive::aliveTest() done
[13:47:32.946] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0
[13:47:32.975] INFO: enter test to run
[13:48:52.211] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:48:52.211] INFO: running: highrate
[13:48:52.211] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:48:52.463] INFO: ----------------------------------------------------------------------
[13:48:52.463] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:48:52.463] INFO: ----------------------------------------------------------------------
[13:48:52.464] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:48:52.464] INFO: edge/corner pixel THR is adjusted
[13:48:52.464] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:48:53.423] INFO: Collecting data for 5 seconds...
[13:48:58.439] INFO: Done with hot pixel readout
[13:49:09.848] INFO: PixTest:: pg_setup set to default.
[13:49:09.849] INFO: 15 hot pixels found in step 0
[13:49:10.856] INFO: Collecting data for 5 seconds...
[13:49:15.873] INFO: Done with hot pixel readout
[13:49:27.328] INFO: PixTest:: pg_setup set to default.
[13:49:27.329] INFO: 14 hot pixels found in step 1
[13:49:28.315] INFO: Collecting data for 5 seconds...
[13:49:33.333] INFO: Done with hot pixel readout
[13:49:44.695] INFO: PixTest:: pg_setup set to default.
[13:49:44.695] INFO: 13 hot pixels found in step 2
[13:49:45.682] INFO: Collecting data for 5 seconds...
[13:49:50.702] INFO: Done with hot pixel readout
[13:50:01.778] INFO: PixTest:: pg_setup set to default.
[13:50:01.779] INFO: 13 hot pixels found in step 3
[13:50:02.766] INFO: Collecting data for 5 seconds...
[13:50:07.783] INFO: Done with hot pixel readout
[13:50:18.774] INFO: PixTest:: pg_setup set to default.
[13:50:18.775] INFO: 13 hot pixels found in step 4
[13:50:19.761] INFO: Collecting data for 5 seconds...
[13:50:24.780] INFO: Done with hot pixel readout
[13:50:36.127] INFO: PixTest:: pg_setup set to default.
[13:50:36.128] INFO: 9 hot pixels found in step 5
[13:50:37.114] INFO: Collecting data for 5 seconds...
[13:50:42.134] INFO: Done with hot pixel readout
[13:50:53.596] INFO: PixTest:: pg_setup set to default.
[13:50:53.597] INFO: 4 hot pixels found in step 6
[13:50:54.583] INFO: Collecting data for 5 seconds...
[13:50:59.602] INFO: Done with hot pixel readout
[13:51:10.946] INFO: PixTest:: pg_setup set to default.
[13:51:10.946] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:51:10.947] INFO: 5 hot pixels found in step 7
[13:51:11.934] INFO: Collecting data for 5 seconds...
[13:51:16.952] INFO: Done with hot pixel readout
[13:51:28.504] INFO: PixTest:: pg_setup set to default.
[13:51:28.505] INFO: 2 hot pixels found in step 8
[13:51:29.491] INFO: Collecting data for 5 seconds...
[13:51:34.509] INFO: Done with hot pixel readout
[13:51:45.723] INFO: PixTest:: pg_setup set to default.
[13:51:45.723] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:51:45.724] INFO: 2 hot pixels found in step 9
[13:51:46.710] INFO: Collecting data for 5 seconds...
[13:51:51.730] INFO: Done with hot pixel readout
[13:52:03.228] INFO: PixTest:: pg_setup set to default.
[13:52:03.229] INFO: 2 hot pixels found in step 10
[13:52:04.214] INFO: Collecting data for 5 seconds...
[13:52:09.233] INFO: Done with hot pixel readout
[13:52:20.602] INFO: PixTest:: pg_setup set to default.
[13:52:20.603] INFO: 1 hot pixels found in step 11
[13:52:21.589] INFO: Collecting data for 5 seconds...
[13:52:26.611] INFO: Done with hot pixel readout
[13:52:38.056] INFO: PixTest:: pg_setup set to default.
[13:52:38.056] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:52:38.057] INFO: 3 hot pixels found in step 12
[13:52:39.043] INFO: Collecting data for 5 seconds...
[13:52:44.063] INFO: Done with hot pixel readout
[13:52:55.574] INFO: PixTest:: pg_setup set to default.
[13:52:55.574] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:52:55.575] INFO: 2 hot pixels found in step 13
[13:52:56.561] INFO: Collecting data for 5 seconds...
[13:53:01.579] INFO: Done with hot pixel readout
[13:53:13.056] INFO: PixTest:: pg_setup set to default.
[13:53:13.057] INFO: 3 hot pixels found in step 14
[13:53:13.087] INFO: 3 hot pixels could not be trimmed and have been masked.
[13:53:13.090] INFO: PixTest::trimHotPixels() done
[13:53:13.093] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C0.dat
[13:53:13.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C1.dat
[13:53:13.105] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C2.dat
[13:53:13.110] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C3.dat
[13:53:13.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C4.dat
[13:53:13.121] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C5.dat
[13:53:13.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C6.dat
[13:53:13.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C7.dat
[13:53:13.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C8.dat
[13:53:13.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C9.dat
[13:53:13.147] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C10.dat
[13:53:13.152] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C11.dat
[13:53:13.157] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C12.dat
[13:53:13.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C13.dat
[13:53:13.167] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C14.dat
[13:53:13.173] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C15.dat
[13:53:13.178] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//defaultMaskFile.dat
[13:53:13.187] INFO: enter test to run
[13:53:37.833] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:53:37.833] INFO: running: highrate
[13:53:37.837] INFO: ----------------------------------------------------------------------
[13:53:37.837] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:53:37.837] INFO: ----------------------------------------------------------------------
[13:53:37.837] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:53:37.838] INFO: edge/corner pixel THR is adjusted
[13:53:37.838] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:53:38.799] INFO: Collecting data for 1 seconds...
[13:53:39.803] INFO: Done with hot pixel readout
[13:53:43.912] INFO: PixTest:: pg_setup set to default.
[13:53:43.913] INFO: 0 hot pixels found in step 0
[13:53:43.918] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:53:44.006] INFO: PixTest::trimHotPixels() done
[13:53:44.007] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C0.dat
[13:53:44.018] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C1.dat
[13:53:44.028] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C2.dat
[13:53:44.034] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C3.dat
[13:53:44.040] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C4.dat
[13:53:44.045] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C5.dat
[13:53:44.051] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C6.dat
[13:53:44.056] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C7.dat
[13:53:44.061] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C8.dat
[13:53:44.067] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C9.dat
[13:53:44.072] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C10.dat
[13:53:44.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C11.dat
[13:53:44.083] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C12.dat
[13:53:44.088] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C13.dat
[13:53:44.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C14.dat
[13:53:44.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//trimParameters35_C15.dat
[13:53:44.104] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-27_FPIXTest-17C-FNAL-160906-1541-300V_2016-09-06_15h41m_1473194476/000_FPIXTest_p17//defaultMaskFile.dat
[13:53:44.114] INFO: enter test to run
[13:54:04.625] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:54:04.625] INFO: running: xray
[13:54:04.626] INFO: ----------------------------------------------------------------------
[13:54:04.626] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:54:04.626] INFO: ----------------------------------------------------------------------
[13:54:05.588] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:54:17.613] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:54:47.066] INFO: Resuming triggers.
[13:54:59.117] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:55:28.463] INFO: Resuming triggers.
[13:55:40.526] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[13:56:09.759] INFO: Resuming triggers.
[13:56:21.820] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[13:56:51.050] INFO: Resuming triggers.
[13:57:03.119] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[13:57:32.330] INFO: Resuming triggers.
[13:57:44.406] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[13:58:13.633] INFO: Resuming triggers.
[13:58:25.727] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[13:58:54.967] INFO: Resuming triggers.
[13:59:07.069] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[13:59:36.224] INFO: Resuming triggers.
[13:59:40.026] INFO: data taking finished, elapsed time: 100 seconds.
[13:59:49.582] INFO: PixTest:: pg_setup set to default.
[13:59:49.586] INFO: PixTestXray::doPhRun() done
[13:59:49.720] INFO: enter test to run
[14:00:17.078] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:00:17.078] INFO: running: xray
[14:00:17.079] INFO: ----------------------------------------------------------------------
[14:00:17.079] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:00:17.079] INFO: ----------------------------------------------------------------------
[14:00:18.050] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:00:25.297] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[14:00:55.538] INFO: Resuming triggers.
[14:01:02.795] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[14:01:33.075] INFO: Resuming triggers.
[14:01:40.337] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[14:02:10.600] INFO: Resuming triggers.
[14:02:17.868] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[14:02:48.715] INFO: Resuming triggers.
[14:02:55.989] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[14:03:26.983] INFO: Resuming triggers.
[14:03:34.254] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[14:04:04.839] INFO: Resuming triggers.
[14:04:12.107] INFO: run duration 50 seconds, buffer almost full (81%), pausing triggers.
[14:04:42.005] INFO: Resuming triggers.
[14:04:50.272] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:05:21.461] INFO: Resuming triggers.
[14:05:28.730] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:06:00.276] INFO: Resuming triggers.
[14:06:07.547] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:06:38.214] INFO: Resuming triggers.
[14:06:45.487] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:07:15.692] INFO: Resuming triggers.
[14:07:22.967] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:07:53.134] INFO: Resuming triggers.
[14:08:00.409] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[14:08:30.598] INFO: Resuming triggers.
[14:08:36.479] INFO: data taking finished, elapsed time: 100 seconds.
[14:09:01.167] INFO: PixTest:: pg_setup set to default.
[14:09:01.171] INFO: PixTestXray::doPhRun() done
[14:09:01.321] INFO: enter test to run
[14:09:44.730] INFO: test: HighRate no parameter change
[14:09:44.730] INFO: running: highrate
[14:09:44.746] INFO: ----------------------------------------------------------------------
[14:09:44.746] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:09:44.746] INFO: ----------------------------------------------------------------------
[14:09:44.901] INFO: Expecting 768 events.
[14:09:46.041] INFO: 768 events read in total (418ms).
[14:09:46.042] INFO: Test took 1275ms.
[14:09:46.844] INFO: Expecting 41600 events.
[14:09:49.840] INFO: 41600 events read in total (2469ms).
[14:09:49.842] INFO: Test took 3780ms.
[14:09:49.875] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:50.605] INFO: Expecting 41600 events.
[14:09:53.742] INFO: 41600 events read in total (2610ms).
[14:09:53.744] INFO: Test took 3852ms.
[14:09:53.783] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:54.504] INFO: Expecting 41600 events.
[14:09:57.669] INFO: 41600 events read in total (2638ms).
[14:09:57.670] INFO: Test took 3869ms.
[14:09:57.699] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:09:58.432] INFO: Expecting 41600 events.
[14:10:01.567] INFO: 41600 events read in total (2608ms).
[14:10:01.568] INFO: Test took 3853ms.
[14:10:01.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:02.328] INFO: Expecting 41600 events.
[14:10:05.517] INFO: 41600 events read in total (2662ms).
[14:10:05.518] INFO: Test took 3903ms.
[14:10:05.548] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:06.280] INFO: Expecting 41600 events.
[14:10:09.475] INFO: 41600 events read in total (2668ms).
[14:10:09.476] INFO: Test took 3911ms.
[14:10:09.506] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:10.236] INFO: Expecting 41600 events.
[14:10:13.410] INFO: 41600 events read in total (2647ms).
[14:10:13.411] INFO: Test took 3887ms.
[14:10:13.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:14.169] INFO: Expecting 41600 events.
[14:10:17.364] INFO: 41600 events read in total (2668ms).
[14:10:17.365] INFO: Test took 3909ms.
[14:10:17.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:18.128] INFO: Expecting 41600 events.
[14:10:21.324] INFO: 41600 events read in total (2669ms).
[14:10:21.325] INFO: Test took 3911ms.
[14:10:21.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:22.088] INFO: Expecting 41600 events.
[14:10:25.284] INFO: 41600 events read in total (2669ms).
[14:10:25.285] INFO: Test took 3912ms.
[14:10:25.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:26.048] INFO: Expecting 41600 events.
[14:10:29.228] INFO: 41600 events read in total (2653ms).
[14:10:29.229] INFO: Test took 3897ms.
[14:10:29.259] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:29.990] INFO: Expecting 41600 events.
[14:10:33.200] INFO: 41600 events read in total (2683ms).
[14:10:33.201] INFO: Test took 3924ms.
[14:10:33.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:33.961] INFO: Expecting 41600 events.
[14:10:37.137] INFO: 41600 events read in total (2649ms).
[14:10:37.138] INFO: Test took 3891ms.
[14:10:37.168] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:37.900] INFO: Expecting 41600 events.
[14:10:41.088] INFO: 41600 events read in total (2661ms).
[14:10:41.089] INFO: Test took 3903ms.
[14:10:41.120] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:41.853] INFO: Expecting 41600 events.
[14:10:45.048] INFO: 41600 events read in total (2668ms).
[14:10:45.049] INFO: Test took 3912ms.
[14:10:45.079] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:45.813] INFO: Expecting 41600 events.
[14:10:48.005] INFO: 41600 events read in total (2665ms).
[14:10:48.005] INFO: Test took 3909ms.
[14:10:49.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:49.767] INFO: Expecting 41600 events.
[14:10:52.963] INFO: 41600 events read in total (2669ms).
[14:10:52.964] INFO: Test took 3912ms.
[14:10:52.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:53.723] INFO: Expecting 41600 events.
[14:10:56.926] INFO: 41600 events read in total (2676ms).
[14:10:56.927] INFO: Test took 3917ms.
[14:10:56.957] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:10:57.690] INFO: Expecting 41600 events.
[14:11:00.884] INFO: 41600 events read in total (2667ms).
[14:11:00.885] INFO: Test took 3911ms.
[14:11:00.915] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:01.645] INFO: Expecting 41600 events.
[14:11:04.710] INFO: 41600 events read in total (2538ms).
[14:11:04.712] INFO: Test took 3779ms.
[14:11:04.741] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:05.110] INFO: enter test to run
[14:11:15.705] INFO: test: HighRate no parameter change
[14:11:15.706] INFO: running: highrate
[14:11:15.707] INFO: ----------------------------------------------------------------------
[14:11:15.707] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:11:15.707] INFO: ----------------------------------------------------------------------
[14:11:16.317] INFO: Expecting 208000 events.
[14:11:27.959] INFO: 208000 events read in total (11115ms).
[14:11:27.962] INFO: Test took 12249ms.
[14:11:28.088] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:28.333] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 2 0 0 1 0 0 0 0
[14:11:28.333] INFO: number of red-efficiency pixels: 85 53 68 102 113 121 86 83 81 87 85 80 99 45 22 25
[14:11:28.333] INFO: number of X-ray hits detected: 60581 37480 58974 92622 95246 98515 91097 68449 62328 79180 82112 71090 73605 44983 18132 21891
[14:11:28.333] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:11:28.333] INFO: number of Vcal hits detected: 207913 207946 207932 207897 207883 207877 207911 207866 207801 207908 207910 207869 207901 207955 207977 207975
[14:11:28.333] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[14:11:28.333] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 100.0 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0
[14:11:28.333] INFO: X-ray hit rate [MHz/cm2]: 17.8 11.0 17.3 27.1 27.9 28.9 26.7 20.1 18.3 23.2 24.1 20.8 21.6 13.2 5.3 6.4
[14:11:28.333] INFO: PixTestHighRate::doXPixelAlive() done
[14:11:28.385] INFO: PixTest:: pg_setup set to default.
[14:11:28.398] INFO: enter test to run
[14:11:50.921] INFO: test: HighRate no parameter change
[14:11:50.921] INFO: running: highrate
[14:11:50.923] INFO: ----------------------------------------------------------------------
[14:11:50.923] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:11:50.923] INFO: ----------------------------------------------------------------------
[14:11:51.545] INFO: Expecting 208000 events.
[14:12:04.726] INFO: 208000 events read in total (12653ms).
[14:12:04.730] INFO: Test took 13796ms.
[14:12:04.993] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:05.281] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 7 0 0 1 0 0 0 0
[14:12:05.281] INFO: number of red-efficiency pixels: 196 112 240 378 371 448 301 235 218 296 312 231 265 166 49 46
[14:12:05.281] INFO: number of X-ray hits detected: 128787 78672 125819 195440 201718 208019 192875 144473 132488 166759 173835 150786 155279 95525 39017 46703
[14:12:05.281] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:12:05.281] INFO: number of Vcal hits detected: 207787 207886 207737 207592 207609 207508 207671 207709 207394 207683 207677 207702 207723 207828 207950 207954
[14:12:05.282] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0
[14:12:05.282] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.7 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:12:05.282] INFO: X-ray hit rate [MHz/cm2]: 37.7 23.1 36.9 57.3 59.1 61.0 56.5 42.3 38.8 48.9 51.0 44.2 45.5 28.0 11.4 13.7
[14:12:05.282] INFO: PixTestHighRate::doXPixelAlive() done
[14:12:05.332] INFO: PixTest:: pg_setup set to default.
[14:12:05.350] INFO: enter test to run
[14:12:26.841] INFO: test: HighRate no parameter change
[14:12:26.841] INFO: running: highrate
[14:12:26.842] INFO: ----------------------------------------------------------------------
[14:12:26.842] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:12:26.842] INFO: ----------------------------------------------------------------------
[14:12:27.456] INFO: Expecting 208000 events.
[14:12:42.111] INFO: 208000 events read in total (14128ms).
[14:12:42.118] INFO: Test took 15267ms.
[14:12:42.505] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:42.834] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 1 15 0 0 1 0 0 0 0
[14:12:42.834] INFO: number of red-efficiency pixels: 533 233 567 836 807 998 671 517 442 620 676 511 587 325 77 75
[14:12:42.834] INFO: number of X-ray hits detected: 191767 118493 188276 293192 302619 309830 286998 216541 197470 247918 259349 225586 233319 142260 58218 70059
[14:12:42.834] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:12:42.834] INFO: number of Vcal hits detected: 207367 207747 207300 207026 207079 206746 207240 207352 206702 207313 207232 207366 207344 207634 207919 207924
[14:12:42.834] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.6 99.6 99.5 99.7 99.7 99.8 99.7 99.7 99.8 99.7 99.8 100.0 100.0
[14:12:42.834] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.5 99.6 99.4 99.6 99.7 99.4 99.7 99.6 99.7 99.7 99.8 100.0 100.0
[14:12:42.834] INFO: X-ray hit rate [MHz/cm2]: 56.2 34.7 55.2 85.9 88.7 90.8 84.1 63.5 57.9 72.7 76.0 66.1 68.4 41.7 17.1 20.5
[14:12:42.834] INFO: PixTestHighRate::doXPixelAlive() done
[14:12:42.886] INFO: PixTest:: pg_setup set to default.
[14:12:42.904] INFO: enter test to run
[14:12:48.289] INFO: test: exit no parameter change
[14:12:48.638] QUIET: Connection to board 33 closed.
[14:12:48.650] INFO: pXar: this is the end, my friend