[15:20:06.376] INFO: *** Welcome to pxar ***
[15:20:06.376] INFO: *** Today: 2016/06/15
[15:20:06.394] INFO: *** Version: v1.9.0-814-g7497
[15:20:06.394] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//dacParameters35_C15.dat
[15:20:06.397] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:20:06.397] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//defaultMaskFile.dat
[15:20:06.413] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C15.dat
[15:20:06.517] INFO: clk: 4
[15:20:06.517] INFO: ctr: 4
[15:20:06.517] INFO: sda: 19
[15:20:06.517] INFO: tin: 9
[15:20:06.517] INFO: level: 15
[15:20:06.517] INFO: triggerdelay: 0
[15:20:06.517] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:20:06.517] INFO: Log level: INFO
[15:20:06.536] QUIET: Connection to board DTB_WREKRL opened.
[15:20:06.539] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 33
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREKRL
MAC address: 40D855118021
Hostname: pixelDTB033
Comment:
------------------------------------------------------
[15:20:06.542] INFO: RPC call hashes of host and DTB match: 398089610
[15:20:08.067] INFO: DUT info:
[15:20:08.068] INFO: The DUT currently contains the following objects:
[15:20:08.068] INFO: 2 TBM Cores tbm08c (2 ON)
[15:20:08.068] INFO: TBM Core alpha (0): 7 registers set
[15:20:08.068] INFO: TBM Core beta (1): 7 registers set
[15:20:08.068] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:20:08.068] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.068] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:20:08.490] INFO: enter 'restricted' command line mode
[15:20:08.490] INFO: enter test to run
[15:20:12.335] INFO: test: PixelAlive no parameter change
[15:20:12.335] INFO: running: pixelalive
[15:20:12.344] INFO: ----------------------------------------------------------------------
[15:20:12.344] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:20:12.344] INFO: ----------------------------------------------------------------------
[15:20:12.664] INFO: Expecting 41600 events.
[15:20:16.983] INFO: 41600 events read in total (3601ms).
[15:20:17.151] INFO: Test took 4805ms.
[15:20:17.163] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:20:17.428] INFO: PixTestAlive::aliveTest() done
[15:20:17.428] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:20:17.458] INFO: enter test to run
[15:22:16.558] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:22:16.558] INFO: running: highrate
[15:22:16.558] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:22:16.761] INFO: ----------------------------------------------------------------------
[15:22:16.761] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:22:16.761] INFO: ----------------------------------------------------------------------
[15:22:16.761] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:22:16.761] INFO: edge/corner pixel THR is adjusted
[15:22:16.761] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:22:17.720] INFO: Collecting data for 5 seconds...
[15:22:22.736] INFO: Done with hot pixel readout
[15:22:34.260] INFO: PixTest:: pg_setup set to default.
[15:22:34.261] INFO: 10 hot pixels found in step 0
[15:22:35.251] INFO: Collecting data for 5 seconds...
[15:22:40.267] INFO: Done with hot pixel readout
[15:22:51.716] INFO: PixTest:: pg_setup set to default.
[15:22:51.717] INFO: 12 hot pixels found in step 1
[15:22:52.707] INFO: Collecting data for 5 seconds...
[15:22:57.723] INFO: Done with hot pixel readout
[15:23:09.141] INFO: PixTest:: pg_setup set to default.
[15:23:09.141] INFO: 9 hot pixels found in step 2
[15:23:10.131] INFO: Collecting data for 5 seconds...
[15:23:15.146] INFO: Done with hot pixel readout
[15:23:26.682] INFO: PixTest:: pg_setup set to default.
[15:23:26.683] INFO: 11 hot pixels found in step 3
[15:23:27.672] INFO: Collecting data for 5 seconds...
[15:23:32.687] INFO: Done with hot pixel readout
[15:23:44.199] INFO: PixTest:: pg_setup set to default.
[15:23:44.200] INFO: 8 hot pixels found in step 4
[15:23:45.188] INFO: Collecting data for 5 seconds...
[15:23:50.204] INFO: Done with hot pixel readout
[15:24:01.748] INFO: PixTest:: pg_setup set to default.
[15:24:01.749] INFO: 7 hot pixels found in step 5
[15:24:02.738] INFO: Collecting data for 5 seconds...
[15:24:07.754] INFO: Done with hot pixel readout
[15:24:19.266] INFO: PixTest:: pg_setup set to default.
[15:24:19.267] INFO: 4 hot pixels found in step 6
[15:24:20.256] INFO: Collecting data for 5 seconds...
[15:24:25.271] INFO: Done with hot pixel readout
[15:24:36.714] INFO: PixTest:: pg_setup set to default.
[15:24:36.715] INFO: 4 hot pixels found in step 7
[15:24:37.704] INFO: Collecting data for 5 seconds...
[15:24:42.719] INFO: Done with hot pixel readout
[15:24:54.224] INFO: PixTest:: pg_setup set to default.
[15:24:54.225] INFO: 2 hot pixels found in step 8
[15:24:55.213] INFO: Collecting data for 5 seconds...
[15:25:00.229] INFO: Done with hot pixel readout
[15:25:11.756] INFO: PixTest:: pg_setup set to default.

