[13:47:50.637] INFO: *** Welcome to pxar ***
[13:47:50.637] INFO: *** Today: 2016/06/09
[13:47:50.655] INFO: *** Version: v1.9.0-814-g7497
[13:47:50.655] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//dacParameters35_C15.dat
[13:47:50.656] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//tbmParameters_C0b.dat
[13:47:50.656] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//defaultMaskFile.dat
[13:47:50.656] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C15.dat
[13:47:50.731] INFO: clk: 4
[13:47:50.731] INFO: ctr: 4
[13:47:50.731] INFO: sda: 19
[13:47:50.731] INFO: tin: 9
[13:47:50.731] INFO: level: 15
[13:47:50.731] INFO: triggerdelay: 0
[13:47:50.731] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[13:47:50.731] INFO: Log level: INFO
[13:47:50.748] QUIET: Connection to board DTB_WREKRL opened.
[13:47:50.751] 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:47:50.754] INFO: RPC call hashes of host and DTB match: 398089610
[13:47:52.284] INFO: DUT info:
[13:47:52.284] INFO: The DUT currently contains the following objects:
[13:47:52.284] INFO: 2 TBM Cores tbm08c (2 ON)
[13:47:52.284] INFO: TBM Core alpha (0): 7 registers set
[13:47:52.284] INFO: TBM Core beta (1): 7 registers set
[13:47:52.284] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[13:47:52.284] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.284] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.284] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.285] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[13:47:52.688] INFO: enter 'restricted' command line mode
[13:47:52.688] INFO: enter test to run
[13:48:01.990] INFO: test: PixelAlive no parameter change
[13:48:01.990] INFO: running: pixelalive
[13:48:01.999] INFO: ----------------------------------------------------------------------
[13:48:01.999] 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:48:01.999] INFO: ----------------------------------------------------------------------
[13:48:02.317] INFO: Expecting 41600 events.
[13:48:06.645] INFO: 41600 events read in total (3609ms).
[13:48:06.812] INFO: Test took 4811ms.
[13:48:06.826] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:48:07.087] INFO: PixTestAlive::aliveTest() done
[13:48:07.087] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[13:48:07.119] INFO: enter test to run
[13:48:33.958] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[13:48:33.958] INFO: running: highrate
[13:48:33.958] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[13:48:34.114] INFO: ----------------------------------------------------------------------
[13:48:34.114] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[13:48:34.114] INFO: ----------------------------------------------------------------------
[13:48:34.114] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[13:48:34.114] INFO: edge/corner pixel THR is adjusted
[13:48:34.114] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:48:35.073] INFO: Collecting data for 5 seconds...
[13:48:40.090] INFO: Done with hot pixel readout
[13:48:51.710] INFO: PixTest:: pg_setup set to default.
[13:48:51.711] INFO: 5 hot pixels found in step 0
[13:48:52.703] INFO: Collecting data for 5 seconds...
[13:48:57.720] INFO: Done with hot pixel readout
[13:49:09.263] INFO: PixTest:: pg_setup set to default.
[13:49:09.264] INFO: 4 hot pixels found in step 1
[13:49:10.255] INFO: Collecting data for 5 seconds...
[13:49:15.272] INFO: Done with hot pixel readout
[13:49:26.890] INFO: PixTest:: pg_setup set to default.
[13:49:26.891] INFO: 7 hot pixels found in step 2
[13:49:27.883] INFO: Collecting data for 5 seconds...
[13:49:32.900] INFO: Done with hot pixel readout
[13:49:44.496] INFO: PixTest:: pg_setup set to default.
[13:49:44.497] INFO: 5 hot pixels found in step 3
[13:49:45.489] INFO: Collecting data for 5 seconds...
[13:49:50.505] INFO: Done with hot pixel readout
[13:50:01.001] INFO: PixTest:: pg_setup set to default.
[13:50:02.002] INFO: 4 hot pixels found in step 4
[13:50:02.994] INFO: Collecting data for 5 seconds...
[13:50:08.010] INFO: Done with hot pixel readout
[13:50:19.609] INFO: PixTest:: pg_setup set to default.
[13:50:19.610] INFO: 4 hot pixels found in step 5
[13:50:20.601] INFO: Collecting data for 5 seconds...
[13:50:25.618] INFO: Done with hot pixel readout
[13:50:37.122] INFO: PixTest:: pg_setup set to default.
[13:50:37.123] INFO: 6 hot pixels found in step 6
[13:50:38.114] INFO: Collecting data for 5 seconds...
[13:50:43.130] INFO: Done with hot pixel readout
[13:50:54.775] INFO: PixTest:: pg_setup set to default.

