[15:53:17.077] INFO: *** Welcome to pxar ***
[15:53:17.077] INFO: *** Today: 2016/05/18
[15:53:17.097] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:53:17.097] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//dacParameters35_C15.dat
[15:53:17.120] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:53:17.120] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//defaultMaskFile.dat
[15:53:17.129] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C15.dat
[15:53:17.211] INFO: clk: 4
[15:53:17.211] INFO: ctr: 4
[15:53:17.211] INFO: sda: 19
[15:53:17.211] INFO: tin: 9
[15:53:17.211] INFO: level: 15
[15:53:17.211] INFO: triggerdelay: 0
[15:53:17.211] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:53:17.211] INFO: Log level: INFO
[15:53:17.226] QUIET: Connection to board DTB_WREK4U opened.
[15:53:17.230] 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:
------------------------------------------------------
[15:53:17.232] INFO: RPC call hashes of host and DTB match: 398089610
[15:53:18.763] INFO: DUT info:
[15:53:18.763] INFO: The DUT currently contains the following objects:
[15:53:18.763] INFO: 2 TBM Cores tbm08c (2 ON)
[15:53:18.763] INFO: TBM Core alpha (0): 7 registers set
[15:53:18.763] INFO: TBM Core beta (1): 7 registers set
[15:53:18.763] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:53:18.763] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:18.763] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:53:19.167] INFO: enter 'restricted' command line mode
[15:53:19.167] INFO: enter test to run
[15:53:23.701] INFO: test: PixelAlive no parameter change
[15:53:23.701] INFO: running: pixelalive
[15:53:23.711] INFO: ----------------------------------------------------------------------
[15:53:23.711] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:53:23.711] INFO: ----------------------------------------------------------------------
[15:53:24.039] INFO: Expecting 41600 events.
[15:53:28.348] INFO: 41600 events read in total (3590ms).
[15:53:28.517] INFO: Test took 4804ms.
[15:53:28.531] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:53:28.796] INFO: PixTestAlive::aliveTest() done
[15:53:28.796] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[15:53:28.832] INFO: enter test to run
[15:54:34.588] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:54:34.588] INFO: running: highrate
[15:54:34.589] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:54:34.793] INFO: ----------------------------------------------------------------------
[15:54:34.793] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:54:34.793] INFO: ----------------------------------------------------------------------
[15:54:34.793] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:54:34.793] INFO: edge/corner pixel THR is adjusted
[15:54:34.793] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:54:35.753] INFO: Collecting data for 5 seconds...
[15:54:40.768] INFO: Done with hot pixel readout
[15:54:52.322] INFO: PixTest:: pg_setup set to default.
[15:54:52.323] INFO: 13 hot pixels found in step 0
[15:54:53.339] INFO: Collecting data for 5 seconds...
[15:54:58.354] INFO: Done with hot pixel readout
[15:55:09.593] INFO: PixTest:: pg_setup set to default.
[15:55:09.593] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:55:09.594] INFO: 11 hot pixels found in step 1
[15:55:10.582] INFO: Collecting data for 5 seconds...
[15:55:15.598] INFO: Done with hot pixel readout
[15:55:26.582] INFO: PixTest:: pg_setup set to default.
[15:55:26.583] INFO: 14 hot pixels found in step 2
[15:55:27.571] INFO: Collecting data for 5 seconds...
[15:55:32.586] INFO: Done with hot pixel readout
[15:55:44.119] INFO: PixTest:: pg_setup set to default.
[15:55:44.120] INFO: 13 hot pixels found in step 3
[15:55:45.110] INFO: Collecting data for 5 seconds...
[15:55:50.125] INFO: Done with hot pixel readout
[15:56:01.146] INFO: PixTest:: pg_setup set to default.
[15:56:01.146] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:56:01.146] INFO: 13 hot pixels found in step 4
[15:56:02.134] INFO: Collecting data for 5 seconds...
[15:56:07.149] INFO: Done with hot pixel readout
[15:56:18.574] INFO: PixTest:: pg_setup set to default.
[15:56:18.575] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:56:18.575] INFO: 11 hot pixels found in step 5
[15:56:19.564] INFO: Collecting data for 5 seconds...
[15:56:24.580] INFO: Done with hot pixel readout
[15:56:35.808] INFO: PixTest:: pg_setup set to default.
[15:56:35.808] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:56:35.809] INFO: 8 hot pixels found in step 6
[15:56:36.798] INFO: Collecting data for 5 seconds...
[15:56:41.815] INFO: Done with hot pixel readout
[15:56:53.418] INFO: PixTest:: pg_setup set to default.
[15:56:53.419] INFO: 3 hot pixels found in step 7
[15:56:54.407] INFO: Collecting data for 5 seconds...
[15:56:59.425] INFO: Done with hot pixel readout
[15:57:10.600] INFO: PixTest:: pg_setup set to default.
[15:57:10.601] INFO: 5 hot pixels found in step 8
[15:57:11.589] INFO: Collecting data for 5 seconds...
[15:57:16.607] INFO: Done with hot pixel readout
[15:57:27.004] INFO: PixTest:: pg_setup set to default.
[15:57:27.005] INFO: 5 hot pixels found in step 9
[15:57:28.993] INFO: Collecting data for 5 seconds...
[15:57:34.007] INFO: Done with hot pixel readout
[15:57:45.592] INFO: PixTest:: pg_setup set to default.
[15:57:45.592] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:57:45.593] INFO: 8 hot pixels found in step 10
[15:57:46.582] INFO: Collecting data for 5 seconds...
[15:57:51.598] INFO: Done with hot pixel readout
[15:58:02.789] INFO: PixTest:: pg_setup set to default.
[15:58:02.789] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:58:02.790] INFO: 2 hot pixels found in step 11
[15:58:03.778] INFO: Collecting data for 5 seconds...
[15:58:08.794] INFO: Done with hot pixel readout
[15:58:20.362] INFO: PixTest:: pg_setup set to default.
[15:58:20.362] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:58:20.363] INFO: 6 hot pixels found in step 12
[15:58:21.350] INFO: Collecting data for 5 seconds...
[15:58:26.366] INFO: Done with hot pixel readout
[15:58:37.824] INFO: PixTest:: pg_setup set to default.
[15:58:37.825] INFO: 3 hot pixels found in step 13
[15:58:38.814] INFO: Collecting data for 5 seconds...
[15:58:43.830] INFO: Done with hot pixel readout
[15:58:55.164] INFO: PixTest:: pg_setup set to default.
[15:58:55.165] INFO: 3 hot pixels found in step 14
[15:58:55.199] INFO: 3 hot pixels could not be trimmed and have been masked.
[15:58:55.202] INFO: PixTest::trimHotPixels() done
[15:58:55.207] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C0.dat
[15:58:55.213] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C1.dat
[15:58:55.218] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C2.dat
[15:58:55.223] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C3.dat
[15:58:55.229] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C4.dat
[15:58:55.234] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C5.dat
[15:58:55.239] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C6.dat
[15:58:55.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C7.dat
[15:58:55.250] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C8.dat
[15:58:55.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C9.dat
[15:58:55.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C10.dat
[15:58:55.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C11.dat
[15:58:55.272] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C12.dat
[15:58:55.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C13.dat
[15:58:55.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C14.dat
[15:58:55.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C15.dat
[15:58:55.293] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//defaultMaskFile.dat
[15:58:55.303] INFO: enter test to run
[16:01:33.817] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[16:01:33.817] INFO: running: highrate
[16:01:33.822] INFO: ----------------------------------------------------------------------
[16:01:33.822] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[16:01:33.822] INFO: ----------------------------------------------------------------------
[16:01:33.822] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[16:01:33.822] INFO: edge/corner pixel THR is adjusted
[16:01:33.822] INFO: PixTestHighRate::trimHotPixels: step 0...
[16:01:34.780] INFO: Collecting data for 1 seconds...
[16:01:35.784] INFO: Done with hot pixel readout
[16:01:39.717] INFO: PixTest:: pg_setup set to default.
[16:01:39.718] INFO: 0 hot pixels found in step 0
[16:01:39.724] INFO: 0 hot pixels could not be trimmed and have been masked.
[16:01:39.817] INFO: PixTest::trimHotPixels() done
[16:01:39.817] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C0.dat
[16:01:39.822] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C1.dat
[16:01:39.827] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C2.dat
[16:01:39.833] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C3.dat
[16:01:39.838] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C4.dat
[16:01:39.844] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C5.dat
[16:01:39.850] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C6.dat
[16:01:39.855] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C7.dat
[16:01:39.861] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C8.dat
[16:01:39.866] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C9.dat
[16:01:39.872] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C10.dat
[16:01:39.877] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C11.dat
[16:01:39.882] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C12.dat
[16:01:39.888] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C13.dat
[16:01:39.893] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C14.dat
[16:01:39.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//trimParameters35_C15.dat
[16:01:39.904] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-I-4-04_FPIXTest-17C-FNAL-160513-1252_2016-05-13_12h52m_1463161948/000_FPIXTest_p17//defaultMaskFile.dat
[16:01:39.913] INFO: enter test to run
[16:02:55.000] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[16:02:55.000] INFO: running: xray
[16:02:55.001] INFO: ----------------------------------------------------------------------
[16:02:55.001] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:02:55.001] INFO: ----------------------------------------------------------------------
[16:02:56.962] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:03:08.390] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[16:03:36.760] INFO: Resuming triggers.
[16:03:48.190] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[16:04:16.767] INFO: Resuming triggers.
[16:04:28.195] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[16:04:56.538] INFO: Resuming triggers.
[16:05:07.971] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[16:05:37.032] INFO: Resuming triggers.
[16:05:48.462] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[16:06:17.181] INFO: Resuming triggers.
[16:06:28.609] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[16:06:56.641] INFO: Resuming triggers.
[16:07:08.070] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[16:07:36.794] INFO: Resuming triggers.
[16:07:48.223] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[16:08:16.589] INFO: Resuming triggers.
[16:08:25.493] INFO: data taking finished, elapsed time: 100 seconds.
[16:08:47.969] INFO: PixTest:: pg_setup set to default.
[16:08:47.972] INFO: PixTestXray::doPhRun() done
[16:08:48.148] INFO: enter test to run
[16:09:42.941] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[16:09:42.941] INFO: running: xray
[16:09:42.942] INFO: ----------------------------------------------------------------------
[16:09:42.942] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[16:09:42.942] INFO: ----------------------------------------------------------------------
[16:09:43.906] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[16:09:50.634] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[16:10:19.561] INFO: Resuming triggers.
[16:10:26.292] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[16:10:55.978] INFO: Resuming triggers.
[16:11:02.707] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[16:11:32.517] INFO: Resuming triggers.
[16:11:39.250] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[16:12:08.977] INFO: Resuming triggers.
[16:12:15.703] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[16:12:45.410] INFO: Resuming triggers.
[16:12:52.138] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[16:13:21.886] INFO: Resuming triggers.
[16:13:28.615] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[16:13:57.925] INFO: Resuming triggers.
[16:14:04.652] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[16:14:34.309] INFO: Resuming triggers.
[16:14:41.039] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[16:15:10.543] INFO: Resuming triggers.
[16:15:17.272] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[16:15:47.566] INFO: Resuming triggers.
[16:15:54.295] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[16:16:24.530] INFO: Resuming triggers.
[16:16:31.253] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[16:17:00.844] INFO: Resuming triggers.
[16:17:07.565] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[16:17:36.698] INFO: Resuming triggers.
[16:17:43.421] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[16:18:13.104] INFO: Resuming triggers.
[16:18:19.247] INFO: data taking finished, elapsed time: 100 seconds.
[16:18:46.521] INFO: PixTest:: pg_setup set to default.
[16:18:46.524] INFO: PixTestXray::doPhRun() done
[16:18:46.673] INFO: enter test to run
[16:22:36.312] INFO: test: HighRate no parameter change
[16:22:36.312] INFO: running: highrate
[16:22:36.369] INFO: ----------------------------------------------------------------------
[16:22:36.369] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:22:36.369] INFO: ----------------------------------------------------------------------
[16:22:36.533] INFO: Expecting 768 events.
[16:22:37.667] INFO: 768 events read in total (418ms).
[16:22:37.668] INFO: Test took 1270ms.
[16:22:38.471] INFO: Expecting 41600 events.
[16:22:41.538] INFO: 41600 events read in total (2541ms).
[16:22:41.540] INFO: Test took 3865ms.
[16:22:41.572] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:42.301] INFO: Expecting 41600 events.
[16:22:45.477] INFO: 41600 events read in total (2649ms).
[16:22:45.478] INFO: Test took 3889ms.
[16:22:45.511] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:46.238] INFO: Expecting 41600 events.
[16:22:49.452] INFO: 41600 events read in total (2687ms).
[16:22:49.453] INFO: Test took 3924ms.
[16:22:49.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:50.213] INFO: Expecting 41600 events.
[16:22:53.450] INFO: 41600 events read in total (2710ms).
[16:22:53.451] INFO: Test took 3946ms.
[16:22:53.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:54.212] INFO: Expecting 41600 events.
[16:22:57.443] INFO: 41600 events read in total (2705ms).
[16:22:57.444] INFO: Test took 3943ms.
[16:22:57.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:22:58.202] INFO: Expecting 41600 events.
[16:23:01.438] INFO: 41600 events read in total (2709ms).
[16:23:01.439] INFO: Test took 3944ms.
[16:23:01.472] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:02.196] INFO: Expecting 41600 events.
[16:23:05.436] INFO: 41600 events read in total (2713ms).
[16:23:05.437] INFO: Test took 3947ms.
[16:23:05.470] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:06.196] INFO: Expecting 41600 events.
[16:23:09.440] INFO: 41600 events read in total (2717ms).
[16:23:09.441] INFO: Test took 3952ms.
[16:23:09.475] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:10.196] INFO: Expecting 41600 events.
[16:23:13.437] INFO: 41600 events read in total (2714ms).
[16:23:13.438] INFO: Test took 3946ms.
[16:23:13.471] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:14.194] INFO: Expecting 41600 events.
[16:23:17.425] INFO: 41600 events read in total (2704ms).
[16:23:17.426] INFO: Test took 3937ms.
[16:23:17.460] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:18.186] INFO: Expecting 41600 events.
[16:23:21.428] INFO: 41600 events read in total (2715ms).
[16:23:21.429] INFO: Test took 3951ms.
[16:23:21.463] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:22.186] INFO: Expecting 41600 events.
[16:23:25.428] INFO: 41600 events read in total (2716ms).
[16:23:25.429] INFO: Test took 3948ms.
[16:23:25.464] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:26.187] INFO: Expecting 41600 events.
[16:23:29.434] INFO: 41600 events read in total (2721ms).
[16:23:29.435] INFO: Test took 3952ms.
[16:23:29.468] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:30.190] INFO: Expecting 41600 events.
[16:23:33.408] INFO: 41600 events read in total (2691ms).
[16:23:33.408] INFO: Test took 3921ms.
[16:23:33.442] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:34.169] INFO: Expecting 41600 events.
[16:23:37.414] INFO: 41600 events read in total (2719ms).
[16:23:37.415] INFO: Test took 3956ms.
[16:23:37.448] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:38.171] INFO: Expecting 41600 events.
[16:23:41.410] INFO: 41600 events read in total (2712ms).
[16:23:41.411] INFO: Test took 3946ms.
[16:23:41.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:42.168] INFO: Expecting 41600 events.
[16:23:45.398] INFO: 41600 events read in total (2703ms).
[16:23:45.399] INFO: Test took 3937ms.
[16:23:45.433] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:46.159] INFO: Expecting 41600 events.
[16:23:49.403] INFO: 41600 events read in total (2718ms).
[16:23:49.404] INFO: Test took 3953ms.
[16:23:49.437] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:50.161] INFO: Expecting 41600 events.
[16:23:53.387] INFO: 41600 events read in total (2699ms).
[16:23:53.388] INFO: Test took 3932ms.
[16:23:53.421] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:54.147] INFO: Expecting 41600 events.
[16:23:57.291] INFO: 41600 events read in total (2617ms).
[16:23:57.292] INFO: Test took 3854ms.
[16:23:57.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:23:57.685] INFO: enter test to run
[16:24:07.055] INFO: test: HighRate no parameter change
[16:24:07.055] INFO: running: highrate
[16:24:07.056] INFO: ----------------------------------------------------------------------
[16:24:07.056] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:24:07.056] INFO: ----------------------------------------------------------------------
[16:24:07.666] INFO: Expecting 208000 events.
[16:24:19.531] INFO: 208000 events read in total (11338ms).
[16:24:19.534] INFO: Test took 12471ms.
[16:24:19.677] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:19.928] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:24:19.928] INFO: number of red-efficiency pixels: 68 40 69 135 115 148 123 118 73 92 114 125 80 54 20 27
[16:24:19.928] INFO: number of X-ray hits detected: 64784 43471 62105 102222 106118 110077 114056 80236 74496 94607 95430 81746 88476 55058 23042 27008
[16:24:19.928] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:24:19.928] INFO: number of Vcal hits detected: 207883 207959 207928 207859 207880 207851 207875 207880 207927 207905 207883 207873 207920 207945 207979 207973
[16:24:19.928] 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 99.9 99.9 100.0 100.0 100.0 100.0
[16:24:19.928] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0
[16:24:19.928] INFO: X-ray hit rate [MHz/cm2]: 19.0 12.7 18.2 30.0 31.1 32.3 33.4 23.5 21.8 27.7 28.0 24.0 25.9 16.1 6.8 7.9
[16:24:19.928] INFO: PixTestHighRate::doXPixelAlive() done
[16:24:19.976] INFO: PixTest:: pg_setup set to default.
[16:24:19.993] INFO: enter test to run
[16:24:33.287] INFO: test: HighRate no parameter change
[16:24:33.287] INFO: running: highrate
[16:24:33.288] INFO: ----------------------------------------------------------------------
[16:24:33.288] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:24:33.288] INFO: ----------------------------------------------------------------------
[16:24:33.906] INFO: Expecting 208000 events.
[16:24:47.497] INFO: 208000 events read in total (13065ms).
[16:24:47.502] INFO: Test took 14205ms.
[16:24:47.791] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:24:48.091] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:24:48.091] INFO: number of red-efficiency pixels: 273 130 174 387 381 403 427 343 283 407 358 351 272 196 52 56
[16:24:48.091] INFO: number of X-ray hits detected: 137036 90907 130532 216038 224687 232161 238872 169503 157761 199447 202202 171495 186493 116230 48943 57258
[16:24:48.091] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:24:48.091] INFO: number of Vcal hits detected: 207657 207864 207814 207592 207593 207561 207542 207634 207707 207556 207614 207625 207716 207793 207945 207942
[16:24:48.091] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[16:24:48.091] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[16:24:48.091] INFO: X-ray hit rate [MHz/cm2]: 40.2 26.6 38.3 63.3 65.9 68.0 70.0 49.7 46.2 58.5 59.3 50.3 54.7 34.1 14.3 16.8
[16:24:48.091] INFO: PixTestHighRate::doXPixelAlive() done
[16:24:48.138] INFO: PixTest:: pg_setup set to default.
[16:24:48.151] INFO: enter test to run
[16:25:11.359] INFO: test: HighRate no parameter change
[16:25:11.359] INFO: running: highrate
[16:25:11.361] INFO: ----------------------------------------------------------------------
[16:25:11.361] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:25:11.361] INFO: ----------------------------------------------------------------------
[16:25:11.988] INFO: Expecting 208000 events.
[16:25:27.679] INFO: 208000 events read in total (15164ms).
[16:25:27.687] INFO: Test took 16317ms.
[16:25:28.137] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:25:28.487] INFO: number of dead pixels (per ROC): 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[16:25:28.487] INFO: number of red-efficiency pixels: 523 260 423 818 846 930 986 779 586 922 780 745 607 388 72 116
[16:25:28.487] INFO: number of X-ray hits detected: 206320 137051 196379 325584 338021 347422 359671 255228 237145 298612 304088 259248 279350 174594 73560 86327
[16:25:28.487] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:25:28.487] INFO: number of Vcal hits detected: 207310 207721 207520 207067 207009 206880 206785 206994 207362 206917 207062 207134 207328 207566 207924 207879
[16:25:28.487] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.8 99.6 99.6 99.5 99.5 99.6 99.7 99.5 99.6 99.6 99.7 99.8 100.0 99.9
[16:25:28.487] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.8 99.6 99.5 99.5 99.4 99.5 99.7 99.5 99.5 99.6 99.7 99.8 100.0 99.9
[16:25:28.487] INFO: X-ray hit rate [MHz/cm2]: 60.5 40.2 57.6 95.4 99.1 101.8 105.4 74.8 69.5 87.5 89.1 76.0 81.9 51.2 21.6 25.3
[16:25:28.487] INFO: PixTestHighRate::doXPixelAlive() done
[16:25:28.532] INFO: PixTest:: pg_setup set to default.
[16:25:28.552] INFO: enter test to run
[16:25:36.766] INFO: test: exit no parameter change
[16:25:37.106] QUIET: Connection to board 32 closed.
[16:25:37.107] INFO: pXar: this is the end, my friend