[15:25:11.757] INFO: 3 hot pixels found in step 9
[15:25:12.746] INFO: Collecting data for 5 seconds...
[15:25:17.761] INFO: Done with hot pixel readout
[15:25:29.273] INFO: PixTest:: pg_setup set to default.

[15:25:29.274] INFO: 3 hot pixels found in step 10
[15:25:30.264] INFO: Collecting data for 5 seconds...
[15:25:35.279] INFO: Done with hot pixel readout
[15:25:46.772] INFO: PixTest:: pg_setup set to default.
[15:25:46.773] INFO: 1 hot pixels found in step 11
[15:25:47.763] INFO: Collecting data for 5 seconds...
[15:25:52.779] INFO: Done with hot pixel readout
[15:26:04.300] INFO: PixTest:: pg_setup set to default.
[15:26:04.301] INFO: 2 hot pixels found in step 12
[15:26:05.289] INFO: Collecting data for 5 seconds...
[15:26:10.305] INFO: Done with hot pixel readout
[15:26:21.777] INFO: PixTest:: pg_setup set to default.
[15:26:21.778] INFO: 1 hot pixels found in step 13
[15:26:22.766] INFO: Collecting data for 5 seconds...
[15:26:27.782] INFO: Done with hot pixel readout
[15:26:39.284] INFO: PixTest:: pg_setup set to default.
[15:26:39.285] INFO: 0 hot pixels found in step 14
[15:26:39.317] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:26:39.321] INFO: PixTest::trimHotPixels() done
[15:26:39.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C0.dat
[15:26:39.327] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C1.dat
[15:26:39.333] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C2.dat
[15:26:39.339] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C3.dat
[15:26:39.344] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C4.dat
[15:26:39.349] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C5.dat
[15:26:39.354] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C6.dat
[15:26:39.360] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C7.dat
[15:26:39.365] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C8.dat
[15:26:39.370] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C9.dat
[15:26:39.375] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C10.dat
[15:26:39.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C11.dat
[15:26:39.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C12.dat
[15:26:39.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C13.dat
[15:26:39.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C14.dat
[15:26:39.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C15.dat
[15:26:39.406] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//defaultMaskFile.dat
[15:26:39.417] INFO: enter test to run
[15:27:59.107] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:27:59.107] INFO: running: highrate
[15:27:59.112] INFO: ----------------------------------------------------------------------
[15:27:59.112] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:27:59.112] INFO: ----------------------------------------------------------------------
[15:27:59.112] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:27:59.112] INFO: edge/corner pixel THR is adjusted
[15:27:59.112] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:28:00.070] INFO: Collecting data for 1 seconds...
[15:28:01.073] INFO: Done with hot pixel readout
[15:28:04.942] INFO: PixTest:: pg_setup set to default.
[15:28:04.943] INFO: 0 hot pixels found in step 0
[15:28:04.948] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:28:05.046] INFO: PixTest::trimHotPixels() done
[15:28:05.046] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C0.dat
[15:28:05.055] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C1.dat
[15:28:05.061] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C2.dat
[15:28:05.066] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C3.dat
[15:28:05.071] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C4.dat
[15:28:05.076] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C5.dat
[15:28:05.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C6.dat
[15:28:05.086] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C7.dat
[15:28:05.091] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C8.dat
[15:28:05.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C9.dat
[15:28:05.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C10.dat
[15:28:05.107] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C11.dat
[15:28:05.112] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C12.dat
[15:28:05.117] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C13.dat
[15:28:05.122] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C14.dat
[15:28:05.127] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//trimParameters35_C15.dat
[15:28:05.133] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-33_FPIXTest-17C-FNAL-160610-1134_2016-06-10_11h34m_1465576476/000_FPIXTest_p17//defaultMaskFile.dat
[15:28:05.147] INFO: enter test to run
[15:28:27.667] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:28:27.667] INFO: running: xray
[15:28:27.668] INFO: ----------------------------------------------------------------------
[15:28:27.668] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:28:27.668] INFO: ----------------------------------------------------------------------
[15:28:28.632] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:28:40.335] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:29:09.574] INFO: Resuming triggers.
[15:29:21.274] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[15:29:50.588] INFO: Resuming triggers.
[15:30:02.292] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:30:31.592] INFO: Resuming triggers.
[15:30:43.300] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:31:12.443] INFO: Resuming triggers.
[15:31:24.153] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[15:31:53.400] INFO: Resuming triggers.
[15:32:05.103] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[15:32:34.407] INFO: Resuming triggers.
[15:32:46.108] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[15:33:15.450] INFO: Resuming triggers.
[15:33:27.154] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[15:33:56.418] INFO: Resuming triggers.
[15:34:03.099] INFO: data taking finished, elapsed time: 100 seconds.
[15:34:19.983] INFO: PixTest:: pg_setup set to default.
[15:34:19.986] INFO: PixTestXray::doPhRun() done
[15:34:20.146] INFO: enter test to run
[15:34:50.857] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:34:50.857] INFO: running: xray
[15:34:50.858] INFO: ----------------------------------------------------------------------
[15:34:50.858] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:34:50.858] INFO: ----------------------------------------------------------------------
[15:34:51.822] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:34:58.835] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:35:28.948] INFO: Resuming triggers.
[15:35:35.958] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:36:06.052] INFO: Resuming triggers.
[15:36:13.060] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[15:36:43.176] INFO: Resuming triggers.
[15:36:50.186] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[15:37:20.276] INFO: Resuming triggers.
[15:37:27.291] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:37:57.419] INFO: Resuming triggers.
[15:38:04.432] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:38:34.527] INFO: Resuming triggers.
[15:38:41.540] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[15:39:11.736] INFO: Resuming triggers.
[15:39:18.749] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:39:48.835] INFO: Resuming triggers.
[15:39:55.849] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[15:40:25.883] INFO: Resuming triggers.
[15:40:32.902] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:41:03.002] INFO: Resuming triggers.
[15:41:10.020] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[15:41:40.089] INFO: Resuming triggers.
[15:41:47.104] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:42:17.024] INFO: Resuming triggers.
[15:42:24.039] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:42:54.087] INFO: Resuming triggers.
[15:43:01.104] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[15:43:31.270] INFO: Resuming triggers.
[15:43:33.389] INFO: data taking finished, elapsed time: 100 seconds.
[15:43:42.781] INFO: PixTest:: pg_setup set to default.
[15:43:42.784] INFO: PixTestXray::doPhRun() done
[15:43:42.931] INFO: enter test to run
[15:48:06.587] INFO: test: HighRate no parameter change
[15:48:06.587] INFO: running: highrate
[15:48:06.588] INFO: ----------------------------------------------------------------------
[15:48:06.588] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:48:06.588] INFO: ----------------------------------------------------------------------
[15:48:06.731] INFO: Expecting 768 events.
[15:48:07.863] INFO: 768 events read in total (416ms).
[15:48:07.864] INFO: Test took 1267ms.
[15:48:08.667] INFO: Expecting 41600 events.
[15:48:11.705] INFO: 41600 events read in total (2512ms).
[15:48:11.706] INFO: Test took 3833ms.
[15:48:11.737] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:12.470] INFO: Expecting 41600 events.
[15:48:15.643] INFO: 41600 events read in total (2646ms).
[15:48:15.643] INFO: Test took 3889ms.
[15:48:15.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:16.400] INFO: Expecting 41600 events.
[15:48:19.603] INFO: 41600 events read in total (2676ms).
[15:48:19.604] INFO: Test took 3910ms.
[15:48:19.636] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:20.361] INFO: Expecting 41600 events.
[15:48:23.554] INFO: 41600 events read in total (2666ms).
[15:48:23.555] INFO: Test took 3901ms.
[15:48:23.587] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:24.315] INFO: Expecting 41600 events.
[15:48:27.528] INFO: 41600 events read in total (2686ms).
[15:48:27.528] INFO: Test took 3923ms.
[15:48:27.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:28.290] INFO: Expecting 41600 events.
[15:48:31.508] INFO: 41600 events read in total (2691ms).
[15:48:31.509] INFO: Test took 3931ms.
[15:48:31.541] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:32.268] INFO: Expecting 41600 events.
[15:48:35.482] INFO: 41600 events read in total (2687ms).
[15:48:35.483] INFO: Test took 3923ms.
[15:48:35.515] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:36.242] INFO: Expecting 41600 events.
[15:48:39.466] INFO: 41600 events read in total (2697ms).
[15:48:39.467] INFO: Test took 3934ms.
[15:48:39.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:40.228] INFO: Expecting 41600 events.
[15:48:43.437] INFO: 41600 events read in total (2682ms).
[15:48:43.438] INFO: Test took 3921ms.
[15:48:43.470] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:44.199] INFO: Expecting 41600 events.
[15:48:47.411] INFO: 41600 events read in total (2685ms).
[15:48:47.412] INFO: Test took 3924ms.
[15:48:47.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:48.174] INFO: Expecting 41600 events.
[15:48:51.394] INFO: 41600 events read in total (2693ms).
[15:48:51.395] INFO: Test took 3934ms.
[15:48:51.426] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:52.156] INFO: Expecting 41600 events.
[15:48:55.369] INFO: 41600 events read in total (2686ms).
[15:48:55.370] INFO: Test took 3926ms.
[15:48:55.402] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:56.132] INFO: Expecting 41600 events.
[15:48:59.340] INFO: 41600 events read in total (2681ms).
[15:48:59.341] INFO: Test took 3923ms.
[15:48:59.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:00.102] INFO: Expecting 41600 events.
[15:49:03.322] INFO: 41600 events read in total (2693ms).
[15:49:03.323] INFO: Test took 3933ms.
[15:49:03.354] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:04.084] INFO: Expecting 41600 events.
[15:49:07.295] INFO: 41600 events read in total (2684ms).
[15:49:07.296] INFO: Test took 3923ms.
[15:49:07.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:08.056] INFO: Expecting 41600 events.
[15:49:11.275] INFO: 41600 events read in total (2692ms).
[15:49:11.276] INFO: Test took 3931ms.
[15:49:11.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:12.033] INFO: Expecting 41600 events.
[15:49:15.249] INFO: 41600 events read in total (2689ms).
[15:49:15.249] INFO: Test took 3923ms.
[15:49:15.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:16.008] INFO: Expecting 41600 events.
[15:49:19.223] INFO: 41600 events read in total (2688ms).
[15:49:19.223] INFO: Test took 3923ms.
[15:49:19.255] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:19.985] INFO: Expecting 41600 events.
[15:49:23.182] INFO: 41600 events read in total (2670ms).
[15:49:23.183] INFO: Test took 3909ms.
[15:49:23.215] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:23.945] INFO: Expecting 41600 events.
[15:49:27.058] INFO: 41600 events read in total (2586ms).
[15:49:27.059] INFO: Test took 3826ms.
[15:49:27.090] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:27.463] INFO: enter test to run
[15:50:42.810] INFO: test: HighRate no parameter change
[15:50:42.810] INFO: running: highrate
[15:50:42.811] INFO: ----------------------------------------------------------------------
[15:50:42.811] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:50:42.811] INFO: ----------------------------------------------------------------------
[15:50:43.425] INFO: Expecting 208000 events.
[15:50:55.146] INFO: 208000 events read in total (11194ms).
[15:50:55.149] INFO: Test took 12327ms.
[15:50:55.281] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:50:55.530] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:50:55.530] INFO: number of red-efficiency pixels: 72 27 68 100 125 116 105 74 82 107 130 104 81 67 30 24
[15:50:55.530] INFO: number of X-ray hits detected: 56019 36876 61106 90721 96090 101448 103403 75743 80434 97185 96189 81582 80276 50260 19526 22349
[15:50:55.530] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:50:55.530] INFO: number of Vcal hits detected: 207925 207971 207932 207891 207870 207883 207891 207924 207918 207885 207868 207893 207919 207933 207970 207976
[15:50:55.531] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[15:50:55.531] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[15:50:55.531] INFO: X-ray hit rate [MHz/cm2]: 16.4 10.8 17.9 26.6 28.2 29.7 30.3 22.2 23.6 28.5 28.2 23.9 23.5 14.7 5.7 6.6
[15:50:55.531] INFO: PixTestHighRate::doXPixelAlive() done
[15:50:55.583] INFO: PixTest:: pg_setup set to default.
[15:50:55.598] INFO: enter test to run
[15:51:19.314] INFO: test: HighRate no parameter change
[15:51:19.314] INFO: running: highrate
[15:51:19.315] INFO: ----------------------------------------------------------------------
[15:51:19.315] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:51:19.315] INFO: ----------------------------------------------------------------------
[15:51:19.928] INFO: Expecting 208000 events.
[15:51:33.249] INFO: 208000 events read in total (12794ms).
[15:51:33.254] INFO: Test took 13929ms.
[15:51:33.527] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:33.821] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:51:33.821] INFO: number of red-efficiency pixels: 169 108 179 263 353 398 370 207 220 351 370 309 204 179 36 45
[15:51:33.821] INFO: number of X-ray hits detected: 116782 76164 126251 187899 198461 211660 213243 158056 168185 201406 199084 169695 167026 104750 40811 46591
[15:51:33.821] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:51:33.821] INFO: number of Vcal hits detected: 207823 207889 207810 207719 207619 207573 207606 207782 207772 207630 207605 207673 207787 207807 207964 207954
[15:51:33.821] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:51:33.821] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[15:51:33.821] INFO: X-ray hit rate [MHz/cm2]: 34.2 22.3 37.0 55.1 58.2 62.0 62.5 46.3 49.3 59.0 58.4 49.7 49.0 30.7 12.0 13.7
[15:51:33.821] INFO: PixTestHighRate::doXPixelAlive() done
[15:51:33.869] INFO: PixTest:: pg_setup set to default.
[15:51:33.883] INFO: enter test to run
[15:52:25.409] INFO: test: HighRate no parameter change
[15:52:25.409] INFO: running: highrate
[15:52:25.410] INFO: ----------------------------------------------------------------------
[15:52:25.410] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:52:25.410] INFO: ----------------------------------------------------------------------
[15:52:26.022] INFO: Expecting 208000 events.
[15:52:41.053] INFO: 208000 events read in total (14504ms).
[15:52:41.059] INFO: Test took 15637ms.
[15:52:41.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:52:41.801] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:52:41.801] INFO: number of red-efficiency pixels: 372 188 347 540 789 779 799 428 435 754 888 676 459 408 81 75
[15:52:41.801] INFO: number of X-ray hits detected: 175064 115447 189945 284564 299359 318696 321685 239075 254677 304135 300378 256028 249815 158771 61512 70946
[15:52:41.801] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:52:41.801] INFO: number of Vcal hits detected: 207564 207796 207606 207384 207090 207096 207037 207521 207529 207118 206938 207207 207496 207516 207914 207922
[15:52:41.801] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.6 99.6 99.8 99.8 99.6 99.5 99.7 99.8 99.8 100.0 100.0
[15:52:41.801] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.6 99.6 99.5 99.8 99.8 99.6 99.5 99.6 99.8 99.8 100.0 100.0
[15:52:41.801] INFO: X-ray hit rate [MHz/cm2]: 51.3 33.8 55.7 83.4 87.7 93.4 94.3 70.1 74.6 89.1 88.0 75.0 73.2 46.5 18.0 20.8
[15:52:41.801] INFO: PixTestHighRate::doXPixelAlive() done
[15:52:41.847] INFO: PixTest:: pg_setup set to default.
[15:52:41.862] INFO: enter test to run
[15:53:39.729] INFO: test: exit no parameter change
[15:53:40.071] QUIET: Connection to board 33 closed.
[15:53:40.072] INFO: pXar: this is the end, my friend