[13:50:54.776] INFO: 13 hot pixels found in step 7
[13:50:55.768] INFO: Collecting data for 5 seconds...
[13:51:00.785] INFO: Done with hot pixel readout
[13:51:12.381] INFO: PixTest:: pg_setup set to default.
[13:51:12.381] INFO: 3 hot pixels found in step 8
[13:51:13.373] INFO: Collecting data for 5 seconds...
[13:51:18.389] INFO: Done with hot pixel readout
[13:51:29.935] INFO: PixTest:: pg_setup set to default.
[13:51:29.936] INFO: 7 hot pixels found in step 9
[13:51:30.928] INFO: Collecting data for 5 seconds...
[13:51:35.944] INFO: Done with hot pixel readout
[13:51:47.553] INFO: PixTest:: pg_setup set to default.

[13:51:47.554] INFO: 6 hot pixels found in step 10
[13:51:48.546] INFO: Collecting data for 5 seconds...
[13:51:53.562] INFO: Done with hot pixel readout
[13:52:05.164] INFO: PixTest:: pg_setup set to default.
[13:52:05.165] INFO: 5 hot pixels found in step 11
[13:52:06.158] INFO: Collecting data for 5 seconds...
[13:52:11.174] INFO: Done with hot pixel readout
[13:52:22.784] INFO: PixTest:: pg_setup set to default.
[13:52:22.784] INFO: 4 hot pixels found in step 12
[13:52:23.776] INFO: Collecting data for 5 seconds...
[13:52:28.793] INFO: Done with hot pixel readout
[13:52:40.400] INFO: PixTest:: pg_setup set to default.
[13:52:40.401] INFO: 3 hot pixels found in step 13
[13:52:41.392] INFO: Collecting data for 5 seconds...
[13:52:46.408] INFO: Done with hot pixel readout
[13:52:58.024] INFO: PixTest:: pg_setup set to default.
[13:52:58.025] INFO: 2 hot pixels found in step 14
[13:52:58.060] INFO: 2 hot pixels could not be trimmed and have been masked.
[13:52:58.063] INFO: PixTest::trimHotPixels() done
[13:52:58.063] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C0.dat
[13:52:58.069] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C1.dat
[13:52:58.076] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C2.dat
[13:52:58.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C3.dat
[13:52:58.087] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C4.dat
[13:52:58.092] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C5.dat
[13:52:58.097] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C6.dat
[13:52:58.103] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C7.dat
[13:52:58.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C8.dat
[13:52:58.114] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C9.dat
[13:52:58.119] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C10.dat
[13:52:58.124] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C11.dat
[13:52:58.129] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C12.dat
[13:52:58.135] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C13.dat
[13:52:58.140] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C14.dat
[13:52:58.145] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C15.dat
[13:52:58.151] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//defaultMaskFile.dat
[13:52:58.164] INFO: enter test to run
[13:54:20.195] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[13:54:20.195] INFO: running: highrate
[13:54:20.200] INFO: ----------------------------------------------------------------------
[13:54:20.200] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[13:54:20.200] INFO: ----------------------------------------------------------------------
[13:54:20.200] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[13:54:20.200] INFO: edge/corner pixel THR is adjusted
[13:54:20.200] INFO: PixTestHighRate::trimHotPixels: step 0...
[13:54:21.158] INFO: Collecting data for 1 seconds...
[13:54:22.163] INFO: Done with hot pixel readout
[13:54:26.099] INFO: PixTest:: pg_setup set to default.
[13:54:26.100] INFO: 0 hot pixels found in step 0
[13:54:26.105] INFO: 0 hot pixels could not be trimmed and have been masked.
[13:54:26.191] INFO: PixTest::trimHotPixels() done
[13:54:26.191] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C0.dat
[13:54:26.233] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C1.dat
[13:54:26.239] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C2.dat
[13:54:26.244] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C3.dat
[13:54:26.250] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C4.dat
[13:54:26.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C5.dat
[13:54:26.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C6.dat
[13:54:26.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C7.dat
[13:54:26.272] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C8.dat
[13:54:26.278] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C9.dat
[13:54:26.284] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C10.dat
[13:54:26.290] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C11.dat
[13:54:26.296] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C12.dat
[13:54:26.301] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C13.dat
[13:54:26.307] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C14.dat
[13:54:26.313] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//trimParameters35_C15.dat
[13:54:26.318] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-2-23_FPIXTest-17C-FNAL-160606-1109_2016-06-06_11h09m_1465229386/000_FPIXTest_p17//defaultMaskFile.dat
[13:54:26.328] INFO: enter test to run
[13:55:09.227] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:55:09.227] INFO: running: xray
[13:55:09.228] INFO: ----------------------------------------------------------------------
[13:55:09.228] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:55:09.228] INFO: ----------------------------------------------------------------------
[13:55:10.191] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:55:21.831] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:55:51.891] INFO: Resuming triggers.
[13:56:03.536] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[13:56:33.359] INFO: Resuming triggers.
[13:56:45.003] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:57:14.294] INFO: Resuming triggers.
[13:57:25.939] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[13:57:55.198] INFO: Resuming triggers.
[13:58:06.842] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[13:58:36.063] INFO: Resuming triggers.
[13:58:47.707] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[13:59:16.979] INFO: Resuming triggers.
[13:59:28.623] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:59:57.859] INFO: Resuming triggers.
[14:00:09.503] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[14:00:38.682] INFO: Resuming triggers.
[14:00:45.885] INFO: data taking finished, elapsed time: 100 seconds.
[14:01:04.221] INFO: PixTest:: pg_setup set to default.
[14:01:04.224] INFO: PixTestXray::doPhRun() done
[14:01:04.358] INFO: enter test to run
[14:02:00.592] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:02:00.592] INFO: running: xray
[14:02:00.593] INFO: ----------------------------------------------------------------------
[14:02:00.593] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:02:00.593] INFO: ----------------------------------------------------------------------
[14:02:01.562] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:02:08.440] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:02:38.525] INFO: Resuming triggers.
[14:02:45.405] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:03:15.479] INFO: Resuming triggers.
[14:03:22.361] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[14:03:52.479] INFO: Resuming triggers.
[14:03:59.360] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[14:04:29.440] INFO: Resuming triggers.
[14:04:36.321] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[14:05:06.905] INFO: Resuming triggers.
[14:05:13.787] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[14:05:44.544] INFO: Resuming triggers.
[14:05:51.429] INFO: run duration 48 seconds, buffer almost full (81%), pausing triggers.
[14:06:21.850] INFO: Resuming triggers.
[14:06:28.735] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[14:06:59.794] INFO: Resuming triggers.
[14:07:06.678] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[14:07:38.007] INFO: Resuming triggers.
[14:07:44.894] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[14:08:15.174] INFO: Resuming triggers.
[14:08:22.064] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[14:08:52.138] INFO: Resuming triggers.
[14:08:59.029] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[14:09:29.384] INFO: Resuming triggers.
[14:09:36.270] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:10:06.515] INFO: Resuming triggers.
[14:10:13.399] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[14:10:43.411] INFO: Resuming triggers.
[14:10:47.384] INFO: data taking finished, elapsed time: 100 seconds.
[14:11:05.120] INFO: PixTest:: pg_setup set to default.
[14:11:05.123] INFO: PixTestXray::doPhRun() done
[14:11:05.270] INFO: enter test to run
[14:11:33.348] INFO: test: HighRate no parameter change
[14:11:33.348] INFO: running: highrate
[14:11:33.349] INFO: ----------------------------------------------------------------------
[14:11:33.349] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:11:33.349] INFO: ----------------------------------------------------------------------
[14:11:33.489] INFO: Expecting 768 events.
[14:11:34.623] INFO: 768 events read in total (418ms).
[14:11:34.623] INFO: Test took 1268ms.
[14:11:35.427] INFO: Expecting 41600 events.
[14:11:38.464] INFO: 41600 events read in total (2511ms).
[14:11:38.465] INFO: Test took 3836ms.
[14:11:38.499] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:39.231] INFO: Expecting 41600 events.
[14:11:42.423] INFO: 41600 events read in total (2666ms).
[14:11:42.424] INFO: Test took 3907ms.
[14:11:42.457] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:43.182] INFO: Expecting 41600 events.
[14:11:46.397] INFO: 41600 events read in total (2688ms).
[14:11:46.398] INFO: Test took 3925ms.
[14:11:46.431] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:47.157] INFO: Expecting 41600 events.
[14:11:50.373] INFO: 41600 events read in total (2689ms).
[14:11:50.374] INFO: Test took 3927ms.
[14:11:50.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:51.135] INFO: Expecting 41600 events.
[14:11:54.352] INFO: 41600 events read in total (2690ms).
[14:11:54.353] INFO: Test took 3930ms.
[14:11:54.385] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:55.110] INFO: Expecting 41600 events.
[14:11:58.324] INFO: 41600 events read in total (2687ms).
[14:11:58.325] INFO: Test took 3922ms.
[14:11:58.358] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:11:59.083] INFO: Expecting 41600 events.
[14:12:02.307] INFO: 41600 events read in total (2697ms).
[14:12:02.308] INFO: Test took 3932ms.
[14:12:02.341] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:03.065] INFO: Expecting 41600 events.
[14:12:06.296] INFO: 41600 events read in total (2704ms).
[14:12:06.297] INFO: Test took 3937ms.
[14:12:06.328] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:07.057] INFO: Expecting 41600 events.
[14:12:10.278] INFO: 41600 events read in total (2694ms).
[14:12:10.279] INFO: Test took 3932ms.
[14:12:10.311] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:11.039] INFO: Expecting 41600 events.
[14:12:14.262] INFO: 41600 events read in total (2696ms).
[14:12:14.263] INFO: Test took 3934ms.
[14:12:14.295] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:15.021] INFO: Expecting 41600 events.
[14:12:18.259] INFO: 41600 events read in total (2711ms).
[14:12:18.261] INFO: Test took 3948ms.
[14:12:18.300] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:19.019] INFO: Expecting 41600 events.
[14:12:22.253] INFO: 41600 events read in total (2707ms).
[14:12:22.254] INFO: Test took 3937ms.
[14:12:22.286] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:23.011] INFO: Expecting 41600 events.
[14:12:26.237] INFO: 41600 events read in total (2699ms).
[14:12:26.238] INFO: Test took 3933ms.
[14:12:26.271] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:26.998] INFO: Expecting 41600 events.
[14:12:30.233] INFO: 41600 events read in total (2708ms).
[14:12:30.233] INFO: Test took 3944ms.
[14:12:30.265] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:30.992] INFO: Expecting 41600 events.
[14:12:34.203] INFO: 41600 events read in total (2684ms).
[14:12:34.204] INFO: Test took 3920ms.
[14:12:34.237] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:34.960] INFO: Expecting 41600 events.
[14:12:38.188] INFO: 41600 events read in total (2701ms).
[14:12:38.189] INFO: Test took 3934ms.
[14:12:38.222] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:38.946] INFO: Expecting 41600 events.
[14:12:42.173] INFO: 41600 events read in total (2700ms).
[14:12:42.174] INFO: Test took 3935ms.
[14:12:42.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:42.933] INFO: Expecting 41600 events.
[14:12:46.158] INFO: 41600 events read in total (2698ms).
[14:12:46.159] INFO: Test took 3934ms.
[14:12:46.191] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:46.918] INFO: Expecting 41600 events.
[14:12:50.104] INFO: 41600 events read in total (2659ms).
[14:12:50.105] INFO: Test took 3896ms.
[14:12:50.138] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:50.864] INFO: Expecting 41600 events.
[14:12:53.942] INFO: 41600 events read in total (2551ms).
[14:12:53.943] INFO: Test took 3788ms.
[14:12:53.974] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:12:54.344] INFO: enter test to run
[14:13:07.635] INFO: test: HighRate no parameter change
[14:13:07.635] INFO: running: highrate
[14:13:07.636] INFO: ----------------------------------------------------------------------
[14:13:07.636] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:13:07.636] INFO: ----------------------------------------------------------------------
[14:13:08.255] INFO: Expecting 208000 events.
[14:13:20.016] INFO: 208000 events read in total (11234ms).
[14:13:20.019] INFO: Test took 12373ms.
[14:13:20.153] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:20.403] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:13:20.403] INFO: number of red-efficiency pixels: 72 44 126 133 115 138 126 83 72 117 78 67 92 73 23 20
[14:13:20.403] INFO: number of X-ray hits detected: 60779 41795 71006 109304 109636 113560 105862 77892 68489 87001 85344 70530 80222 55187 22191 25351
[14:13:20.403] 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:13:20.403] INFO: number of Vcal hits detected: 207927 207956 207867 207864 207883 207860 207870 207913 207928 207881 207920 207932 207906 207927 207977 207980
[14:13:20.403] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[14:13:20.403] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[14:13:20.403] INFO: X-ray hit rate [MHz/cm2]: 17.8 12.3 20.8 32.0 32.1 33.3 31.0 22.8 20.1 25.5 25.0 20.7 23.5 16.2 6.5 7.4
[14:13:20.403] INFO: PixTestHighRate::doXPixelAlive() done
[14:13:20.451] INFO: PixTest:: pg_setup set to default.
[14:13:20.462] INFO: enter test to run
[14:13:44.818] INFO: test: HighRate no parameter change
[14:13:44.819] INFO: running: highrate
[14:13:44.820] INFO: ----------------------------------------------------------------------
[14:13:44.820] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:13:44.820] INFO: ----------------------------------------------------------------------
[14:13:45.435] INFO: Expecting 208000 events.
[14:13:58.848] INFO: 208000 events read in total (12886ms).
[14:13:58.853] INFO: Test took 14023ms.
[14:13:59.132] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:13:59.428] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:13:59.429] INFO: number of red-efficiency pixels: 144 114 319 448 470 415 458 304 183 305 304 226 256 155 38 67
[14:13:59.429] INFO: number of X-ray hits detected: 124571 86634 147227 225023 227757 235199 219978 160226 141507 179871 177062 145896 165842 114453 45791 52554
[14:13:59.429] 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:13:59.429] INFO: number of Vcal hits detected: 207849 207881 207646 207519 207494 207552 207505 207676 207810 207679 207676 207765 207727 207838 207962 207932
[14:13:59.429] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.8 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[14:13:59.429] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.9 99.9 99.9 100.0 100.0
[14:13:59.429] INFO: X-ray hit rate [MHz/cm2]: 36.5 25.4 43.2 66.0 66.8 68.9 64.5 47.0 41.5 52.7 51.9 42.8 48.6 33.5 13.4 15.4
[14:13:59.429] INFO: PixTestHighRate::doXPixelAlive() done
[14:13:59.476] INFO: PixTest:: pg_setup set to default.
[14:13:59.494] INFO: enter test to run
[14:14:24.882] INFO: test: HighRate no parameter change
[14:14:24.882] INFO: running: highrate
[14:14:24.883] INFO: ----------------------------------------------------------------------
[14:14:24.883] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:14:24.883] INFO: ----------------------------------------------------------------------
[14:14:25.501] INFO: Expecting 208000 events.
[14:14:40.688] INFO: 208000 events read in total (14660ms).
[14:14:40.695] INFO: Test took 15801ms.
[14:14:41.113] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:14:41.457] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[14:14:41.457] INFO: number of red-efficiency pixels: 339 209 762 1025 1085 924 1121 652 389 751 706 544 576 357 83 102
[14:14:41.457] INFO: number of X-ray hits detected: 188221 131375 225001 341919 345345 355639 332719 245407 215661 273570 269165 221928 250706 174377 70427 80155
[14:14:41.457] 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:14:41.457] INFO: number of Vcal hits detected: 207611 207777 206974 206708 206603 206868 206595 207201 207581 207145 207209 207402 207327 207587 207912 207893
[14:14:41.457] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.4 99.4 99.5 99.4 99.6 99.8 99.6 99.6 99.7 99.7 99.8 100.0 100.0
[14:14:41.457] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.5 99.4 99.3 99.5 99.3 99.6 99.8 99.6 99.6 99.7 99.7 99.8 100.0 99.9
[14:14:41.457] INFO: X-ray hit rate [MHz/cm2]: 55.2 38.5 65.9 100.2 101.2 104.2 97.5 71.9 63.2 80.2 78.9 65.0 73.5 51.1 20.6 23.5
[14:14:41.457] INFO: PixTestHighRate::doXPixelAlive() done
[14:14:41.512] INFO: PixTest:: pg_setup set to default.
[14:14:41.530] INFO: enter test to run
[14:14:46.218] INFO: test: exit no parameter change
[14:14:46.558] QUIET: Connection to board 33 closed.
[14:14:46.559] INFO: pXar: this is the end, my friend