[13:54:15.605] INFO: *** Welcome to pxar ***
[13:54:15.605] INFO: *** Today: 2016/07/06
[13:54:15.740] INFO: *** Version: v1.9.0-814-g7497
[13:54:15.740] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//dacParameters35_C15.dat
[13:54:15.741] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:54:15.741] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//defaultMaskFile.dat
[13:54:15.741] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C15.dat
[13:54:15.807] INFO: clk: 4
[13:54:15.808] INFO: ctr: 4
[13:54:15.808] INFO: sda: 19
[13:54:15.808] INFO: tin: 9
[13:54:15.808] INFO: level: 15
[13:54:15.808] INFO: triggerdelay: 0
[13:54:15.808] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:54:15.808] INFO: Log level: INFO
[13:54:15.822] QUIET: Connection to board DTB_WREKRL opened.
[13:54:15.826] 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:
------------------------------------------------------
[13:54:15.829] INFO: RPC call hashes of host and DTB match: 398089610
[13:54:17.356] INFO: DUT info:
[13:54:17.356] INFO: The DUT currently contains the following objects:
[13:54:17.356] INFO: 2 TBM Cores tbm08c (2 ON)
[13:54:17.356] INFO: TBM Core alpha (0): 7 registers set
[13:54:17.356] INFO: TBM Core beta (1): 7 registers set
[13:54:17.356] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:54:17.356] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.356] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.356] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.356] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.356] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.357] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:54:17.760] INFO: enter 'restricted' command line mode
[13:54:17.760] INFO: enter test to run
[13:54:23.463] INFO: test: PixelAlive no parameter change
[13:54:23.464] INFO: running: pixelalive
[13:54:23.515] INFO: ----------------------------------------------------------------------
[13:54:23.515] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[13:54:23.515] INFO: ----------------------------------------------------------------------
[13:54:23.839] INFO: Expecting 41600 events.
[13:54:28.215] INFO: 41600 events read in total (3658ms).
[13:54:28.383] INFO: Test took 4864ms.
[13:54:28.396] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:54:28.676] INFO: PixTestAlive::aliveTest() done
[13:54:28.676] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:54:28.788] INFO: enter test to run
[13:56:07.471] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:56:07.471] INFO: running: highrate
[13:56:07.493] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:56:07.648] INFO: ----------------------------------------------------------------------
[13:56:07.649] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:56:07.649] INFO: ----------------------------------------------------------------------
[13:56:07.649] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:56:07.666] INFO: edge/corner pixel THR is adjusted
[13:56:07.666] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:56:08.625] INFO: Collecting data for 5 seconds...
[13:56:13.642] INFO: Done with hot pixel readout
[13:56:25.403] INFO: PixTest:: pg_setup set to default.
[13:56:25.404] INFO: 12 hot pixels found in step 0
[13:56:26.391] INFO: Collecting data for 5 seconds...
[13:56:31.411] INFO: Done with hot pixel readout
[13:56:43.386] INFO: PixTest:: pg_setup set to default.
[13:56:43.387] INFO: 11 hot pixels found in step 1
[13:56:44.379] INFO: Collecting data for 5 seconds...
[13:56:49.396] INFO: Done with hot pixel readout
[13:57:00.997] INFO: PixTest:: pg_setup set to default.
[13:57:00.998] INFO: 8 hot pixels found in step 2
[13:57:01.989] INFO: Collecting data for 5 seconds...
[13:57:07.010] INFO: Done with hot pixel readout
[13:57:18.997] INFO: PixTest:: pg_setup set to default.
[13:57:18.997] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:18.997] INFO: 9 hot pixels found in step 3
[13:57:19.989] INFO: Collecting data for 5 seconds...
[13:57:25.007] INFO: Done with hot pixel readout
[13:57:36.848] INFO: PixTest:: pg_setup set to default.
[13:57:36.848] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:36.849] INFO: 10 hot pixels found in step 4
[13:57:37.839] INFO: Collecting data for 5 seconds...
[13:57:42.856] INFO: Done with hot pixel readout
[13:57:54.396] INFO: PixTest:: pg_setup set to default.
[13:57:54.396] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:57:54.397] INFO: 10 hot pixels found in step 5
[13:57:55.388] INFO: Collecting data for 5 seconds...
[13:58:00.404] INFO: Done with hot pixel readout
[13:58:11.952] INFO: PixTest:: pg_setup set to default.
[13:58:11.953] INFO: 6 hot pixels found in step 6
[13:58:12.943] INFO: Collecting data for 5 seconds...
[13:58:17.959] INFO: Done with hot pixel readout
[13:58:29.531] INFO: PixTest:: pg_setup set to default.
[13:58:29.531] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:58:29.532] INFO: 7 hot pixels found in step 7
[13:58:30.523] INFO: Collecting data for 5 seconds...
[13:58:35.539] INFO: Done with hot pixel readout
[13:58:47.123] INFO: PixTest:: pg_setup set to default.
[13:58:47.124] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:58:47.124] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:58:47.124] INFO: 3 hot pixels found in step 8
[13:58:48.115] INFO: Collecting data for 5 seconds...
[13:58:53.132] INFO: Done with hot pixel readout
[13:59:04.629] INFO: PixTest:: pg_setup set to default.
[13:59:04.629] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:59:04.630] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:59:04.630] INFO: 5 hot pixels found in step 9
[13:59:05.621] INFO: Collecting data for 5 seconds...
[13:59:10.637] INFO: Done with hot pixel readout
[13:59:22.170] INFO: PixTest:: pg_setup set to default.
[13:59:22.170] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:59:22.171] INFO: 6 hot pixels found in step 10
[13:59:23.162] INFO: Collecting data for 5 seconds...
[13:59:28.179] INFO: Done with hot pixel readout
[13:59:39.719] INFO: PixTest:: pg_setup set to default.
[13:59:39.719] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:59:39.719] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:59:39.719] INFO: 5 hot pixels found in step 11
[13:59:40.714] INFO: Collecting data for 5 seconds...
[13:59:45.730] INFO: Done with hot pixel readout
[13:59:57.240] INFO: PixTest:: pg_setup set to default.
[13:59:57.240] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:59:57.240] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:59:57.240] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[13:59:57.241] INFO: 3 hot pixels found in step 12
[13:59:57.275] INFO: 3 hot pixels could not be trimmed and have been masked.
[13:59:57.279] INFO: PixTest::trimHotPixels() done
[13:59:57.279] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C0.dat
[13:59:57.300] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C1.dat
[13:59:57.305] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C2.dat
[13:59:57.310] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C3.dat
[13:59:57.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C4.dat
[13:59:57.321] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C5.dat
[13:59:57.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C6.dat
[13:59:57.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C7.dat
[13:59:57.338] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C8.dat
[13:59:57.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C9.dat
[13:59:57.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C10.dat
[13:59:57.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C11.dat
[13:59:57.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C12.dat
[13:59:57.391] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C13.dat
[13:59:57.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C14.dat
[13:59:57.402] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C15.dat
[13:59:57.407] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//defaultMaskFile.dat
[13:59:57.423] INFO: enter test to run
[14:00:27.413] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:00:27.413] INFO: running: highrate
[14:00:27.417] INFO: ----------------------------------------------------------------------
[14:00:27.417] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:00:27.417] INFO: ----------------------------------------------------------------------
[14:00:27.417] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:00:27.418] INFO: edge/corner pixel THR is adjusted
[14:00:27.418] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:00:28.376] INFO: Collecting data for 1 seconds...
[14:00:29.379] INFO: Done with hot pixel readout
[14:00:33.234] INFO: PixTest:: pg_setup set to default.
[14:00:33.235] INFO: 0 hot pixels found in step 0
[14:00:33.240] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:00:33.333] INFO: PixTest::trimHotPixels() done
[14:00:33.333] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C0.dat
[14:00:33.341] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C1.dat
[14:00:33.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C2.dat
[14:00:33.352] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C3.dat
[14:00:33.358] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C4.dat
[14:00:33.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C5.dat
[14:00:33.369] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C6.dat
[14:00:33.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C7.dat
[14:00:33.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C8.dat
[14:00:33.385] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C9.dat
[14:00:33.390] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C10.dat
[14:00:33.396] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C11.dat
[14:00:33.401] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C12.dat
[14:00:33.407] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C13.dat
[14:00:33.412] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C14.dat
[14:00:33.418] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//trimParameters35_C15.dat
[14:00:33.423] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-06_FPIXTest-17C-FNAL-160705-1225_2016-07-05_12h25m_1467739507/000_FPIXTest_p17//defaultMaskFile.dat
[14:00:33.432] INFO: enter test to run
[14:02:04.276] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:02:04.276] INFO: running: xray
[14:02:04.346] INFO: ----------------------------------------------------------------------
[14:02:04.346] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:02:04.346] INFO: ----------------------------------------------------------------------
[14:02:05.331] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:02:16.989] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:02:46.235] INFO: Resuming triggers.
[14:02:57.902] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:03:27.865] INFO: Resuming triggers.
[14:03:39.533] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:04:09.665] INFO: Resuming triggers.
[14:04:21.330] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:04:51.608] INFO: Resuming triggers.
[14:05:03.277] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:05:32.576] INFO: Resuming triggers.
[14:05:44.241] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:06:13.527] INFO: Resuming triggers.
[14:06:25.195] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:06:54.566] INFO: Resuming triggers.
[14:07:06.229] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:07:35.446] INFO: Resuming triggers.
[14:07:42.474] INFO: data taking finished, elapsed time: 100 seconds.
[14:08:00.961] INFO: PixTest:: pg_setup set to default.
[14:08:00.964] INFO: PixTestXray::doPhRun() done
[14:08:01.770] INFO: enter test to run
[14:08:20.954] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:08:20.954] INFO: running: xray
[14:08:20.955] INFO: ----------------------------------------------------------------------
[14:08:20.955] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:08:20.955] INFO: ----------------------------------------------------------------------
[14:08:21.918] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:08:28.926] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:09:00.111] INFO: Resuming triggers.
[14:09:07.117] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:09:38.080] INFO: Resuming triggers.
[14:09:45.089] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:10:15.132] INFO: Resuming triggers.
[14:10:22.145] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:10:52.415] INFO: Resuming triggers.
[14:10:59.427] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:11:29.658] INFO: Resuming triggers.
[14:11:36.668] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[14:12:06.858] INFO: Resuming triggers.
[14:12:13.869] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[14:12:44.026] INFO: Resuming triggers.
[14:12:51.037] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:13:21.203] INFO: Resuming triggers.
[14:13:28.215] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[14:13:58.965] INFO: Resuming triggers.
[14:14:05.975] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:14:36.706] INFO: Resuming triggers.
[14:14:43.718] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[14:15:14.532] INFO: Resuming triggers.
[14:15:21.544] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[14:15:52.355] INFO: Resuming triggers.
[14:15:59.366] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[14:16:30.149] INFO: Resuming triggers.
[14:16:37.162] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[14:17:09.068] INFO: Resuming triggers.
[14:17:11.267] INFO: data taking finished, elapsed time: 100 seconds.
[14:17:21.471] INFO: PixTest:: pg_setup set to default.
[14:17:21.474] INFO: PixTestXray::doPhRun() done
[14:17:21.625] INFO: enter test to run
[14:18:29.677] INFO: test: HighRate no parameter change
[14:18:29.677] INFO: running: highrate
[14:18:29.698] INFO: ----------------------------------------------------------------------
[14:18:29.698] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:18:29.698] INFO: ----------------------------------------------------------------------
[14:18:29.862] INFO: Expecting 768 events.
[14:18:30.996] INFO: 768 events read in total (419ms).
[14:18:30.997] INFO: Test took 1270ms.
[14:18:31.800] INFO: Expecting 41600 events.
[14:18:34.843] INFO: 41600 events read in total (2516ms).
[14:18:34.844] INFO: Test took 3813ms.
[14:18:34.874] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:35.608] INFO: Expecting 41600 events.
[14:18:38.758] INFO: 41600 events read in total (2623ms).
[14:18:38.759] INFO: Test took 3867ms.
[14:18:38.792] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:39.522] INFO: Expecting 41600 events.
[14:18:42.729] INFO: 41600 events read in total (2680ms).
[14:18:42.730] INFO: Test took 3922ms.
[14:18:42.762] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:43.487] INFO: Expecting 41600 events.
[14:18:46.692] INFO: 41600 events read in total (2679ms).
[14:18:46.693] INFO: Test took 3914ms.
[14:18:46.725] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:47.455] INFO: Expecting 41600 events.
[14:18:50.675] INFO: 41600 events read in total (2693ms).
[14:18:50.675] INFO: Test took 3934ms.
[14:18:50.707] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:51.436] INFO: Expecting 41600 events.
[14:18:54.659] INFO: 41600 events read in total (2696ms).
[14:18:54.660] INFO: Test took 3934ms.
[14:18:54.692] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:55.421] INFO: Expecting 41600 events.
[14:18:58.655] INFO: 41600 events read in total (2707ms).
[14:18:58.656] INFO: Test took 3947ms.
[14:18:58.689] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:18:59.416] INFO: Expecting 41600 events.
[14:19:02.636] INFO: 41600 events read in total (2693ms).
[14:19:02.637] INFO: Test took 3931ms.
[14:19:02.669] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:03.394] INFO: Expecting 41600 events.
[14:19:06.619] INFO: 41600 events read in total (2698ms).
[14:19:06.620] INFO: Test took 3934ms.
[14:19:06.652] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:07.376] INFO: Expecting 41600 events.
[14:19:10.604] INFO: 41600 events read in total (2701ms).
[14:19:10.605] INFO: Test took 3935ms.
[14:19:10.636] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:11.363] INFO: Expecting 41600 events.
[14:19:14.579] INFO: 41600 events read in total (2689ms).
[14:19:14.580] INFO: Test took 3927ms.
[14:19:14.612] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:15.341] INFO: Expecting 41600 events.
[14:19:18.526] INFO: 41600 events read in total (2658ms).
[14:19:18.527] INFO: Test took 3898ms.
[14:19:18.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:19.289] INFO: Expecting 41600 events.
[14:19:22.511] INFO: 41600 events read in total (2695ms).
[14:19:22.512] INFO: Test took 3935ms.
[14:19:22.544] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:23.273] INFO: Expecting 41600 events.
[14:19:26.491] INFO: 41600 events read in total (2691ms).
[14:19:26.492] INFO: Test took 3930ms.
[14:19:26.524] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:27.249] INFO: Expecting 41600 events.
[14:19:30.464] INFO: 41600 events read in total (2688ms).
[14:19:30.465] INFO: Test took 3924ms.
[14:19:30.498] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:31.223] INFO: Expecting 41600 events.
[14:19:34.460] INFO: 41600 events read in total (2710ms).
[14:19:34.461] INFO: Test took 3945ms.
[14:19:34.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:35.219] INFO: Expecting 41600 events.
[14:19:38.536] INFO: 41600 events read in total (2791ms).
[14:19:38.537] INFO: Test took 4027ms.
[14:19:38.571] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:39.286] INFO: Expecting 41600 events.
[14:19:42.541] INFO: 41600 events read in total (2728ms).
[14:19:42.542] INFO: Test took 3951ms.
[14:19:42.576] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:43.295] INFO: Expecting 41600 events.
[14:19:46.544] INFO: 41600 events read in total (2722ms).
[14:19:46.545] INFO: Test took 3952ms.
[14:19:46.578] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:47.300] INFO: Expecting 41600 events.
[14:19:50.450] INFO: 41600 events read in total (2623ms).
[14:19:50.451] INFO: Test took 3856ms.
[14:19:50.491] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:19:50.842] INFO: enter test to run
[14:21:48.844] INFO: test: HighRate no parameter change
[14:21:48.844] INFO: running: highrate
[14:21:48.845] INFO: ----------------------------------------------------------------------
[14:21:48.845] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:21:48.845] INFO: ----------------------------------------------------------------------
[14:21:49.462] INFO: Expecting 208000 events.
[14:22:01.245] INFO: 208000 events read in total (11256ms).
[14:22:01.248] INFO: Test took 12394ms.
[14:22:01.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:22:01.631] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:22:01.631] INFO: number of red-efficiency pixels: 80 44 74 101 108 123 104 89 89 131 110 122 83 64 17 18
[14:22:01.631] INFO: number of X-ray hits detected: 62109 39591 52344 85908 94997 100377 102358 80372 82403 99194 101684 85314 86610 50348 18656 20101
[14:22:01.631] 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:22:01.631] INFO: number of Vcal hits detected: 207919 207956 207924 207897 207891 207875 207887 207909 207911 207863 207888 207877 207916 207936 207983 207982
[14:22:01.631] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[14:22:01.631] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 100.0 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[14:22:01.631] INFO: X-ray hit rate [MHz/cm2]: 18.2 11.6 15.3 25.2 27.8 29.4 30.0 23.6 24.2 29.1 29.8 25.0 25.4 14.8 5.5 5.9
[14:22:01.631] INFO: PixTestHighRate::doXPixelAlive() done
[14:22:01.680] INFO: PixTest:: pg_setup set to default.
[14:22:01.695] INFO: enter test to run
[14:24:02.752] INFO: test: HighRate no parameter change
[14:24:02.752] INFO: running: highrate
[14:24:02.753] INFO: ----------------------------------------------------------------------
[14:24:02.753] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:24:02.753] INFO: ----------------------------------------------------------------------
[14:24:03.368] INFO: Expecting 208000 events.
[14:24:16.704] INFO: 208000 events read in total (12809ms).
[14:24:16.709] INFO: Test took 13945ms.
[14:24:16.975] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:24:17.269] 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:17.269] INFO: number of red-efficiency pixels: 239 113 203 324 296 349 359 250 294 405 343 332 337 172 47 47
[14:24:17.269] INFO: number of X-ray hits detected: 128923 81139 107994 177501 195824 205070 210408 165712 168715 203300 207756 175887 179055 103136 38697 41704
[14:24:17.269] 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:24:17.269] INFO: number of Vcal hits detected: 207745 207885 207779 207665 207689 207635 207614 207741 207682 207568 207639 207646 207647 207822 207953 207952
[14:24:17.269] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.9 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:24:17.269] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.9 99.8 99.8 99.9 99.8 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:24:17.269] INFO: X-ray hit rate [MHz/cm2]: 37.8 23.8 31.7 52.0 57.4 60.1 61.7 48.6 49.5 59.6 60.9 51.6 52.5 30.2 11.3 12.2
[14:24:17.269] INFO: PixTestHighRate::doXPixelAlive() done
[14:24:17.326] INFO: PixTest:: pg_setup set to default.
[14:24:17.344] INFO: enter test to run
[14:25:59.883] INFO: test: HighRate no parameter change
[14:25:59.883] INFO: running: highrate
[14:25:59.884] INFO: ----------------------------------------------------------------------
[14:25:59.884] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:25:59.884] INFO: ----------------------------------------------------------------------
[14:26:00.500] INFO: Expecting 208000 events.
[14:26:15.560] INFO: 208000 events read in total (14533ms).
[14:26:15.567] INFO: Test took 15672ms.
[14:26:15.963] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:16.296] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:26:16.296] INFO: number of red-efficiency pixels: 457 221 427 688 614 798 802 546 634 980 741 757 696 379 78 77
[14:26:16.296] INFO: number of X-ray hits detected: 193547 122923 162722 267191 295602 310620 316921 249184 255114 305452 314840 264396 269298 155227 58352 62864
[14:26:16.296] 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:26:16.296] INFO: number of Vcal hits detected: 207420 207763 207510 207205 207295 207071 207052 207372 207265 206814 207131 207090 207218 207565 207918 207920
[14:26:16.296] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.7 99.6 99.6 99.7 99.7 99.5 99.6 99.6 99.7 99.8 100.0 100.0
[14:26:16.296] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.8 99.6 99.7 99.6 99.5 99.7 99.6 99.4 99.6 99.6 99.6 99.8 100.0 100.0
[14:26:16.296] INFO: X-ray hit rate [MHz/cm2]: 56.7 36.0 47.7 78.3 86.6 91.0 92.9 73.0 74.8 89.5 92.3 77.5 78.9 45.5 17.1 18.4
[14:26:16.296] INFO: PixTestHighRate::doXPixelAlive() done
[14:26:16.343] INFO: PixTest:: pg_setup set to default.
[14:26:16.361] INFO: enter test to run
[14:26:19.746] INFO: test: exit no parameter change
[14:26:20.371] QUIET: Connection to board 33 closed.
[14:26:20.464] INFO: pXar: this is the end, my friend