[14:24:29.810] INFO: *** Welcome to pxar ***
[14:24:29.810] INFO: *** Today: 2016/04/20
[14:24:29.830] INFO: *** Version: v1.9.0-796-gef167-dirty
[14:24:29.830] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//dacParameters35_C15.dat
[14:24:29.830] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:24:29.830] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//defaultMaskFile.dat
[14:24:29.830] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C15.dat
[14:24:29.898] INFO: clk: 4
[14:24:29.898] INFO: ctr: 4
[14:24:29.898] INFO: sda: 19
[14:24:29.898] INFO: tin: 9
[14:24:29.898] INFO: level: 15
[14:24:29.898] INFO: triggerdelay: 0
[14:24:29.898] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[14:24:29.898] INFO: Log level: INFO
[14:24:29.915] QUIET: Connection to board DTB_WREKRL opened.
[14:24:29.918] 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:
------------------------------------------------------
[14:24:29.921] INFO: RPC call hashes of host and DTB match: 398089610
[14:24:31.447] INFO: DUT info:
[14:24:31.447] INFO: The DUT currently contains the following objects:
[14:24:31.447] INFO: 2 TBM Cores tbm08c (2 ON)
[14:24:31.447] INFO: TBM Core alpha (0): 7 registers set
[14:24:31.447] INFO: TBM Core beta (1): 7 registers set
[14:24:31.447] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:24:31.447] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.447] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:24:31.850] INFO: enter 'restricted' command line mode
[14:24:31.850] INFO: enter test to run
[14:24:50.863] INFO: test: PixelAlive no parameter change
[14:24:50.863] INFO: running: pixelalive
[14:24:50.872] INFO: ----------------------------------------------------------------------
[14:24:50.872] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:24:50.872] INFO: ----------------------------------------------------------------------
[14:24:51.192] INFO: Expecting 41600 events.
[14:24:55.518] INFO: 41600 events read in total (3607ms).
[14:24:55.684] INFO: Test took 4808ms.
[14:24:55.698] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:55.962] INFO: PixTestAlive::aliveTest() done
[14:24:55.962] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:24:55.993] INFO: enter test to run
[14:25:24.871] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:25:24.871] INFO: running: highrate
[14:25:24.871] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:25:25.025] INFO: ----------------------------------------------------------------------
[14:25:25.025] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:25:25.025] INFO: ----------------------------------------------------------------------
[14:25:25.025] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:25:25.025] INFO: edge/corner pixel THR is adjusted
[14:25:25.025] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:25:25.985] INFO: Collecting data for 5 seconds...
[14:25:30.002] INFO: Done with hot pixel readout
[14:25:42.831] INFO: PixTest:: pg_setup set to default.
[14:25:42.831] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:25:42.832] INFO: 4 hot pixels found in step 0
[14:25:43.844] INFO: Collecting data for 5 seconds...
[14:25:48.860] INFO: Done with hot pixel readout
[14:26:00.729] INFO: PixTest:: pg_setup set to default.
[14:26:00.729] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:26:00.730] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:26:00.731] INFO: 4 hot pixels found in step 1
[14:26:01.724] INFO: Collecting data for 5 seconds...
[14:26:06.740] INFO: Done with hot pixel readout
[14:26:18.608] INFO: PixTest:: pg_setup set to default.
[14:26:18.608] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:26:18.608] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:26:18.609] INFO: 5 hot pixels found in step 2
[14:26:19.602] INFO: Collecting data for 5 seconds...
[14:26:24.619] INFO: Done with hot pixel readout
[14:26:36.476] INFO: PixTest:: pg_setup set to default.
[14:26:36.476] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:26:36.476] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:26:36.477] INFO: 3 hot pixels found in step 3
[14:26:37.471] INFO: Collecting data for 5 seconds...
[14:26:42.488] INFO: Done with hot pixel readout
[14:26:54.382] INFO: PixTest:: pg_setup set to default.
[14:26:54.382] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:26:54.382] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:26:54.383] INFO: 3 hot pixels found in step 4
[14:26:55.375] INFO: Collecting data for 5 seconds...
[14:27:00.391] INFO: Done with hot pixel readout
[14:27:12.222] INFO: PixTest:: pg_setup set to default.
[14:27:12.222] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:27:12.222] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:27:12.222] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:27:12.223] INFO: 5 hot pixels found in step 5
[14:27:13.215] INFO: Collecting data for 5 seconds...
[14:27:18.231] INFO: Done with hot pixel readout
[14:27:30.090] INFO: PixTest:: pg_setup set to default.
[14:27:30.090] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:27:30.090] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:27:30.090] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:27:30.091] INFO: 3 hot pixels found in step 6
[14:27:30.127] INFO: 3 hot pixels could not be trimmed and have been masked.
[14:27:30.131] INFO: PixTest::trimHotPixels() done
[14:27:30.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C0.dat
[14:27:30.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C1.dat
[14:27:30.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C2.dat
[14:27:30.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C3.dat
[14:27:30.154] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C4.dat
[14:27:30.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C5.dat
[14:27:30.164] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C6.dat
[14:27:30.170] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C7.dat
[14:27:30.175] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C8.dat
[14:27:30.180] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C9.dat
[14:27:30.185] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C10.dat
[14:27:30.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C11.dat
[14:27:30.196] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C12.dat
[14:27:30.201] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C13.dat
[14:27:30.206] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C14.dat
[14:27:30.212] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C15.dat
[14:27:30.217] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//defaultMaskFile.dat
[14:27:30.227] INFO: enter test to run
[14:29:26.317] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:29:26.317] INFO: running: highrate
[14:29:26.321] INFO: ----------------------------------------------------------------------
[14:29:26.321] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:29:26.321] INFO: ----------------------------------------------------------------------
[14:29:26.321] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:29:26.321] INFO: edge/corner pixel THR is adjusted
[14:29:26.321] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:29:27.281] INFO: Collecting data for 1 seconds...
[14:29:28.284] INFO: Done with hot pixel readout
[14:29:32.320] INFO: PixTest:: pg_setup set to default.
[14:29:32.321] INFO: 0 hot pixels found in step 0
[14:29:32.326] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:29:32.414] INFO: PixTest::trimHotPixels() done
[14:29:32.414] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C0.dat
[14:29:32.426] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C1.dat
[14:29:32.433] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C2.dat
[14:29:32.439] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C3.dat
[14:29:32.444] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C4.dat
[14:29:32.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C5.dat
[14:29:32.454] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C6.dat
[14:29:32.460] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C7.dat
[14:29:32.465] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C8.dat
[14:29:32.470] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C9.dat
[14:29:32.475] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C10.dat
[14:29:32.481] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C11.dat
[14:29:32.486] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C12.dat
[14:29:32.491] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C13.dat
[14:29:32.497] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C14.dat
[14:29:32.502] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//trimParameters35_C15.dat
[14:29:32.507] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-M-1-19_FPIXTest-17C-FNAL-160415-1125_2016-04-15_11h26m_1460737568/000_FPIXTest_p17//defaultMaskFile.dat
[14:29:32.517] INFO: enter test to run
[14:30:04.581] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:30:04.581] INFO: running: xray
[14:30:04.582] INFO: ----------------------------------------------------------------------
[14:30:04.582] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:30:04.582] INFO: ----------------------------------------------------------------------
[14:30:05.545] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:30:17.199] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:30:46.599] INFO: Resuming triggers.
[14:30:58.254] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:31:25.558] INFO: Resuming triggers.
[14:31:37.216] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:32:06.544] INFO: Resuming triggers.
[14:32:18.200] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:32:47.501] INFO: Resuming triggers.
[14:32:59.157] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:33:28.513] INFO: Resuming triggers.
[14:33:40.169] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:34:09.498] INFO: Resuming triggers.
[14:34:21.154] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:34:50.507] INFO: Resuming triggers.
[14:35:02.167] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:35:31.498] INFO: Resuming triggers.
[14:35:38.561] INFO: data taking finished, elapsed time: 100 seconds.
[14:35:56.565] INFO: PixTest:: pg_setup set to default.
[14:35:56.568] INFO: PixTestXray::doPhRun() done
[14:35:56.740] INFO: enter test to run
[14:36:55.001] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:36:55.001] INFO: running: xray
[14:36:55.003] INFO: ----------------------------------------------------------------------
[14:36:55.003] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:36:55.003] INFO: ----------------------------------------------------------------------
[14:36:56.966] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:37:03.579] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:37:33.817] INFO: Resuming triggers.
[14:37:40.430] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:38:10.697] INFO: Resuming triggers.
[14:38:17.311] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:38:47.495] INFO: Resuming triggers.
[14:38:54.105] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:39:24.233] INFO: Resuming triggers.
[14:39:30.844] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:40:01.072] INFO: Resuming triggers.
[14:40:07.681] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:40:37.930] INFO: Resuming triggers.
[14:40:44.539] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:41:11.822] INFO: Resuming triggers.
[14:41:18.431] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:41:48.618] INFO: Resuming triggers.
[14:41:55.227] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:42:25.445] INFO: Resuming triggers.
[14:42:32.053] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:43:02.292] INFO: Resuming triggers.
[14:43:08.900] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:43:39.196] INFO: Resuming triggers.
[14:43:45.805] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:44:16.099] INFO: Resuming triggers.
[14:44:22.709] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:44:52.927] INFO: Resuming triggers.
[14:44:59.535] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:45:29.741] INFO: Resuming triggers.
[14:45:36.350] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:46:06.555] INFO: Resuming triggers.
[14:46:07.737] INFO: data taking finished, elapsed time: 100 seconds.
[14:46:13.469] INFO: PixTest:: pg_setup set to default.
[14:46:13.472] INFO: PixTestXray::doPhRun() done
[14:46:13.620] INFO: enter test to run
[14:48:11.101] INFO: test: HighRate no parameter change
[14:48:11.101] INFO: running: highrate
[14:48:11.102] INFO: ----------------------------------------------------------------------
[14:48:11.102] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:48:11.102] INFO: ----------------------------------------------------------------------
[14:48:11.242] INFO: Expecting 768 events.
[14:48:12.376] INFO: 768 events read in total (418ms).
[14:48:12.376] INFO: Test took 1269ms.
[14:48:13.180] INFO: Expecting 41600 events.
[14:48:16.307] INFO: 41600 events read in total (2600ms).
[14:48:16.308] INFO: Test took 3925ms.
[14:48:16.340] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:17.066] INFO: Expecting 41600 events.
[14:48:20.269] INFO: 41600 events read in total (2676ms).
[14:48:20.269] INFO: Test took 3913ms.
[14:48:20.302] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:21.027] INFO: Expecting 41600 events.
[14:48:24.239] INFO: 41600 events read in total (2685ms).
[14:48:24.239] INFO: Test took 3921ms.
[14:48:24.272] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:24.997] INFO: Expecting 41600 events.
[14:48:28.215] INFO: 41600 events read in total (2691ms).
[14:48:28.216] INFO: Test took 3927ms.
[14:48:28.248] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:28.976] INFO: Expecting 41600 events.
[14:48:32.189] INFO: 41600 events read in total (2686ms).
[14:48:32.190] INFO: Test took 3924ms.
[14:48:32.223] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:32.951] INFO: Expecting 41600 events.
[14:48:36.194] INFO: 41600 events read in total (2716ms).
[14:48:36.195] INFO: Test took 3954ms.
[14:48:36.228] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:36.954] INFO: Expecting 41600 events.
[14:48:40.177] INFO: 41600 events read in total (2697ms).
[14:48:40.178] INFO: Test took 3933ms.
[14:48:40.210] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:40.937] INFO: Expecting 41600 events.
[14:48:44.163] INFO: 41600 events read in total (2699ms).
[14:48:44.164] INFO: Test took 3936ms.
[14:48:44.197] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:44.923] INFO: Expecting 41600 events.
[14:48:48.155] INFO: 41600 events read in total (2705ms).
[14:48:48.156] INFO: Test took 3941ms.
[14:48:48.189] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:48.913] INFO: Expecting 41600 events.
[14:48:52.141] INFO: 41600 events read in total (2702ms).
[14:48:52.142] INFO: Test took 3935ms.
[14:48:52.175] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:52.900] INFO: Expecting 41600 events.
[14:48:56.128] INFO: 41600 events read in total (2701ms).
[14:48:56.129] INFO: Test took 3936ms.
[14:48:56.161] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:48:56.890] INFO: Expecting 41600 events.
[14:49:00.112] INFO: 41600 events read in total (2695ms).
[14:49:00.113] INFO: Test took 3935ms.
[14:49:00.146] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:00.873] INFO: Expecting 41600 events.
[14:49:04.107] INFO: 41600 events read in total (2708ms).
[14:49:04.108] INFO: Test took 3944ms.
[14:49:04.141] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:04.867] INFO: Expecting 41600 events.
[14:49:08.103] INFO: 41600 events read in total (2709ms).
[14:49:08.104] INFO: Test took 3946ms.
[14:49:08.136] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:08.864] INFO: Expecting 41600 events.
[14:49:12.100] INFO: 41600 events read in total (2709ms).
[14:49:12.101] INFO: Test took 3947ms.
[14:49:12.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:12.863] INFO: Expecting 41600 events.
[14:49:16.083] INFO: 41600 events read in total (2694ms).
[14:49:16.084] INFO: Test took 3932ms.
[14:49:16.117] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:16.843] INFO: Expecting 41600 events.
[14:49:20.067] INFO: 41600 events read in total (2697ms).
[14:49:20.068] INFO: Test took 3932ms.
[14:49:20.101] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:20.827] INFO: Expecting 41600 events.
[14:49:24.053] INFO: 41600 events read in total (2699ms).
[14:49:24.054] INFO: Test took 3935ms.
[14:49:24.086] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:24.815] INFO: Expecting 41600 events.
[14:49:28.023] INFO: 41600 events read in total (2681ms).
[14:49:28.024] INFO: Test took 3920ms.
[14:49:28.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:28.786] INFO: Expecting 41600 events.
[14:49:31.873] INFO: 41600 events read in total (2560ms).
[14:49:31.874] INFO: Test took 3799ms.
[14:49:31.905] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:32.272] INFO: enter test to run
[14:49:43.356] INFO: test: HighRate no parameter change
[14:49:43.356] INFO: running: highrate
[14:49:43.357] INFO: ----------------------------------------------------------------------
[14:49:43.357] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:49:43.357] INFO: ----------------------------------------------------------------------
[14:49:43.977] INFO: Expecting 208000 events.
[14:49:55.807] INFO: 208000 events read in total (11303ms).
[14:49:55.810] INFO: Test took 12442ms.
[14:49:55.947] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:49:56.197] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:49:56.197] INFO: number of red-efficiency pixels: 66 41 72 143 145 122 118 98 88 108 110 94 107 72 19 26
[14:49:56.197] INFO: number of X-ray hits detected: 61144 40377 63176 101512 105813 108503 107512 74825 75959 90983 92070 81201 85053 50859 22471 27253
[14:49:56.197] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:49:56.197] INFO: number of Vcal hits detected: 207933 207959 207927 207852 207849 207875 207878 207899 207910 207891 207887 207906 207892 207926 207981 207973
[14:49:56.197] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[14:49:56.197] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:49:56.197] INFO: X-ray hit rate [MHz/cm2]: 17.9 11.8 18.5 29.8 31.0 31.8 31.5 21.9 22.3 26.7 27.0 23.8 24.9 14.9 6.6 8.0
[14:49:56.197] INFO: PixTestHighRate::doXPixelAlive() done
[14:49:56.247] INFO: PixTest:: pg_setup set to default.
[14:49:56.260] INFO: enter test to run
[14:50:26.403] INFO: test: HighRate no parameter change
[14:50:26.404] INFO: running: highrate
[14:50:26.405] INFO: ----------------------------------------------------------------------
[14:50:26.405] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:50:26.405] INFO: ----------------------------------------------------------------------
[14:50:27.022] INFO: Expecting 208000 events.
[14:50:40.477] INFO: 208000 events read in total (12928ms).
[14:50:40.482] INFO: Test took 14067ms.
[14:50:40.775] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:50:41.076] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:50:41.076] INFO: number of red-efficiency pixels: 232 120 235 460 515 403 429 326 262 348 393 255 286 204 60 80
[14:50:41.076] INFO: number of X-ray hits detected: 131172 86638 134462 217619 227519 230603 232934 162128 162530 194458 197840 174366 182015 109995 48302 59019
[14:50:41.076] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:50:41.076] INFO: number of Vcal hits detected: 207754 207875 207742 207509 207433 207567 207540 207651 207722 207626 207576 207732 207703 207782 207937 207918
[14:50:41.076] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:50:41.076] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:50:41.076] INFO: X-ray hit rate [MHz/cm2]: 38.4 25.4 39.4 63.8 66.7 67.6 68.3 47.5 47.6 57.0 58.0 51.1 53.3 32.2 14.2 17.3
[14:50:41.076] INFO: PixTestHighRate::doXPixelAlive() done
[14:50:41.123] INFO: PixTest:: pg_setup set to default.
[14:50:41.135] INFO: enter test to run
[14:50:56.699] INFO: test: HighRate no parameter change
[14:50:56.699] INFO: running: highrate
[14:50:56.700] INFO: ----------------------------------------------------------------------
[14:50:56.700] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:50:56.700] INFO: ----------------------------------------------------------------------
[14:50:57.319] INFO: Expecting 208000 events.
[14:51:10.986] INFO: 208000 events read in total (13140ms).
[14:51:10.993] INFO: Test took 14284ms.
[14:51:11.462] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:51:11.815] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:51:11.815] INFO: number of red-efficiency pixels: 505 199 627 1156 1348 949 1098 815 644 862 938 582 552 460 111 111
[14:51:11.815] INFO: number of X-ray hits detected: 202482 135219 208235 336466 350205 356584 359033 249672 252159 302242 304203 270149 281408 170250 75430 91626
[14:51:11.815] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:51:11.815] INFO: number of Vcal hits detected: 207387 207791 207192 206551 206232 206853 206602 206955 207267 206981 206872 207355 207378 207454 207886 207885
[14:51:11.815] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.4 99.2 99.5 99.4 99.5 99.7 99.6 99.5 99.7 99.7 99.8 99.9 99.9
[14:51:11.815] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.3 99.2 99.4 99.3 99.5 99.6 99.5 99.5 99.7 99.7 99.7 99.9 99.9
[14:51:11.815] INFO: X-ray hit rate [MHz/cm2]: 59.3 39.6 61.0 98.6 102.6 104.5 105.2 73.2 73.9 88.6 89.2 79.2 82.5 49.9 22.1 26.9
[14:51:11.815] INFO: PixTestHighRate::doXPixelAlive() done
[14:51:11.859] INFO: PixTest:: pg_setup set to default.
[14:51:11.869] INFO: enter test to run
[14:51:16.715] INFO: test: exit no parameter change
[14:51:17.032] QUIET: Connection to board 33 closed.
[14:51:17.034] INFO: pXar: this is the end, my friend