[12:51:31.358] INFO: *** Welcome to pxar ***
[12:51:31.358] INFO: *** Today: 2016/06/29
[12:51:32.263] INFO: *** Version: v1.9.0-814-g7497
[12:51:32.263] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/dacParameters35_C15.dat
[12:51:32.380] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/tbmParameters_C0b.dat
[12:51:32.380] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/defaultMaskFile.dat
[12:51:32.391] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C15.dat
[12:51:32.532] INFO: clk: 4
[12:51:32.532] INFO: ctr: 4
[12:51:32.532] INFO: sda: 19
[12:51:32.532] INFO: tin: 9
[12:51:32.532] INFO: level: 15
[12:51:32.532] INFO: triggerdelay: 0
[12:51:32.533] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:51:32.533] INFO: Log level: INFO
[12:51:32.551] QUIET: Connection to board DTB_WREKRL opened.
[12:51:32.555] 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:
------------------------------------------------------
[12:51:32.557] INFO: RPC call hashes of host and DTB match: 398089610
[12:51:34.103] INFO: DUT info:
[12:51:34.104] INFO: The DUT currently contains the following objects:
[12:51:34.104] INFO: 2 TBM Cores tbm08c (2 ON)
[12:51:34.117] INFO: TBM Core alpha (0): 7 registers set
[12:51:34.117] INFO: TBM Core beta (1): 7 registers set
[12:51:34.117] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:51:34.117] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.118] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:51:34.578] INFO: enter 'restricted' command line mode
[12:51:34.578] INFO: enter test to run
[12:51:38.543] INFO: test: PixelAlive no parameter change
[12:51:38.543] INFO: running: pixelalive
[12:51:38.615] INFO: ----------------------------------------------------------------------
[12:51:38.615] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:51:38.615] INFO: ----------------------------------------------------------------------
[12:51:38.934] INFO: Expecting 41600 events.
[12:51:43.313] INFO: 41600 events read in total (3660ms).
[12:51:43.483] INFO: Test took 4864ms.
[12:51:43.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:51:44.073] INFO: PixTestAlive::aliveTest() done
[12:51:44.073] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 1 0 0 2 0 0 1
[12:51:44.224] INFO: enter test to run
[12:52:29.182] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:52:29.182] INFO: running: highrate
[12:52:29.193] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/phCalibrationFitErr35_C15.dat
[12:52:29.468] INFO: ----------------------------------------------------------------------
[12:52:29.468] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:52:29.468] INFO: ----------------------------------------------------------------------
[12:52:29.468] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:52:29.468] INFO: edge/corner pixel THR is adjusted
[12:52:29.468] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:52:30.429] INFO: Collecting data for 5 seconds...
[12:52:35.444] INFO: Done with hot pixel readout
[12:52:46.962] INFO: PixTest:: pg_setup set to default.
[12:52:46.963] INFO: 10 hot pixels found in step 0
[12:52:47.951] INFO: Collecting data for 5 seconds...
[12:52:52.967] INFO: Done with hot pixel readout
[12:53:04.446] INFO: PixTest:: pg_setup set to default.
[12:53:04.447] INFO: 5 hot pixels found in step 1
[12:53:05.437] INFO: Collecting data for 5 seconds...
[12:53:10.453] INFO: Done with hot pixel readout
[12:53:21.983] INFO: PixTest:: pg_setup set to default.
[12:53:21.984] INFO: 12 hot pixels found in step 2
[12:53:22.975] INFO: Collecting data for 5 seconds...
[12:53:27.991] INFO: Done with hot pixel readout
[12:53:39.540] INFO: PixTest:: pg_setup set to default.
[12:53:39.540] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:53:39.541] INFO: 14 hot pixels found in step 3
[12:53:40.531] INFO: Collecting data for 5 seconds...
[12:53:45.547] INFO: Done with hot pixel readout
[12:53:57.211] INFO: PixTest:: pg_setup set to default.
[12:53:57.212] INFO: 10 hot pixels found in step 4
[12:53:58.202] INFO: Collecting data for 5 seconds...
[12:54:03.221] INFO: Done with hot pixel readout
[12:54:14.818] INFO: PixTest:: pg_setup set to default.
[12:54:14.819] INFO: 12 hot pixels found in step 5
[12:54:15.810] INFO: Collecting data for 5 seconds...
[12:54:20.829] INFO: Done with hot pixel readout
[12:54:32.375] INFO: PixTest:: pg_setup set to default.
[12:54:32.376] INFO: 10 hot pixels found in step 6
[12:54:33.366] INFO: Collecting data for 5 seconds...
[12:54:38.384] INFO: Done with hot pixel readout
[12:54:49.700] INFO: PixTest:: pg_setup set to default.
[12:54:49.701] INFO: 10 hot pixels found in step 7
[12:54:50.691] INFO: Collecting data for 5 seconds...
[12:54:55.709] INFO: Done with hot pixel readout
[12:55:06.893] INFO: PixTest:: pg_setup set to default.
[12:55:06.894] INFO: 10 hot pixels found in step 8
[12:55:07.885] INFO: Collecting data for 5 seconds...
[12:55:12.903] INFO: Done with hot pixel readout
[12:55:24.309] INFO: PixTest:: pg_setup set to default.
[12:55:24.310] INFO: 11 hot pixels found in step 9
[12:55:25.301] INFO: Collecting data for 5 seconds...
[12:55:30.319] INFO: Done with hot pixel readout
[12:55:41.907] INFO: PixTest:: pg_setup set to default.
[12:55:41.908] INFO: 8 hot pixels found in step 10
[12:55:42.898] INFO: Collecting data for 5 seconds...
[12:55:47.918] INFO: Done with hot pixel readout
[12:55:59.698] INFO: PixTest:: pg_setup set to default.
[12:55:59.699] INFO: 10 hot pixels found in step 11
[12:56:00.689] INFO: Collecting data for 5 seconds...
[12:56:05.709] INFO: Done with hot pixel readout
[12:56:17.465] INFO: PixTest:: pg_setup set to default.
[12:56:17.465] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:17.466] INFO: 9 hot pixels found in step 12
[12:56:18.456] INFO: Collecting data for 5 seconds...
[12:56:23.476] INFO: Done with hot pixel readout
[12:56:35.256] INFO: PixTest:: pg_setup set to default.
[12:56:35.256] INFO: 7 hot pixels found in step 13
[12:56:36.247] INFO: Collecting data for 5 seconds...
[12:56:41.265] INFO: Done with hot pixel readout
[12:56:53.241] INFO: PixTest:: pg_setup set to default.
[12:56:53.242] INFO: 4 hot pixels found in step 14
[12:56:53.278] INFO: 4 hot pixels could not be trimmed and have been masked.
[12:56:53.289] INFO: PixTest::trimHotPixels() done
[12:56:53.289] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C0.dat
[12:56:53.299] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C1.dat
[12:56:53.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C2.dat
[12:56:53.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C3.dat
[12:56:53.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C4.dat
[12:56:53.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C5.dat
[12:56:53.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C6.dat
[12:56:53.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C7.dat
[12:56:53.337] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C8.dat
[12:56:53.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C9.dat
[12:56:53.348] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C10.dat
[12:56:53.353] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C11.dat
[12:56:53.359] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C12.dat
[12:56:53.364] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C13.dat
[12:56:53.369] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C14.dat
[12:56:53.375] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C15.dat
[12:56:53.380] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/defaultMaskFile.dat
[12:56:53.390] INFO: enter test to run
[12:59:36.227] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:59:36.227] INFO: running: highrate
[12:59:36.232] INFO: ----------------------------------------------------------------------
[12:59:36.232] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:59:36.232] INFO: ----------------------------------------------------------------------
[12:59:36.232] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:59:36.232] INFO: edge/corner pixel THR is adjusted
[12:59:36.232] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:59:37.189] INFO: Collecting data for 1 seconds...
[12:59:38.193] INFO: Done with hot pixel readout
[12:59:42.021] INFO: PixTest:: pg_setup set to default.
[12:59:42.022] INFO: 0 hot pixels found in step 0
[12:59:42.027] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:59:42.125] INFO: PixTest::trimHotPixels() done
[12:59:42.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C0.dat
[12:59:42.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C1.dat
[12:59:42.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C2.dat
[12:59:42.146] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C3.dat
[12:59:42.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C4.dat
[12:59:42.156] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C5.dat
[12:59:42.161] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C6.dat
[12:59:42.166] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C7.dat
[12:59:42.172] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C8.dat
[12:59:42.177] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C9.dat
[12:59:42.182] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C10.dat
[12:59:42.187] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C11.dat
[12:59:42.192] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C12.dat
[12:59:42.197] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C13.dat
[12:59:42.203] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C14.dat
[12:59:42.208] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/trimParameters35_C15.dat
[12:59:42.213] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-43_FPIXTest-17C-FNAL-160622-1238_2016-06-22_12h39m_1466617145/000_FPIXTest_p17/defaultMaskFile.dat
[12:59:42.223] INFO: enter test to run
[13:00:42.195] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:00:42.195] INFO: running: xray
[13:00:42.196] INFO: ----------------------------------------------------------------------
[13:00:42.196] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:00:42.196] INFO: ----------------------------------------------------------------------
[13:00:43.180] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:00:54.918] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:01:24.511] INFO: Resuming triggers.
[13:01:36.253] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:02:05.793] INFO: Resuming triggers.
[13:02:17.531] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:02:46.697] INFO: Resuming triggers.
[13:02:58.437] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:03:28.007] INFO: Resuming triggers.
[13:03:39.744] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:04:09.486] INFO: Resuming triggers.
[13:04:21.223] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:04:50.563] INFO: Resuming triggers.
[13:05:02.302] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:05:29.509] INFO: Resuming triggers.
[13:05:41.246] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:06:10.633] INFO: Resuming triggers.
[13:06:17.050] INFO: data taking finished, elapsed time: 100 seconds.
[13:06:33.298] INFO: PixTest:: pg_setup set to default.
[13:06:33.301] INFO: PixTestXray::doPhRun() done
[13:06:33.440] INFO: enter test to run
[13:07:34.160] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:07:34.160] INFO: running: xray
[13:07:34.161] INFO: ----------------------------------------------------------------------
[13:07:34.161] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:07:34.161] INFO: ----------------------------------------------------------------------
[13:07:35.124] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:07:42.222] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[13:08:13.386] INFO: Resuming triggers.
[13:08:20.484] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[13:08:51.421] INFO: Resuming triggers.
[13:08:58.514] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[13:09:28.767] INFO: Resuming triggers.
[13:09:35.864] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[13:10:06.215] INFO: Resuming triggers.
[13:10:13.310] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[13:10:43.501] INFO: Resuming triggers.
[13:10:50.600] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[13:11:20.889] INFO: Resuming triggers.
[13:11:27.986] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[13:11:58.229] INFO: Resuming triggers.
[13:12:05.328] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[13:12:35.555] INFO: Resuming triggers.
[13:12:42.649] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[13:13:12.870] INFO: Resuming triggers.
[13:13:19.968] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[13:13:50.269] INFO: Resuming triggers.
[13:13:57.360] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[13:14:27.656] INFO: Resuming triggers.
[13:14:34.747] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[13:15:04.826] INFO: Resuming triggers.
[13:15:11.920] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:15:42.124] INFO: Resuming triggers.
[13:15:49.212] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[13:16:19.480] INFO: Resuming triggers.
[13:16:20.488] INFO: data taking finished, elapsed time: 100 seconds.
[13:16:25.138] INFO: PixTest:: pg_setup set to default.
[13:16:25.141] INFO: PixTestXray::doPhRun() done
[13:16:25.295] INFO: enter test to run
[13:21:13.155] INFO: test: HighRate no parameter change
[13:21:13.155] INFO: running: highrate
[13:21:13.167] INFO: ----------------------------------------------------------------------
[13:21:13.167] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:21:13.167] INFO: ----------------------------------------------------------------------
[13:21:13.322] INFO: Expecting 768 events.
[13:21:14.458] INFO: 768 events read in total (420ms).
[13:21:14.458] INFO: Test took 1270ms.
[13:21:15.261] INFO: Expecting 41600 events.
[13:21:18.505] INFO: 41600 events read in total (2717ms).
[13:21:18.506] INFO: Test took 4041ms.
[13:21:18.538] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:19.244] INFO: Expecting 41600 events.
[13:21:22.533] INFO: 41600 events read in total (2763ms).
[13:21:22.534] INFO: Test took 3979ms.
[13:21:22.566] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:23.282] INFO: Expecting 41600 events.
[13:21:26.532] INFO: 41600 events read in total (2723ms).
[13:21:26.533] INFO: Test took 3950ms.
[13:21:26.566] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:27.293] INFO: Expecting 41600 events.
[13:21:30.597] INFO: 41600 events read in total (2777ms).
[13:21:30.598] INFO: Test took 4014ms.
[13:21:30.631] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:31.353] INFO: Expecting 41600 events.
[13:21:34.706] INFO: 41600 events read in total (2827ms).
[13:21:34.707] INFO: Test took 4058ms.
[13:21:34.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:35.462] INFO: Expecting 41600 events.
[13:21:38.698] INFO: 41600 events read in total (2709ms).
[13:21:38.699] INFO: Test took 3943ms.
[13:21:38.731] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:39.460] INFO: Expecting 41600 events.
[13:21:42.683] INFO: 41600 events read in total (2697ms).
[13:21:42.684] INFO: Test took 3936ms.
[13:21:42.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:43.445] INFO: Expecting 41600 events.
[13:21:46.689] INFO: 41600 events read in total (2717ms).
[13:21:46.690] INFO: Test took 3955ms.
[13:21:46.723] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:47.449] INFO: Expecting 41600 events.
[13:21:50.684] INFO: 41600 events read in total (2708ms).
[13:21:50.685] INFO: Test took 3944ms.
[13:21:50.717] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:51.441] INFO: Expecting 41600 events.
[13:21:54.668] INFO: 41600 events read in total (2700ms).
[13:21:54.669] INFO: Test took 3936ms.
[13:21:54.702] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:55.426] INFO: Expecting 41600 events.
[13:21:58.657] INFO: 41600 events read in total (2704ms).
[13:21:58.658] INFO: Test took 3939ms.
[13:21:58.690] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:59.419] INFO: Expecting 41600 events.
[13:22:02.654] INFO: 41600 events read in total (2708ms).
[13:22:02.655] INFO: Test took 3947ms.
[13:22:02.688] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:03.417] INFO: Expecting 41600 events.
[13:22:06.660] INFO: 41600 events read in total (2716ms).
[13:22:06.661] INFO: Test took 3957ms.
[13:22:06.694] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:07.422] INFO: Expecting 41600 events.
[13:22:10.654] INFO: 41600 events read in total (2705ms).
[13:22:10.655] INFO: Test took 3944ms.
[13:22:10.687] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:11.414] INFO: Expecting 41600 events.
[13:22:14.672] INFO: 41600 events read in total (2731ms).
[13:22:14.673] INFO: Test took 3969ms.
[13:22:14.705] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:15.429] INFO: Expecting 41600 events.
[13:22:18.650] INFO: 41600 events read in total (2694ms).
[13:22:18.651] INFO: Test took 3930ms.
[13:22:18.683] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:19.412] INFO: Expecting 41600 events.
[13:22:22.645] INFO: 41600 events read in total (2706ms).
[13:22:22.646] INFO: Test took 3946ms.
[13:22:22.679] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:23.409] INFO: Expecting 41600 events.
[13:22:26.641] INFO: 41600 events read in total (2705ms).
[13:22:26.642] INFO: Test took 3946ms.
[13:22:26.675] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:27.401] INFO: Expecting 41600 events.
[13:22:30.608] INFO: 41600 events read in total (2680ms).
[13:22:30.609] INFO: Test took 3916ms.
[13:22:30.642] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:31.366] INFO: Expecting 41600 events.
[13:22:34.445] INFO: 41600 events read in total (2552ms).
[13:22:34.446] INFO: Test took 3787ms.
[13:22:34.478] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:34.846] INFO: enter test to run
[13:22:55.450] INFO: test: HighRate no parameter change
[13:22:55.450] INFO: running: highrate
[13:22:55.451] INFO: ----------------------------------------------------------------------
[13:22:55.451] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:22:55.451] INFO: ----------------------------------------------------------------------
[13:22:56.069] INFO: Expecting 208000 events.
[13:23:07.897] INFO: 208000 events read in total (11301ms).
[13:23:07.900] INFO: Test took 12438ms.
[13:23:08.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:08.283] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 1 0 0 2 0 0 1
[13:23:08.284] INFO: number of red-efficiency pixels: 54 45 57 102 137 163 153 92 83 98 95 88 99 47 24 30
[13:23:08.284] INFO: number of X-ray hits detected: 58935 38782 62567 99948 107659 111945 114641 81155 75179 93462 88325 73980 75270 44986 20199 23304
[13:23:08.284] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:23:08.284] INFO: number of Vcal hits detected: 207946 207955 207943 207849 207859 207834 207841 207907 207915 207849 207902 207908 207800 207951 207976 207921
[13:23:08.284] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[13:23:08.284] 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 100.0 100.0 99.9 100.0 100.0 100.0
[13:23:08.284] INFO: X-ray hit rate [MHz/cm2]: 17.3 11.4 18.3 29.3 31.6 32.8 33.6 23.8 22.0 27.4 25.9 21.7 22.1 13.2 5.9 6.8
[13:23:08.284] INFO: PixTestHighRate::doXPixelAlive() done
[13:23:08.329] INFO: PixTest:: pg_setup set to default.
[13:23:08.343] INFO: enter test to run
[13:24:13.345] INFO: test: HighRate no parameter change
[13:24:13.346] INFO: running: highrate
[13:24:13.347] INFO: ----------------------------------------------------------------------
[13:24:13.347] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:24:13.347] INFO: ----------------------------------------------------------------------
[13:24:13.966] INFO: Expecting 208000 events.
[13:24:27.337] INFO: 208000 events read in total (12844ms).
[13:24:27.342] INFO: Test took 13984ms.
[13:24:27.616] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:27.909] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 1 0 0 2 0 0 1
[13:24:27.909] INFO: number of red-efficiency pixels: 148 104 172 317 476 487 533 307 274 376 349 262 216 103 56 48
[13:24:27.909] INFO: number of X-ray hits detected: 120989 78704 127083 201848 218404 227038 231347 165380 152660 187292 179145 150754 153893 91789 41707 47670
[13:24:27.909] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:24:27.909] INFO: number of Vcal hits detected: 207847 207892 207814 207622 207479 207457 207415 207662 207717 207541 207638 207727 207675 207894 207942 207903
[13:24:27.909] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.8 99.7 99.9 99.9 99.8 99.8 99.9 99.9 100.0 100.0 100.0
[13:24:27.909] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[13:24:27.909] INFO: X-ray hit rate [MHz/cm2]: 35.5 23.1 37.2 59.2 64.0 66.5 67.8 48.5 44.7 54.9 52.5 44.2 45.1 26.9 12.2 14.0
[13:24:27.909] INFO: PixTestHighRate::doXPixelAlive() done
[13:24:27.960] INFO: PixTest:: pg_setup set to default.
[13:24:27.976] INFO: enter test to run
[13:25:02.025] INFO: test: HighRate no parameter change
[13:25:02.025] INFO: running: highrate
[13:25:02.026] INFO: ----------------------------------------------------------------------
[13:25:02.026] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:25:02.026] INFO: ----------------------------------------------------------------------
[13:25:02.645] INFO: Expecting 208000 events.
[13:25:17.708] INFO: 208000 events read in total (14537ms).
[13:25:17.714] INFO: Test took 15676ms.
[13:25:18.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:25:18.444] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 1 0 0 2 0 0 1
[13:25:18.444] INFO: number of red-efficiency pixels: 295 206 425 753 1111 1209 1301 743 533 792 772 592 419 236 67 92
[13:25:18.444] INFO: number of X-ray hits detected: 181931 118436 189323 302491 327608 340100 346891 247475 229530 279227 269340 225799 230518 136942 62969 71753
[13:25:18.444] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:25:18.444] INFO: number of Vcal hits detected: 207681 207765 207492 207102 206624 206441 206290 207058 207398 206980 207118 207337 207447 207750 207930 207857
[13:25:18.444] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.6 99.4 99.3 99.3 99.6 99.7 99.6 99.6 99.7 99.8 99.9 100.0 100.0
[13:25:18.444] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.3 99.3 99.2 99.5 99.7 99.5 99.6 99.7 99.7 99.9 100.0 99.9
[13:25:18.444] INFO: X-ray hit rate [MHz/cm2]: 53.3 34.7 55.5 88.7 96.0 99.7 101.7 72.5 67.3 81.8 78.9 66.2 67.6 40.1 18.5 21.0
[13:25:18.444] INFO: PixTestHighRate::doXPixelAlive() done
[13:25:18.489] INFO: PixTest:: pg_setup set to default.
[13:25:18.508] INFO: enter test to run
[13:25:21.513] INFO: test: exit no parameter change
[13:25:21.835] QUIET: Connection to board 33 closed.
[13:25:21.846] INFO: pXar: this is the end, my friend