[14:34:41.700] INFO: *** Welcome to pxar ***
[14:34:41.700] INFO: *** Today: 2016/06/27
[14:34:41.768] INFO: *** Version: v1.9.0-814-g7497
[14:34:41.768] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//dacParameters35_C15.dat
[14:34:41.816] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:34:41.816] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[14:34:41.825] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[14:34:42.007] INFO: clk: 4
[14:34:42.007] INFO: ctr: 4
[14:34:42.007] INFO: sda: 19
[14:34:42.007] INFO: tin: 9
[14:34:42.007] INFO: level: 15
[14:34:42.007] INFO: triggerdelay: 0
[14:34:42.007] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:34:42.007] INFO: Log level: INFO
[14:34:42.025] QUIET: Connection to board DTB_WREK4U opened.
[14:34:42.028] INFO: DTB startup information
--- DTB info------------------------------------------
Board id: 32
HW version: DTB1.2
FW version: 4.2
SW version: 4.5
USB id: DTB_WREK4U
MAC address: 40D855118020
Hostname: pixelDTB032
Comment:
------------------------------------------------------
[14:34:42.031] INFO: RPC call hashes of host and DTB match: 398089610
[14:34:43.559] INFO: DUT info:
[14:34:43.559] INFO: The DUT currently contains the following objects:
[14:34:43.560] INFO: 2 TBM Cores tbm08c (2 ON)
[14:34:43.560] INFO: TBM Core alpha (0): 7 registers set
[14:34:43.560] INFO: TBM Core beta (1): 7 registers set
[14:34:43.560] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:34:43.560] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.560] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:34:43.974] INFO: enter 'restricted' command line mode
[14:34:43.974] INFO: enter test to run
[14:35:03.902] INFO: test: PixelAlive no parameter change
[14:35:03.902] INFO: running: pixelalive
[14:35:03.910] INFO: ----------------------------------------------------------------------
[14:35:03.911] 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:35:03.911] INFO: ----------------------------------------------------------------------
[14:35:04.230] INFO: Expecting 41600 events.
[14:35:08.557] INFO: 41600 events read in total (3609ms).
[14:35:08.722] INFO: Test took 4809ms.
[14:35:08.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:35:08.993] INFO: PixTestAlive::aliveTest() done
[14:35:08.993] INFO: number of dead pixels (per ROC): 0 2 0 0 0 0 0 0 0 5 0 0 0 1 0 0
[14:35:09.022] INFO: enter test to run
[14:35:36.253] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:35:36.253] INFO: running: highrate
[14:35:36.254] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:35:36.527] INFO: ----------------------------------------------------------------------
[14:35:36.527] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:35:36.527] INFO: ----------------------------------------------------------------------
[14:35:36.528] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:35:36.528] INFO: edge/corner pixel THR is adjusted
[14:35:36.528] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:35:37.487] INFO: Collecting data for 5 seconds...
[14:35:42.504] INFO: Done with hot pixel readout
[14:35:53.785] INFO: PixTest:: pg_setup set to default.
[14:35:53.786] INFO: 13 hot pixels found in step 0
[14:35:54.778] INFO: Collecting data for 5 seconds...
[14:35:59.795] INFO: Done with hot pixel readout
[14:36:11.295] INFO: PixTest:: pg_setup set to default.
[14:36:11.296] INFO: 13 hot pixels found in step 1
[14:36:12.289] INFO: Collecting data for 5 seconds...
[14:36:17.306] INFO: Done with hot pixel readout
[14:36:28.768] INFO: PixTest:: pg_setup set to default.
[14:36:28.769] INFO: 13 hot pixels found in step 2
[14:36:29.762] INFO: Collecting data for 5 seconds...
[14:36:34.778] INFO: Done with hot pixel readout
[14:36:46.209] INFO: PixTest:: pg_setup set to default.
[14:36:46.209] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:36:46.211] INFO: 14 hot pixels found in step 3
[14:36:47.204] INFO: Collecting data for 5 seconds...
[14:36:52.220] INFO: Done with hot pixel readout
[14:37:03.722] INFO: PixTest:: pg_setup set to default.
[14:37:03.722] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:03.722] INFO: 9 hot pixels found in step 4
[14:37:04.716] INFO: Collecting data for 5 seconds...
[14:37:09.732] INFO: Done with hot pixel readout
[14:37:21.240] INFO: PixTest:: pg_setup set to default.
[14:37:21.240] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:21.241] INFO: 11 hot pixels found in step 5
[14:37:22.235] INFO: Collecting data for 5 seconds...
[14:37:27.252] INFO: Done with hot pixel readout
[14:37:38.748] INFO: PixTest:: pg_setup set to default.
[14:37:38.748] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:38.748] INFO: 8 hot pixels found in step 6
[14:37:39.742] INFO: Collecting data for 5 seconds...
[14:37:44.758] INFO: Done with hot pixel readout
[14:37:56.201] INFO: PixTest:: pg_setup set to default.
[14:37:56.201] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:37:56.202] INFO: 7 hot pixels found in step 7
[14:37:57.196] INFO: Collecting data for 5 seconds...
[14:38:02.213] INFO: Done with hot pixel readout
[14:38:13.798] INFO: PixTest:: pg_setup set to default.
[14:38:13.798] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:13.799] INFO: 2 hot pixels found in step 8
[14:38:14.793] INFO: Collecting data for 5 seconds...
[14:38:19.810] INFO: Done with hot pixel readout
[14:38:31.297] INFO: PixTest:: pg_setup set to default.
[14:38:31.297] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:31.298] INFO: 5 hot pixels found in step 9
[14:38:32.291] INFO: Collecting data for 5 seconds...
[14:38:37.307] INFO: Done with hot pixel readout
[14:38:48.941] INFO: PixTest:: pg_setup set to default.
[14:38:48.941] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:38:48.942] INFO: 4 hot pixels found in step 10
[14:38:49.936] INFO: Collecting data for 5 seconds...
[14:38:54.955] INFO: Done with hot pixel readout
[14:39:06.497] INFO: PixTest:: pg_setup set to default.
[14:39:06.497] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:39:06.498] INFO: 2 hot pixels found in step 11
[14:39:07.492] INFO: Collecting data for 5 seconds...
[14:39:12.513] INFO: Done with hot pixel readout
[14:39:24.179] INFO: PixTest:: pg_setup set to default.
[14:39:24.179] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:39:24.180] INFO: 2 hot pixels found in step 12
[14:39:25.173] INFO: Collecting data for 5 seconds...
[14:39:30.192] INFO: Done with hot pixel readout
[14:39:41.768] INFO: PixTest:: pg_setup set to default.
[14:39:41.768] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:39:41.769] INFO: 3 hot pixels found in step 13
[14:39:42.769] INFO: Collecting data for 5 seconds...
[14:39:47.786] INFO: Done with hot pixel readout
[14:39:59.035] INFO: PixTest:: pg_setup set to default.
[14:39:59.036] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:39:59.036] INFO: 3 hot pixels found in step 14
[14:39:59.075] INFO: 3 hot pixels could not be trimmed and have been masked.
[14:39:59.078] INFO: PixTest::trimHotPixels() done
[14:39:59.078] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat
[14:39:59.089] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C1.dat
[14:39:59.131] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C2.dat
[14:39:59.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C3.dat
[14:39:59.149] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C4.dat
[14:39:59.159] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C5.dat
[14:39:59.165] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C6.dat
[14:39:59.172] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C7.dat
[14:39:59.177] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C8.dat
[14:39:59.183] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C9.dat
[14:39:59.189] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C10.dat
[14:39:59.195] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C11.dat
[14:39:59.214] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C12.dat
[14:39:59.223] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C13.dat
[14:39:59.230] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C14.dat
[14:39:59.237] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[14:39:59.242] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[14:39:59.253] INFO: enter test to run
[14:43:47.386] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:43:47.386] INFO: running: highrate
[14:43:47.391] INFO: ----------------------------------------------------------------------
[14:43:47.391] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:43:47.391] INFO: ----------------------------------------------------------------------
[14:43:47.391] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:43:47.391] INFO: edge/corner pixel THR is adjusted
[14:43:47.391] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:43:48.349] INFO: Collecting data for 1 seconds...
[14:43:49.352] INFO: Done with hot pixel readout
[14:43:53.191] INFO: PixTest:: pg_setup set to default.
[14:43:53.192] INFO: 0 hot pixels found in step 0
[14:43:53.197] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:43:53.290] INFO: PixTest::trimHotPixels() done
[14:43:53.290] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C0.dat
[14:43:53.298] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C1.dat
[14:43:53.308] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C2.dat
[14:43:53.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C3.dat
[14:43:53.319] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C4.dat
[14:43:53.324] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C5.dat
[14:43:53.330] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C6.dat
[14:43:53.335] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C7.dat
[14:43:53.341] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C8.dat
[14:43:53.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C9.dat
[14:43:53.352] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C10.dat
[14:43:53.357] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C11.dat
[14:43:53.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C12.dat
[14:43:53.369] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C13.dat
[14:43:53.374] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C14.dat
[14:43:53.380] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//trimParameters35_C15.dat
[14:43:53.385] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-42_FPIXTest-17C-FNAL-160617-1220_2016-06-17_12h26m_1466184369/000_FPIXTest_p17//defaultMaskFile.dat
[14:43:53.395] INFO: enter test to run
[14:47:18.081] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:47:18.081] INFO: running: xray
[14:47:18.082] INFO: ----------------------------------------------------------------------
[14:47:18.082] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:47:18.082] INFO: ----------------------------------------------------------------------
[14:47:19.046] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:47:30.668] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:47:59.939] INFO: Resuming triggers.
[14:48:11.570] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[14:48:40.826] INFO: Resuming triggers.
[14:48:52.457] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:49:21.584] INFO: Resuming triggers.
[14:49:33.212] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[14:50:02.481] INFO: Resuming triggers.
[14:50:14.110] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[14:50:43.409] INFO: Resuming triggers.
[14:50:55.034] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[14:51:24.858] INFO: Resuming triggers.
[14:51:36.485] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[14:52:05.828] INFO: Resuming triggers.
[14:52:17.461] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:52:47.246] INFO: Resuming triggers.
[14:52:54.571] INFO: data taking finished, elapsed time: 100 seconds.
[14:53:13.361] INFO: PixTest:: pg_setup set to default.
[14:53:13.364] INFO: PixTestXray::doPhRun() done
[14:53:13.506] INFO: enter test to run
[14:56:54.293] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:56:54.293] INFO: running: xray
[14:56:54.294] INFO: ----------------------------------------------------------------------
[14:56:54.294] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:56:54.294] INFO: ----------------------------------------------------------------------
[14:56:55.257] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:57:02.225] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:57:32.033] INFO: Resuming triggers.
[14:57:39.003] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:58:09.167] INFO: Resuming triggers.
[14:58:16.130] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:58:46.209] INFO: Resuming triggers.
[14:58:53.174] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:59:23.279] INFO: Resuming triggers.
[14:59:30.242] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[15:00:00.401] INFO: Resuming triggers.
[15:00:07.367] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[15:00:37.423] INFO: Resuming triggers.
[15:00:44.390] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[15:01:14.414] INFO: Resuming triggers.
[15:01:21.383] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:01:51.326] INFO: Resuming triggers.
[15:01:58.293] INFO: run duration 62 seconds, buffer almost full (81%), pausing triggers.
[15:02:28.588] INFO: Resuming triggers.
[15:02:35.555] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[15:03:05.827] INFO: Resuming triggers.
[15:03:12.796] INFO: run duration 76 seconds, buffer almost full (81%), pausing triggers.
[15:03:43.177] INFO: Resuming triggers.
[15:03:50.145] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[15:04:20.499] INFO: Resuming triggers.
[15:04:27.470] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:04:58.901] INFO: Resuming triggers.
[15:05:05.870] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[15:05:37.026] INFO: Resuming triggers.
[15:05:39.828] INFO: data taking finished, elapsed time: 100 seconds.
[15:05:52.565] INFO: PixTest:: pg_setup set to default.
[15:05:52.568] INFO: PixTestXray::doPhRun() done
[15:05:52.719] INFO: enter test to run
[15:07:07.265] INFO: test: HighRate no parameter change
[15:07:07.265] INFO: running: highrate
[15:07:07.286] INFO: ----------------------------------------------------------------------
[15:07:07.286] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:07:07.286] INFO: ----------------------------------------------------------------------
[15:07:07.442] INFO: Expecting 768 events.
[15:07:08.576] INFO: 768 events read in total (419ms).
[15:07:08.577] INFO: Test took 1270ms.
[15:07:09.380] INFO: Expecting 41600 events.
[15:07:12.452] INFO: 41600 events read in total (2545ms).
[15:07:12.453] INFO: Test took 3869ms.
[15:07:12.485] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:13.217] INFO: Expecting 41600 events.
[15:07:16.378] INFO: 41600 events read in total (2635ms).
[15:07:16.379] INFO: Test took 3876ms.
[15:07:16.413] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:17.140] INFO: Expecting 41600 events.
[15:07:20.360] INFO: 41600 events read in total (2693ms).
[15:07:20.361] INFO: Test took 3932ms.
[15:07:20.392] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:21.117] INFO: Expecting 41600 events.
[15:07:24.309] INFO: 41600 events read in total (2665ms).
[15:07:24.310] INFO: Test took 3902ms.
[15:07:24.342] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:25.068] INFO: Expecting 41600 events.
[15:07:28.263] INFO: 41600 events read in total (2668ms).
[15:07:28.264] INFO: Test took 3886ms.
[15:07:28.296] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:29.026] INFO: Expecting 41600 events.
[15:07:32.240] INFO: 41600 events read in total (2687ms).
[15:07:32.241] INFO: Test took 3928ms.
[15:07:32.273] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:32.999] INFO: Expecting 41600 events.
[15:07:36.189] INFO: 41600 events read in total (2663ms).
[15:07:36.190] INFO: Test took 3899ms.
[15:07:36.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:36.949] INFO: Expecting 41600 events.
[15:07:40.174] INFO: 41600 events read in total (2698ms).
[15:07:40.175] INFO: Test took 3936ms.
[15:07:40.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:40.935] INFO: Expecting 41600 events.
[15:07:44.161] INFO: 41600 events read in total (2699ms).
[15:07:44.162] INFO: Test took 3936ms.
[15:07:44.194] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:44.924] INFO: Expecting 41600 events.
[15:07:48.155] INFO: 41600 events read in total (2704ms).
[15:07:48.156] INFO: Test took 3945ms.
[15:07:48.188] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:48.918] INFO: Expecting 41600 events.
[15:07:52.126] INFO: 41600 events read in total (2682ms).
[15:07:52.127] INFO: Test took 3922ms.
[15:07:52.158] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:52.887] INFO: Expecting 41600 events.
[15:07:56.077] INFO: 41600 events read in total (2663ms).
[15:07:56.078] INFO: Test took 3902ms.
[15:07:56.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:07:56.839] INFO: Expecting 41600 events.
[15:08:00.059] INFO: 41600 events read in total (2693ms).
[15:08:00.059] INFO: Test took 3933ms.
[15:08:00.091] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:00.820] INFO: Expecting 41600 events.
[15:08:04.041] INFO: 41600 events read in total (2694ms).
[15:08:04.042] INFO: Test took 3934ms.
[15:08:04.074] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:04.801] INFO: Expecting 41600 events.
[15:08:08.024] INFO: 41600 events read in total (2696ms).
[15:08:08.025] INFO: Test took 3934ms.
[15:08:08.057] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:08.781] INFO: Expecting 41600 events.
[15:08:11.001] INFO: 41600 events read in total (2693ms).
[15:08:12.002] INFO: Test took 3927ms.
[15:08:12.034] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:12.763] INFO: Expecting 41600 events.
[15:08:15.936] INFO: 41600 events read in total (2646ms).
[15:08:15.937] INFO: Test took 3884ms.
[15:08:15.971] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:16.697] INFO: Expecting 41600 events.
[15:08:19.831] INFO: 41600 events read in total (2607ms).
[15:08:19.832] INFO: Test took 3843ms.
[15:08:19.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:20.588] INFO: Expecting 41600 events.
[15:08:23.780] INFO: 41600 events read in total (2665ms).
[15:08:23.781] INFO: Test took 3899ms.
[15:08:23.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:24.537] INFO: Expecting 41600 events.
[15:08:27.484] INFO: 41600 events read in total (2420ms).
[15:08:27.486] INFO: Test took 3655ms.
[15:08:27.527] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:27.887] INFO: enter test to run
[15:08:36.112] INFO: test: HighRate no parameter change
[15:08:36.112] INFO: running: highrate
[15:08:36.113] INFO: ----------------------------------------------------------------------
[15:08:36.113] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:08:36.113] INFO: ----------------------------------------------------------------------
[15:08:36.720] INFO: Expecting 208000 events.
[15:08:48.440] INFO: 208000 events read in total (11194ms).
[15:08:48.443] INFO: Test took 12324ms.
[15:08:48.579] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:08:48.829] INFO: number of dead pixels (per ROC): 0 2 0 0 0 0 0 0 0 3 0 0 0 1 0 0
[15:08:48.829] INFO: number of red-efficiency pixels: 95 54 78 137 128 127 149 110 82 95 96 77 99 50 22 27
[15:08:48.829] INFO: number of X-ray hits detected: 64062 42258 62630 98356 106041 106687 108720 78613 70665 87589 89836 74236 81096 46399 21701 23902
[15:08:48.829] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:08:48.829] INFO: number of Vcal hits detected: 207904 207848 207920 207857 207869 207870 207844 207887 207918 207757 207904 207921 207898 207899 207977 207973
[15:08:48.829] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[15:08:48.829] INFO: Vcal hit overall efficiency (%): 100.0 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[15:08:48.829] INFO: X-ray hit rate [MHz/cm2]: 18.8 12.4 18.4 28.8 31.1 31.3 31.9 23.0 20.7 25.7 26.3 21.8 23.8 13.6 6.4 7.0
[15:08:48.829] INFO: PixTestHighRate::doXPixelAlive() done
[15:08:48.880] INFO: PixTest:: pg_setup set to default.
[15:08:48.892] INFO: enter test to run
[15:09:07.552] INFO: test: HighRate no parameter change
[15:09:07.552] INFO: running: highrate
[15:09:07.553] INFO: ----------------------------------------------------------------------
[15:09:07.553] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:09:07.553] INFO: ----------------------------------------------------------------------
[15:09:08.168] INFO: Expecting 208000 events.
[15:09:21.563] INFO: 208000 events read in total (12868ms).
[15:09:21.568] INFO: Test took 14005ms.
[15:09:21.838] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:22.132] INFO: number of dead pixels (per ROC): 0 2 0 0 0 0 0 0 0 3 0 0 0 1 0 0
[15:09:22.132] INFO: number of red-efficiency pixels: 202 114 265 341 402 348 492 312 242 316 328 211 296 157 41 60
[15:09:22.132] INFO: number of X-ray hits detected: 132517 87037 130996 205703 220044 221771 225751 162819 147541 181735 185793 154016 167815 96974 44024 50410
[15:09:22.132] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:09:22.132] INFO: number of Vcal hits detected: 207782 207785 207722 207634 207573 207627 207451 207666 207743 207520 207649 207776 207689 207787 207957 207939
[15:09:22.132] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.9 99.8 99.9 99.9 99.9 100.0 100.0
[15:09:22.132] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.7 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[15:09:22.132] INFO: X-ray hit rate [MHz/cm2]: 38.8 25.5 38.4 60.3 64.5 65.0 66.2 47.7 43.2 53.3 54.5 45.1 49.2 28.4 12.9 14.8
[15:09:22.132] INFO: PixTestHighRate::doXPixelAlive() done
[15:09:22.185] INFO: PixTest:: pg_setup set to default.
[15:09:22.197] INFO: enter test to run
[15:09:38.448] INFO: test: HighRate no parameter change
[15:09:38.448] INFO: running: highrate
[15:09:38.449] INFO: ----------------------------------------------------------------------
[15:09:38.449] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:09:38.449] INFO: ----------------------------------------------------------------------
[15:09:39.067] INFO: Expecting 208000 events.
[15:09:54.137] INFO: 208000 events read in total (14543ms).
[15:09:54.144] INFO: Test took 15683ms.
[15:09:54.561] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:09:54.901] INFO: number of dead pixels (per ROC): 0 2 0 0 0 0 0 0 0 3 0 0 0 1 0 0
[15:09:54.901] INFO: number of red-efficiency pixels: 495 212 584 745 943 861 1063 728 484 715 829 438 668 266 88 85
[15:09:54.901] INFO: number of X-ray hits detected: 200852 132175 196514 309994 333404 334749 340812 248065 222487 275058 282083 233035 255341 146560 67571 76350
[15:09:54.901] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:09:54.901] INFO: number of Vcal hits detected: 207415 207671 207247 207127 206860 206951 206599 207101 207466 207038 207043 207516 207243 207657 207910 207915
[15:09:54.901] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.5 99.5 99.4 99.6 99.8 99.6 99.6 99.8 99.7 99.9 100.0 100.0
[15:09:54.901] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.6 99.6 99.5 99.5 99.3 99.6 99.7 99.5 99.5 99.8 99.6 99.8 100.0 100.0
[15:09:54.901] INFO: X-ray hit rate [MHz/cm2]: 58.9 38.7 57.6 90.9 97.7 98.1 99.9 72.7 65.2 80.6 82.7 68.3 74.8 43.0 19.8 22.4
[15:09:54.901] INFO: PixTestHighRate::doXPixelAlive() done
[15:09:54.947] INFO: PixTest:: pg_setup set to default.
[15:09:54.963] INFO: enter test to run
[15:10:00.335] INFO: test: exit no parameter change
[15:10:00.616] QUIET: Connection to board 32 closed.
[15:10:00.617] INFO: pXar: this is the end, my friend