[10:21:38.627] INFO: *** Welcome to pxar ***
[10:21:38.627] INFO: *** Today: 2016/05/09
[10:21:39.054] INFO: *** Version: v1.9.0-796-gef167-dirty
[10:21:39.054] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//dacParameters35_C15.dat
[10:21:39.109] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//tbmParameters_C0b.dat
[10:21:39.109] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//defaultMaskFile.dat
[10:21:39.110] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C15.dat
[10:21:39.233] INFO: clk: 4
[10:21:39.233] INFO: ctr: 4
[10:21:39.233] INFO: sda: 19
[10:21:39.233] INFO: tin: 9
[10:21:39.233] INFO: level: 15
[10:21:39.233] INFO: triggerdelay: 0
[10:21:39.233] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[10:21:39.234] INFO: Log level: INFO
[10:21:39.252] QUIET: Connection to board DTB_WREKRL opened.
[10:21:39.255] 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:
------------------------------------------------------
[10:21:39.258] INFO: RPC call hashes of host and DTB match: 398089610
[10:21:40.803] INFO: DUT info:
[10:21:40.803] INFO: The DUT currently contains the following objects:
[10:21:40.804] INFO: 2 TBM Cores tbm08c (2 ON)
[10:21:40.816] INFO: TBM Core alpha (0): 7 registers set
[10:21:40.816] INFO: TBM Core beta (1): 7 registers set
[10:21:40.817] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[10:21:40.817] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:40.817] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[10:21:41.279] INFO: enter 'restricted' command line mode
[10:21:41.279] INFO: enter test to run
[10:21:48.068] INFO: test: PixelAlive no parameter change
[10:21:48.069] INFO: running: pixelalive
[10:21:48.130] INFO: ----------------------------------------------------------------------
[10:21:48.130] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[10:21:48.130] INFO: ----------------------------------------------------------------------
[10:21:48.450] INFO: Expecting 41600 events.
[10:21:52.753] INFO: 41600 events read in total (3584ms).
[10:21:52.915] INFO: Test took 4781ms.
[10:21:52.924] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:21:53.452] INFO: PixTestAlive::aliveTest() done
[10:21:53.452] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 16 0 2 0 0 0 0 0 0 0
[10:21:53.672] INFO: enter test to run
[10:22:38.748] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[10:22:38.748] INFO: running: highrate
[10:22:38.748] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[10:22:39.026] INFO: ----------------------------------------------------------------------
[10:22:39.026] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[10:22:39.026] INFO: ----------------------------------------------------------------------
[10:22:39.026] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[10:22:39.026] INFO: edge/corner pixel THR is adjusted
[10:22:39.026] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:22:39.985] INFO: Collecting data for 5 seconds...
[10:22:44.003] INFO: Done with hot pixel readout
[10:22:56.469] INFO: PixTest:: pg_setup set to default.
[10:22:56.470] INFO: 2 hot pixels found in step 0
[10:22:57.461] INFO: Collecting data for 5 seconds...
[10:23:02.478] INFO: Done with hot pixel readout
[10:23:13.962] INFO: PixTest:: pg_setup set to default.
[10:23:13.963] INFO: 4 hot pixels found in step 1
[10:23:14.961] INFO: Collecting data for 5 seconds...
[10:23:19.979] INFO: Done with hot pixel readout
[10:23:31.810] INFO: PixTest:: pg_setup set to default.
[10:23:31.811] INFO: 3 hot pixels found in step 2
[10:23:32.808] INFO: Collecting data for 5 seconds...
[10:23:37.824] INFO: Done with hot pixel readout
[10:23:49.158] INFO: PixTest:: pg_setup set to default.
[10:23:49.159] INFO: 1 hot pixels found in step 3
[10:23:50.155] INFO: Collecting data for 5 seconds...
[10:23:55.173] INFO: Done with hot pixel readout
[10:24:06.890] INFO: PixTest:: pg_setup set to default.
[10:24:06.891] INFO: 2 hot pixels found in step 4
[10:24:07.887] INFO: Collecting data for 5 seconds...
[10:24:12.905] INFO: Done with hot pixel readout
[10:24:24.185] INFO: PixTest:: pg_setup set to default.
[10:24:24.186] INFO: 1 hot pixels found in step 5
[10:24:25.182] INFO: Collecting data for 5 seconds...
[10:24:30.201] INFO: Done with hot pixel readout
[10:24:42.094] INFO: PixTest:: pg_setup set to default.
[10:24:42.095] INFO: 3 hot pixels found in step 6
[10:24:43.089] INFO: Collecting data for 5 seconds...
[10:24:48.108] INFO: Done with hot pixel readout
[10:24:59.986] INFO: PixTest:: pg_setup set to default.
[10:24:59.987] INFO: 6 hot pixels found in step 7
[10:25:00.982] INFO: Collecting data for 5 seconds...
[10:25:05.001] INFO: Done with hot pixel readout
[10:25:17.804] INFO: PixTest:: pg_setup set to default.
[10:25:17.805] INFO: 3 hot pixels found in step 8
[10:25:18.800] INFO: Collecting data for 5 seconds...
[10:25:23.818] INFO: Done with hot pixel readout
[10:25:35.598] INFO: PixTest:: pg_setup set to default.
[10:25:35.598] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:25:35.598] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:25:35.599] INFO: 3 hot pixels found in step 9
[10:25:36.595] INFO: Collecting data for 5 seconds...
[10:25:41.612] INFO: Done with hot pixel readout
[10:25:53.200] INFO: PixTest:: pg_setup set to default.
[10:25:53.201] INFO: 3 hot pixels found in step 10
[10:25:54.196] INFO: Collecting data for 5 seconds...
[10:25:59.214] INFO: Done with hot pixel readout
[10:26:10.542] INFO: PixTest:: pg_setup set to default.
[10:26:10.543] INFO: 1 hot pixels found in step 11
[10:26:11.538] INFO: Collecting data for 5 seconds...
[10:26:16.555] INFO: Done with hot pixel readout
[10:26:28.429] INFO: PixTest:: pg_setup set to default.
[10:26:28.429] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[10:26:28.430] INFO: 1 hot pixels found in step 12
[10:26:28.469] INFO: 1 hot pixels could not be trimmed and have been masked.
[10:26:28.489] INFO: PixTest::trimHotPixels() done
[10:26:28.503] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C0.dat
[10:26:28.515] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C1.dat
[10:26:28.526] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C2.dat
[10:26:28.532] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C3.dat
[10:26:28.537] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C4.dat
[10:26:28.551] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C5.dat
[10:26:28.556] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C6.dat
[10:26:28.567] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C7.dat
[10:26:28.572] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C8.dat
[10:26:28.578] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C9.dat
[10:26:28.583] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C10.dat
[10:26:28.589] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C11.dat
[10:26:28.594] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C12.dat
[10:26:28.599] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C13.dat
[10:26:28.604] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C14.dat
[10:26:28.610] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C15.dat
[10:26:28.615] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//defaultMaskFile.dat
[10:26:28.626] INFO: enter test to run
[10:26:58.971] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[10:26:58.971] INFO: running: highrate
[10:26:58.975] INFO: ----------------------------------------------------------------------
[10:26:58.975] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[10:26:58.975] INFO: ----------------------------------------------------------------------
[10:26:58.975] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[10:26:58.975] INFO: edge/corner pixel THR is adjusted
[10:26:58.975] INFO: PixTestHighRate::trimHotPixels: step 0...
[10:26:59.933] INFO: Collecting data for 1 seconds...
[10:27:00.937] INFO: Done with hot pixel readout
[10:27:04.956] INFO: PixTest:: pg_setup set to default.
[10:27:04.957] INFO: 0 hot pixels found in step 0
[10:27:04.962] INFO: 0 hot pixels could not be trimmed and have been masked.
[10:27:05.050] INFO: PixTest::trimHotPixels() done
[10:27:05.050] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C0.dat
[10:27:05.059] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C1.dat
[10:27:05.068] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C2.dat
[10:27:05.073] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C3.dat
[10:27:05.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C4.dat
[10:27:05.084] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C5.dat
[10:27:05.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C6.dat
[10:27:05.094] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C7.dat
[10:27:05.099] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C8.dat
[10:27:05.105] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C9.dat
[10:27:05.110] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C10.dat
[10:27:05.115] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C11.dat
[10:27:05.120] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C12.dat
[10:27:05.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C13.dat
[10:27:05.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C14.dat
[10:27:05.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//trimParameters35_C15.dat
[10:27:05.141] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-N-3-29_FPIXTest-17C-FNAL-160503-1259_2016-05-03_12h59m_1462298381/000_FPIXTest_p17//defaultMaskFile.dat
[10:27:05.151] INFO: enter test to run
[10:28:03.570] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[10:28:03.570] INFO: running: xray
[10:28:03.571] INFO: ----------------------------------------------------------------------
[10:28:03.571] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:28:03.571] INFO: ----------------------------------------------------------------------
[10:28:04.548] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:28:15.892] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[10:28:45.466] INFO: Resuming triggers.
[10:28:56.814] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[10:29:26.568] INFO: Resuming triggers.
[10:29:37.909] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[10:30:07.166] INFO: Resuming triggers.
[10:30:18.512] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[10:30:47.961] INFO: Resuming triggers.
[10:30:59.308] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[10:31:28.682] INFO: Resuming triggers.
[10:31:40.027] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[10:32:09.493] INFO: Resuming triggers.
[10:32:20.840] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[10:32:50.243] INFO: Resuming triggers.
[10:33:01.591] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[10:33:31.024] INFO: Resuming triggers.
[10:33:40.585] INFO: data taking finished, elapsed time: 100 seconds.
[10:34:05.637] INFO: PixTest:: pg_setup set to default.
[10:34:05.640] INFO: PixTestXray::doPhRun() done
[10:34:05.779] INFO: enter test to run
[10:35:20.823] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[10:35:20.823] INFO: running: xray
[10:35:20.824] INFO: ----------------------------------------------------------------------
[10:35:20.824] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[10:35:20.824] INFO: ----------------------------------------------------------------------
[10:35:21.787] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[10:35:28.339] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[10:35:59.616] INFO: Resuming triggers.
[10:36:06.166] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[10:36:37.272] INFO: Resuming triggers.
[10:36:43.822] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[10:37:14.439] INFO: Resuming triggers.
[10:37:20.988] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[10:37:51.142] INFO: Resuming triggers.
[10:37:57.687] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[10:38:27.659] INFO: Resuming triggers.
[10:38:34.204] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[10:39:04.410] INFO: Resuming triggers.
[10:39:10.952] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[10:39:41.118] INFO: Resuming triggers.
[10:39:47.663] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[10:40:17.788] INFO: Resuming triggers.
[10:40:24.337] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[10:40:54.456] INFO: Resuming triggers.
[10:41:00.002] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[10:41:31.087] INFO: Resuming triggers.
[10:41:37.632] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[10:42:07.841] INFO: Resuming triggers.
[10:42:14.388] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[10:42:44.573] INFO: Resuming triggers.
[10:42:51.120] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[10:43:21.267] INFO: Resuming triggers.
[10:43:27.818] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[10:43:56.707] INFO: Resuming triggers.
[10:44:03.254] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[10:44:33.305] INFO: Resuming triggers.
[10:44:35.432] INFO: data taking finished, elapsed time: 100 seconds.
[10:44:45.549] INFO: PixTest:: pg_setup set to default.
[10:44:45.552] INFO: PixTestXray::doPhRun() done
[10:44:45.703] INFO: enter test to run
[10:45:20.171] INFO: test: HighRate no parameter change
[10:45:20.171] INFO: running: highrate
[10:45:20.172] INFO: ----------------------------------------------------------------------
[10:45:20.172] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[10:45:20.172] INFO: ----------------------------------------------------------------------
[10:45:20.312] INFO: Expecting 768 events.
[10:45:21.447] INFO: 768 events read in total (420ms).
[10:45:21.447] INFO: Test took 1269ms.
[10:45:22.251] INFO: Expecting 41600 events.
[10:45:25.296] INFO: 41600 events read in total (2518ms).
[10:45:25.297] INFO: Test took 3843ms.
[10:45:25.331] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:26.060] INFO: Expecting 41600 events.
[10:45:29.192] INFO: 41600 events read in total (2606ms).
[10:45:29.193] INFO: Test took 3845ms.
[10:45:29.233] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:29.939] INFO: Expecting 41600 events.
[10:45:33.154] INFO: 41600 events read in total (2689ms).
[10:45:33.155] INFO: Test took 3904ms.
[10:45:33.191] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:33.909] INFO: Expecting 41600 events.
[10:45:37.176] INFO: 41600 events read in total (2740ms).
[10:45:37.177] INFO: Test took 3968ms.
[10:45:37.213] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:37.931] INFO: Expecting 41600 events.
[10:45:41.172] INFO: 41600 events read in total (2714ms).
[10:45:41.173] INFO: Test took 3941ms.
[10:45:41.209] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:41.927] INFO: Expecting 41600 events.
[10:45:45.151] INFO: 41600 events read in total (2697ms).
[10:45:45.152] INFO: Test took 3925ms.
[10:45:45.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:45.907] INFO: Expecting 41600 events.
[10:45:49.091] INFO: 41600 events read in total (2658ms).
[10:45:49.092] INFO: Test took 3886ms.
[10:45:49.128] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:49.846] INFO: Expecting 41600 events.
[10:45:53.086] INFO: 41600 events read in total (2713ms).
[10:45:53.087] INFO: Test took 3941ms.
[10:45:53.123] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:53.840] INFO: Expecting 41600 events.
[10:45:57.116] INFO: 41600 events read in total (2750ms).
[10:45:57.117] INFO: Test took 3975ms.
[10:45:57.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:45:57.867] INFO: Expecting 41600 events.
[10:46:01.104] INFO: 41600 events read in total (2710ms).
[10:46:01.104] INFO: Test took 3933ms.
[10:46:01.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:01.861] INFO: Expecting 41600 events.
[10:46:05.100] INFO: 41600 events read in total (2712ms).
[10:46:05.101] INFO: Test took 3945ms.
[10:46:05.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:05.857] INFO: Expecting 41600 events.
[10:46:09.108] INFO: 41600 events read in total (2724ms).
[10:46:09.109] INFO: Test took 3954ms.
[10:46:09.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:09.866] INFO: Expecting 41600 events.
[10:46:13.117] INFO: 41600 events read in total (2724ms).
[10:46:13.118] INFO: Test took 3956ms.
[10:46:13.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:13.877] INFO: Expecting 41600 events.
[10:46:17.138] INFO: 41600 events read in total (2734ms).
[10:46:17.139] INFO: Test took 3968ms.
[10:46:17.176] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:17.896] INFO: Expecting 41600 events.
[10:46:21.181] INFO: 41600 events read in total (2758ms).
[10:46:21.182] INFO: Test took 3988ms.
[10:46:21.218] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:21.937] INFO: Expecting 41600 events.
[10:46:25.272] INFO: 41600 events read in total (2809ms).
[10:46:25.273] INFO: Test took 4037ms.
[10:46:25.309] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:26.026] INFO: Expecting 41600 events.
[10:46:29.333] INFO: 41600 events read in total (2780ms).
[10:46:29.334] INFO: Test took 4007ms.
[10:46:29.371] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:30.092] INFO: Expecting 41600 events.
[10:46:33.361] INFO: 41600 events read in total (2742ms).
[10:46:33.362] INFO: Test took 3973ms.
[10:46:33.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:34.118] INFO: Expecting 41600 events.
[10:46:37.406] INFO: 41600 events read in total (2762ms).
[10:46:37.407] INFO: Test took 3991ms.
[10:46:37.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:38.164] INFO: Expecting 41600 events.
[10:46:41.326] INFO: 41600 events read in total (2635ms).
[10:46:41.327] INFO: Test took 3866ms.
[10:46:41.363] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:46:41.721] INFO: enter test to run
[10:46:58.913] INFO: test: HighRate no parameter change
[10:46:58.913] INFO: running: highrate
[10:46:58.915] INFO: ----------------------------------------------------------------------
[10:46:58.915] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:46:58.915] INFO: ----------------------------------------------------------------------
[10:46:59.535] INFO: Expecting 208000 events.
[10:47:10.798] INFO: 208000 events read in total (10736ms).
[10:47:10.802] INFO: Test took 11878ms.
[10:47:10.954] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:11.211] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 16 0 2 0 0 0 0 0 0 0
[10:47:11.211] INFO: number of red-efficiency pixels: 73 45 87 132 164 126 187 112 84 121 117 84 98 79 27 45
[10:47:11.211] INFO: number of X-ray hits detected: 64689 42284 70281 115574 121046 118524 118835 88737 80558 97051 96324 83983 87808 54131 24421 28334
[10:47:11.211] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:47:11.211] INFO: number of Vcal hits detected: 207923 207954 207907 207815 207829 207872 207003 207885 207817 207877 207879 207913 207901 207918 207972 207955
[10:47:11.211] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[10:47:11.211] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.5 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[10:47:11.211] INFO: X-ray hit rate [MHz/cm2]: 19.0 12.4 20.6 33.9 35.5 34.7 34.8 26.0 23.6 28.4 28.2 24.6 25.7 15.9 7.2 8.3
[10:47:11.211] INFO: PixTestHighRate::doXPixelAlive() done
[10:47:11.255] INFO: PixTest:: pg_setup set to default.
[10:47:11.271] INFO: enter test to run
[10:47:31.801] INFO: test: HighRate no parameter change
[10:47:31.801] INFO: running: highrate
[10:47:31.802] INFO: ----------------------------------------------------------------------
[10:47:31.802] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:47:31.802] INFO: ----------------------------------------------------------------------
[10:47:32.424] INFO: Expecting 208000 events.
[10:47:46.315] INFO: 208000 events read in total (13364ms).
[10:47:46.320] INFO: Test took 14509ms.
[10:47:46.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:47:46.940] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 15 0 2 0 0 0 0 0 0 0
[10:47:46.940] INFO: number of red-efficiency pixels: 185 112 281 428 472 533 551 450 207 296 358 292 302 221 69 79
[10:47:46.940] INFO: number of X-ray hits detected: 133695 86010 144385 238303 248238 242864 244142 183075 164386 198434 197288 172387 180808 110760 50639 58744
[10:47:46.940] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:47:46.941] INFO: number of Vcal hits detected: 207802 207883 207689 207476 207489 207421 206588 207517 207678 207694 207619 207697 207681 207763 207931 207918
[10:47:46.941] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.7 99.7 99.8 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[10:47:46.941] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.7 99.8 99.7 99.3 99.8 99.8 99.9 99.8 99.9 99.8 99.9 100.0 100.0
[10:47:46.941] INFO: X-ray hit rate [MHz/cm2]: 39.2 25.2 42.3 69.8 72.8 71.2 71.6 53.7 48.2 58.2 57.8 50.5 53.0 32.5 14.8 17.2
[10:47:46.941] INFO: PixTestHighRate::doXPixelAlive() done
[10:47:46.988] INFO: PixTest:: pg_setup set to default.
[10:47:47.008] INFO: enter test to run
[10:48:05.425] INFO: test: HighRate no parameter change
[10:48:05.425] INFO: running: highrate
[10:48:05.426] INFO: ----------------------------------------------------------------------
[10:48:05.426] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[10:48:05.426] INFO: ----------------------------------------------------------------------
[10:48:06.049] INFO: Expecting 208000 events.
[10:48:21.933] INFO: 208000 events read in total (15357ms).
[10:48:21.941] INFO: Test took 16506ms.
[10:48:22.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[10:48:22.763] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 16 0 2 0 0 0 0 0 0 0
[10:48:22.764] INFO: number of red-efficiency pixels: 468 261 712 1047 1129 1253 1461 958 468 738 753 658 746 485 141 127
[10:48:22.764] INFO: number of X-ray hits detected: 207064 134881 223052 367550 382867 375513 376912 281904 255269 305539 305843 267020 279051 172749 78311 90707
[10:48:22.764] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[10:48:22.764] INFO: number of Vcal hits detected: 207444 207718 207064 206659 206587 206353 205256 206755 207391 207149 207121 207250 207152 207427 207847 207870
[10:48:22.764] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.4 99.4 99.3 99.1 99.5 99.8 99.6 99.6 99.7 99.6 99.7 99.9 99.9
[10:48:22.764] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.4 99.3 99.2 98.7 99.4 99.7 99.6 99.6 99.6 99.6 99.7 99.9 99.9
[10:48:22.764] INFO: X-ray hit rate [MHz/cm2]: 60.7 39.5 65.4 107.7 112.2 110.1 110.5 82.6 74.8 89.6 89.6 78.3 81.8 50.6 23.0 26.6
[10:48:22.764] INFO: PixTestHighRate::doXPixelAlive() done
[10:48:22.812] INFO: PixTest:: pg_setup set to default.
[10:48:22.829] INFO: enter test to run
[10:48:36.521] INFO: test: exit no parameter change
[10:48:36.849] QUIET: Connection to board 33 closed.
[10:48:36.850] INFO: pXar: this is the end, my friend