[14:03:09.948] INFO: *** Welcome to pxar ***
[14:03:09.948] INFO: *** Today: 2016/08/22
[14:03:11.209] INFO: *** Version: v1.9.0-818-g96727
[14:03:11.209] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//dacParameters35_C15.dat
[14:03:11.211] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:03:11.211] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//defaultMaskFile.dat
[14:03:11.211] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C15.dat
[14:03:11.284] INFO: clk: 4
[14:03:11.284] INFO: ctr: 4
[14:03:11.284] INFO: sda: 19
[14:03:11.284] INFO: tin: 9
[14:03:11.284] INFO: level: 15
[14:03:11.284] INFO: triggerdelay: 0
[14:03:11.284] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:03:11.284] INFO: Log level: INFO
[14:03:11.297] QUIET: Connection to board DTB_WREKRL opened.
[14:03:11.301] 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:03:11.304] INFO: RPC call hashes of host and DTB match: 398089610
[14:03:12.827] INFO: DUT info:
[14:03:12.827] INFO: The DUT currently contains the following objects:
[14:03:12.827] INFO: 2 TBM Cores tbm08c (2 ON)
[14:03:12.827] INFO: TBM Core alpha (0): 7 registers set
[14:03:12.827] INFO: TBM Core beta (1): 7 registers set
[14:03:12.827] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:03:12.827] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.827] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.828] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:12.828] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:13.231] INFO: enter 'restricted' command line mode
[14:03:13.231] INFO: enter test to run
[14:03:26.524] INFO: test: PixelAlive no parameter change
[14:03:26.524] INFO: running: pixelalive
[14:03:26.533] INFO: ----------------------------------------------------------------------
[14:03:26.533] 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:03:26.533] INFO: ----------------------------------------------------------------------
[14:03:26.849] INFO: Expecting 41600 events.
[14:03:31.176] INFO: 41600 events read in total (3609ms).
[14:03:31.341] INFO: Test took 4805ms.
[14:03:31.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:31.624] INFO: PixTestAlive::aliveTest() done
[14:03:31.624] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 1 0 0 0 0 0 0
[14:03:31.654] INFO: enter test to run
[14:04:14.636] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:04:14.636] INFO: running: highrate
[14:04:14.636] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:04:14.794] INFO: ----------------------------------------------------------------------
[14:04:14.794] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:04:14.794] INFO: ----------------------------------------------------------------------
[14:04:14.794] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:04:14.794] INFO: edge/corner pixel THR is adjusted
[14:04:14.794] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:04:15.754] INFO: Collecting data for 5 seconds...
[14:04:20.770] INFO: Done with hot pixel readout
[14:04:32.363] INFO: PixTest:: pg_setup set to default.
[14:04:32.363] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:32.363] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:32.364] INFO: 3 hot pixels found in step 0
[14:04:33.375] INFO: Collecting data for 5 seconds...
[14:04:38.392] INFO: Done with hot pixel readout
[14:04:49.714] INFO: PixTest:: pg_setup set to default.
[14:04:49.714] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:49.715] INFO: 2 hot pixels found in step 1
[14:04:50.706] INFO: Collecting data for 5 seconds...
[14:04:55.725] INFO: Done with hot pixel readout
[14:05:06.948] INFO: PixTest:: pg_setup set to default.
[14:05:06.948] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:06.948] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:06.948] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:06.948] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:06.949] INFO: 5 hot pixels found in step 2
[14:05:07.939] INFO: Collecting data for 5 seconds...
[14:05:12.956] INFO: Done with hot pixel readout
[14:05:24.292] INFO: PixTest:: pg_setup set to default.
[14:05:24.292] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:24.292] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:24.293] INFO: 3 hot pixels found in step 3
[14:05:25.283] INFO: Collecting data for 5 seconds...
[14:05:30.302] INFO: Done with hot pixel readout
[14:05:41.561] INFO: PixTest:: pg_setup set to default.
[14:05:41.561] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:41.561] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:41.562] INFO: 3 hot pixels found in step 4
[14:05:42.552] INFO: Collecting data for 5 seconds...
[14:05:47.569] INFO: Done with hot pixel readout
[14:05:58.764] INFO: PixTest:: pg_setup set to default.
[14:05:58.764] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:58.764] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:58.765] INFO: 4 hot pixels found in step 5
[14:05:59.756] INFO: Collecting data for 5 seconds...
[14:06:04.773] INFO: Done with hot pixel readout
[14:06:16.031] INFO: PixTest:: pg_setup set to default.
[14:06:16.032] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:16.032] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:16.032] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:16.032] INFO: 4 hot pixels found in step 6
[14:06:17.023] INFO: Collecting data for 5 seconds...
[14:06:22.041] INFO: Done with hot pixel readout
[14:06:33.395] INFO: PixTest:: pg_setup set to default.
[14:06:33.395] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:33.395] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:33.396] INFO: 2 hot pixels found in step 7
[14:06:33.431] INFO: 2 hot pixels could not be trimmed and have been masked.
[14:06:33.435] INFO: PixTest::trimHotPixels() done
[14:06:33.435] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C0.dat
[14:06:33.440] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C1.dat
[14:06:33.446] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C2.dat
[14:06:33.452] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C3.dat
[14:06:33.457] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C4.dat
[14:06:33.463] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C5.dat
[14:06:33.468] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C6.dat
[14:06:33.473] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C7.dat
[14:06:33.479] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C8.dat
[14:06:33.484] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C9.dat
[14:06:33.490] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C10.dat
[14:06:33.495] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C11.dat
[14:06:33.500] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C12.dat
[14:06:33.506] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C13.dat
[14:06:33.511] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C14.dat
[14:06:33.517] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C15.dat
[14:06:33.522] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//defaultMaskFile.dat
[14:06:33.532] INFO: enter test to run
[14:08:07.034] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:08:07.034] INFO: running: highrate
[14:08:07.039] INFO: ----------------------------------------------------------------------
[14:08:07.039] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:08:07.039] INFO: ----------------------------------------------------------------------
[14:08:07.039] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:08:07.039] INFO: edge/corner pixel THR is adjusted
[14:08:07.039] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:08:07.996] INFO: Collecting data for 1 seconds...
[14:08:08.000] INFO: Done with hot pixel readout
[14:08:13.198] INFO: PixTest:: pg_setup set to default.
[14:08:13.199] INFO: 0 hot pixels found in step 0
[14:08:13.204] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:08:13.286] INFO: PixTest::trimHotPixels() done
[14:08:13.286] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C0.dat
[14:08:13.298] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C1.dat
[14:08:13.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C2.dat
[14:08:13.315] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C3.dat
[14:08:13.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C4.dat
[14:08:13.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C5.dat
[14:08:13.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C6.dat
[14:08:13.337] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C7.dat
[14:08:13.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C8.dat
[14:08:13.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C9.dat
[14:08:13.353] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C10.dat
[14:08:13.358] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C11.dat
[14:08:13.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C12.dat
[14:08:13.368] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C13.dat
[14:08:13.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C14.dat
[14:08:13.379] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//trimParameters35_C15.dat
[14:08:13.384] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-6-45_FPIXTest-17C-FNAL-160817-1311-300V_2016-08-17_13h19m_1471457967/000_FPIXTest_p17//defaultMaskFile.dat
[14:08:13.394] INFO: enter test to run
[14:08:52.450] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:08:52.450] INFO: running: xray
[14:08:52.451] INFO: ----------------------------------------------------------------------
[14:08:52.451] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:08:52.451] INFO: ----------------------------------------------------------------------
[14:08:53.416] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:09:04.906] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:09:34.316] INFO: Resuming triggers.
[14:09:45.813] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:10:15.166] INFO: Resuming triggers.
[14:10:26.661] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:10:56.037] INFO: Resuming triggers.
[14:11:07.531] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:11:36.857] INFO: Resuming triggers.
[14:11:48.355] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:12:17.764] INFO: Resuming triggers.
[14:12:29.257] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:12:58.618] INFO: Resuming triggers.
[14:13:10.109] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[14:13:39.595] INFO: Resuming triggers.
[14:13:51.092] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:14:20.509] INFO: Resuming triggers.
[14:14:28.868] INFO: data taking finished, elapsed time: 100 seconds.
[14:14:50.423] INFO: PixTest:: pg_setup set to default.
[14:14:50.427] INFO: PixTestXray::doPhRun() done
[14:14:50.618] INFO: enter test to run
[14:15:28.807] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:15:28.807] INFO: running: xray
[14:15:28.808] INFO: ----------------------------------------------------------------------
[14:15:28.808] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:15:28.808] INFO: ----------------------------------------------------------------------
[14:15:29.773] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:15:36.423] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:16:06.551] INFO: Resuming triggers.
[14:16:13.198] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:16:43.335] INFO: Resuming triggers.
[14:16:49.987] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:17:20.701] INFO: Resuming triggers.
[14:17:27.348] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:17:57.852] INFO: Resuming triggers.
[14:18:04.505] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:18:35.096] INFO: Resuming triggers.
[14:18:41.748] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:19:12.969] INFO: Resuming triggers.
[14:19:19.618] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:19:51.049] INFO: Resuming triggers.
[14:19:57.702] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[14:20:28.925] INFO: Resuming triggers.
[14:20:35.579] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[14:21:05.653] INFO: Resuming triggers.
[14:21:12.309] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[14:21:42.372] INFO: Resuming triggers.
[14:21:49.028] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[14:22:19.144] INFO: Resuming triggers.
[14:22:25.799] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[14:22:55.998] INFO: Resuming triggers.
[14:23:02.652] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[14:23:32.758] INFO: Resuming triggers.
[14:23:39.410] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:24:09.498] INFO: Resuming triggers.
[14:24:16.148] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[14:24:46.185] INFO: Resuming triggers.
[14:24:46.750] INFO: data taking finished, elapsed time: 100 seconds.
[14:24:49.674] INFO: PixTest:: pg_setup set to default.
[14:24:49.677] INFO: PixTestXray::doPhRun() done
[14:24:49.827] INFO: enter test to run
[14:26:40.163] INFO: test: HighRate no parameter change
[14:26:40.163] INFO: running: highrate
[14:26:40.164] INFO: ----------------------------------------------------------------------
[14:26:40.164] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:26:40.164] INFO: ----------------------------------------------------------------------
[14:26:40.305] INFO: Expecting 768 events.
[14:26:41.439] INFO: 768 events read in total (418ms).
[14:26:41.440] INFO: Test took 1269ms.
[14:26:42.243] INFO: Expecting 41600 events.
[14:26:45.320] INFO: 41600 events read in total (2550ms).
[14:26:45.321] INFO: Test took 3874ms.
[14:26:45.355] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:46.083] INFO: Expecting 41600 events.
[14:26:49.287] INFO: 41600 events read in total (2677ms).
[14:26:49.288] INFO: Test took 3915ms.
[14:26:49.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:50.048] INFO: Expecting 41600 events.
[14:26:53.279] INFO: 41600 events read in total (2704ms).
[14:26:53.280] INFO: Test took 3939ms.
[14:26:53.314] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:54.038] INFO: Expecting 41600 events.
[14:26:57.286] INFO: 41600 events read in total (2721ms).
[14:26:57.287] INFO: Test took 3955ms.
[14:26:57.322] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:58.042] INFO: Expecting 41600 events.
[14:27:01.286] INFO: 41600 events read in total (2717ms).
[14:27:01.287] INFO: Test took 3946ms.
[14:27:01.321] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:02.045] INFO: Expecting 41600 events.
[14:27:05.291] INFO: 41600 events read in total (2720ms).
[14:27:05.292] INFO: Test took 3952ms.
[14:27:05.327] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:06.049] INFO: Expecting 41600 events.
[14:27:09.299] INFO: 41600 events read in total (2723ms).
[14:27:09.300] INFO: Test took 3954ms.
[14:27:09.335] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:10.056] INFO: Expecting 41600 events.
[14:27:13.309] INFO: 41600 events read in total (2726ms).
[14:27:13.310] INFO: Test took 3956ms.
[14:27:13.345] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:14.068] INFO: Expecting 41600 events.
[14:27:17.328] INFO: 41600 events read in total (2733ms).
[14:27:17.329] INFO: Test took 3965ms.
[14:27:17.364] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:18.086] INFO: Expecting 41600 events.
[14:27:21.337] INFO: 41600 events read in total (2724ms).
[14:27:21.338] INFO: Test took 3956ms.
[14:27:21.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:22.094] INFO: Expecting 41600 events.
[14:27:25.343] INFO: 41600 events read in total (2722ms).
[14:27:25.344] INFO: Test took 3953ms.
[14:27:25.378] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:26.100] INFO: Expecting 41600 events.
[14:27:29.355] INFO: 41600 events read in total (2728ms).
[14:27:29.356] INFO: Test took 3959ms.
[14:27:29.391] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:30.116] INFO: Expecting 41600 events.
[14:27:33.362] INFO: 41600 events read in total (2719ms).
[14:27:33.363] INFO: Test took 3952ms.
[14:27:33.398] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:34.123] INFO: Expecting 41600 events.
[14:27:37.372] INFO: 41600 events read in total (2722ms).
[14:27:37.373] INFO: Test took 3957ms.
[14:27:37.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:38.133] INFO: Expecting 41600 events.
[14:27:41.389] INFO: 41600 events read in total (2729ms).
[14:27:41.390] INFO: Test took 3964ms.
[14:27:41.425] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:42.149] INFO: Expecting 41600 events.
[14:27:45.409] INFO: 41600 events read in total (2733ms).
[14:27:45.410] INFO: Test took 3966ms.
[14:27:45.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:46.169] INFO: Expecting 41600 events.
[14:27:49.429] INFO: 41600 events read in total (2733ms).
[14:27:49.430] INFO: Test took 3967ms.
[14:27:49.465] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:50.188] INFO: Expecting 41600 events.
[14:27:53.391] INFO: 41600 events read in total (2677ms).
[14:27:53.392] INFO: Test took 3910ms.
[14:27:53.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:54.152] INFO: Expecting 41600 events.
[14:27:57.358] INFO: 41600 events read in total (2679ms).
[14:27:57.359] INFO: Test took 3913ms.
[14:27:57.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:58.117] INFO: Expecting 41600 events.
[14:28:01.196] INFO: 41600 events read in total (2553ms).
[14:28:01.198] INFO: Test took 3785ms.
[14:28:01.231] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:01.596] INFO: enter test to run
[14:28:48.274] INFO: test: HighRate no parameter change
[14:28:48.274] INFO: running: highrate
[14:28:48.275] INFO: ----------------------------------------------------------------------
[14:28:48.275] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:28:48.275] INFO: ----------------------------------------------------------------------
[14:28:48.893] INFO: Expecting 208000 events.
[14:29:00.796] INFO: 208000 events read in total (11376ms).
[14:29:00.799] INFO: Test took 12513ms.
[14:29:00.951] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:01.209] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 1 0 0 0 0 0 1
[14:29:01.209] INFO: number of red-efficiency pixels: 76 52 83 115 141 152 166 107 109 112 149 103 101 67 29 39
[14:29:01.209] INFO: number of X-ray hits detected: 62541 42419 72043 113254 117088 121427 122864 83083 71335 102745 101610 84539 87356 53868 22485 26723
[14:29:01.209] 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:29:01.209] INFO: number of Vcal hits detected: 207921 207948 207917 207835 207856 207844 207828 207891 207891 207835 207849 207896 207898 207932 207971 207911
[14:29:01.209] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:29:01.209] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[14:29:01.209] INFO: X-ray hit rate [MHz/cm2]: 18.3 12.4 21.1 33.2 34.3 35.6 36.0 24.4 20.9 30.1 29.8 24.8 25.6 15.8 6.6 7.8
[14:29:01.209] INFO: PixTestHighRate::doXPixelAlive() done
[14:29:01.256] INFO: PixTest:: pg_setup set to default.
[14:29:01.267] INFO: enter test to run
[14:29:27.474] INFO: test: HighRate no parameter change
[14:29:27.474] INFO: running: highrate
[14:29:27.475] INFO: ----------------------------------------------------------------------
[14:29:27.475] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:29:27.475] INFO: ----------------------------------------------------------------------
[14:29:28.107] INFO: Expecting 208000 events.
[14:29:41.726] INFO: 208000 events read in total (13092ms).
[14:29:41.731] INFO: Test took 14246ms.
[14:29:42.046] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:42.357] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 1 0 0 0 0 0 1
[14:29:42.357] INFO: number of red-efficiency pixels: 236 134 275 441 596 451 631 336 295 345 475 346 324 242 66 82
[14:29:42.357] INFO: number of X-ray hits detected: 129695 88665 149333 234855 243581 250768 253381 172005 147267 212576 211698 175630 181968 111314 46063 55376
[14:29:42.357] 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:29:42.357] INFO: number of Vcal hits detected: 207743 207861 207694 207480 207337 207516 207277 207635 207678 207569 207486 207625 207654 207744 207933 207868
[14:29:42.357] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:29:42.357] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.7 99.8 99.7 99.8 99.8 99.8 99.8 99.8 99.8 99.9 100.0 99.9
[14:29:42.357] INFO: X-ray hit rate [MHz/cm2]: 38.0 26.0 43.8 68.8 71.4 73.5 74.3 50.4 43.2 62.3 62.1 51.5 53.3 32.6 13.5 16.2
[14:29:42.357] INFO: PixTestHighRate::doXPixelAlive() done
[14:29:42.403] INFO: PixTest:: pg_setup set to default.
[14:29:42.422] INFO: enter test to run
[14:29:53.729] INFO: test: HighRate no parameter change
[14:29:53.729] INFO: running: highrate
[14:29:53.731] INFO: ----------------------------------------------------------------------
[14:29:53.731] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:29:53.731] INFO: ----------------------------------------------------------------------
[14:29:54.359] INFO: Expecting 208000 events.
[14:30:10.130] INFO: 208000 events read in total (15245ms).
[14:30:10.138] INFO: Test took 16398ms.
[14:30:10.635] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:10.001] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 1 0 0 0 0 0 1
[14:30:10.001] INFO: number of red-efficiency pixels: 458 300 649 1053 1412 1120 1572 725 640 850 1240 844 820 534 90 120
[14:30:10.001] INFO: number of X-ray hits detected: 200902 137077 230538 361851 378308 387922 392264 266571 229321 329024 328093 271260 280558 172875 72040 85734
[14:30:10.001] 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:30:10.001] INFO: number of Vcal hits detected: 207413 207665 207145 206647 206141 206575 205707 207049 207233 206933 206392 206940 207027 207334 207907 207825
[14:30:10.001] INFO: Vcal hit fiducial efficiency (%): 99.8 99.8 99.6 99.4 99.2 99.4 99.0 99.6 99.7 99.6 99.3 99.6 99.6 99.7 100.0 99.9
[14:30:10.001] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 99.3 99.1 99.3 98.9 99.5 99.6 99.5 99.2 99.5 99.5 99.7 100.0 99.9
[14:30:10.001] INFO: X-ray hit rate [MHz/cm2]: 58.9 40.2 67.6 106.1 110.9 113.7 115.0 78.1 67.2 96.4 96.2 79.5 82.2 50.7 21.1 25.1
[14:30:10.001] INFO: PixTestHighRate::doXPixelAlive() done
[14:30:11.047] INFO: PixTest:: pg_setup set to default.
[14:30:11.061] INFO: enter test to run
[14:30:29.161] INFO: test: exit no parameter change
[14:30:29.447] QUIET: Connection to board 33 closed.
[14:30:29.447] INFO: pXar: this is the end, my friend