[18:34:19.558] INFO: *** Welcome to pxar ***
[18:34:19.558] INFO: *** Today: 2016/07/13
[18:34:19.578] INFO: *** Version: v1.9.0-814-g7497
[18:34:19.578] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//dacParameters35_C15.dat
[18:34:19.604] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//tbmParameters_C0b.dat
[18:34:19.604] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//defaultMaskFile.dat
[18:34:19.609] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C15.dat
[18:34:19.709] INFO: clk: 4
[18:34:19.709] INFO: ctr: 4
[18:34:19.709] INFO: sda: 19
[18:34:19.709] INFO: tin: 9
[18:34:19.709] INFO: level: 15
[18:34:19.709] INFO: triggerdelay: 0
[18:34:19.710] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[18:34:19.710] INFO: Log level: INFO
[18:34:19.727] QUIET: Connection to board DTB_WREKRL opened.
[18:34:19.731] 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:
------------------------------------------------------
[18:34:19.734] INFO: RPC call hashes of host and DTB match: 398089610
[18:34:21.267] INFO: DUT info:
[18:34:21.267] INFO: The DUT currently contains the following objects:
[18:34:21.267] INFO: 2 TBM Cores tbm08c (2 ON)
[18:34:21.267] INFO: TBM Core alpha (0): 7 registers set
[18:34:21.267] INFO: TBM Core beta (1): 7 registers set
[18:34:21.267] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[18:34:21.267] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.267] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.267] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.267] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.267] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.267] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.268] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[18:34:21.671] INFO: enter 'restricted' command line mode
[18:34:21.671] INFO: enter test to run
[18:34:24.112] INFO: test: PixelAlive no parameter change
[18:34:24.112] INFO: running: pixelalive
[18:34:24.121] INFO: ----------------------------------------------------------------------
[18:34:24.121] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[18:34:24.121] INFO: ----------------------------------------------------------------------
[18:34:24.439] INFO: Expecting 41600 events.
[18:34:28.789] INFO: 41600 events read in total (3632ms).
[18:34:28.953] INFO: Test took 4830ms.
[18:34:28.962] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:34:29.223] INFO: PixTestAlive::aliveTest() done
[18:34:29.223] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0
[18:34:29.261] INFO: enter test to run
[18:35:06.312] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[18:35:06.312] INFO: running: highrate
[18:35:06.312] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[18:35:06.548] INFO: ----------------------------------------------------------------------
[18:35:06.548] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[18:35:06.548] INFO: ----------------------------------------------------------------------
[18:35:06.548] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[18:35:06.548] INFO: edge/corner pixel THR is adjusted
[18:35:06.548] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:35:07.508] INFO: Collecting data for 5 seconds...
[18:35:12.524] INFO: Done with hot pixel readout
[18:35:24.080] INFO: PixTest:: pg_setup set to default.
[18:35:24.081] INFO: 16 hot pixels found in step 0
[18:35:25.092] INFO: Collecting data for 5 seconds...
[18:35:30.107] INFO: Done with hot pixel readout
[18:35:41.830] INFO: PixTest:: pg_setup set to default.
[18:35:41.831] INFO: 20 hot pixels found in step 1
[18:35:42.819] INFO: Collecting data for 5 seconds...
[18:35:47.834] INFO: Done with hot pixel readout
[18:35:59.573] INFO: PixTest:: pg_setup set to default.
[18:35:59.574] INFO: 15 hot pixels found in step 2
[18:36:00.562] INFO: Collecting data for 5 seconds...
[18:36:05.578] INFO: Done with hot pixel readout
[18:36:17.335] INFO: PixTest:: pg_setup set to default.
[18:36:17.336] INFO: 20 hot pixels found in step 3
[18:36:18.325] INFO: Collecting data for 5 seconds...
[18:36:23.341] INFO: Done with hot pixel readout
[18:36:35.103] INFO: PixTest:: pg_setup set to default.
[18:36:35.103] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:36:35.104] INFO: 23 hot pixels found in step 4
[18:36:36.092] INFO: Collecting data for 5 seconds...
[18:36:41.108] INFO: Done with hot pixel readout
[18:36:52.867] INFO: PixTest:: pg_setup set to default.
[18:36:52.868] INFO: 13 hot pixels found in step 5
[18:36:53.856] INFO: Collecting data for 5 seconds...
[18:36:58.872] INFO: Done with hot pixel readout
[18:37:10.671] INFO: PixTest:: pg_setup set to default.
[18:37:10.671] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:10.671] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:10.671] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:10.672] INFO: 13 hot pixels found in step 6
[18:37:11.660] INFO: Collecting data for 5 seconds...
[18:37:16.676] INFO: Done with hot pixel readout
[18:37:28.420] INFO: PixTest:: pg_setup set to default.
[18:37:28.420] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:28.420] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:28.420] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:28.421] INFO: 14 hot pixels found in step 7
[18:37:29.410] INFO: Collecting data for 5 seconds...
[18:37:34.426] INFO: Done with hot pixel readout
[18:37:46.205] INFO: PixTest:: pg_setup set to default.
[18:37:46.205] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:46.205] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:46.205] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:46.205] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:37:46.206] INFO: 16 hot pixels found in step 8
[18:37:47.194] INFO: Collecting data for 5 seconds...
[18:37:52.210] INFO: Done with hot pixel readout
[18:38:04.012] INFO: PixTest:: pg_setup set to default.
[18:38:04.012] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:04.012] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:04.012] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:04.012] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:04.013] INFO: 10 hot pixels found in step 9
[18:38:04.001] INFO: Collecting data for 5 seconds...
[18:38:10.018] INFO: Done with hot pixel readout
[18:38:21.773] INFO: PixTest:: pg_setup set to default.
[18:38:21.773] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:21.773] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:21.774] INFO: 8 hot pixels found in step 10
[18:38:22.763] INFO: Collecting data for 5 seconds...
[18:38:27.778] INFO: Done with hot pixel readout
[18:38:39.774] INFO: PixTest:: pg_setup set to default.
[18:38:39.774] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:39.775] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:39.776] INFO: 8 hot pixels found in step 11
[18:38:40.764] INFO: Collecting data for 5 seconds...
[18:38:45.782] INFO: Done with hot pixel readout
[18:38:57.618] INFO: PixTest:: pg_setup set to default.
[18:38:57.618] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:57.618] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:57.618] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:38:57.619] INFO: 6 hot pixels found in step 12
[18:38:58.607] INFO: Collecting data for 5 seconds...
[18:39:03.625] INFO: Done with hot pixel readout
[18:39:15.343] INFO: PixTest:: pg_setup set to default.
[18:39:15.343] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:39:15.343] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:39:15.343] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:39:15.344] INFO: 7 hot pixels found in step 13
[18:39:16.332] INFO: Collecting data for 5 seconds...
[18:39:21.350] INFO: Done with hot pixel readout
[18:39:32.916] INFO: PixTest:: pg_setup set to default.
[18:39:32.916] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:39:32.916] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:39:32.916] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[18:39:32.917] INFO: 5 hot pixels found in step 14
[18:39:32.950] INFO: 5 hot pixels could not be trimmed and have been masked.
[18:39:32.953] INFO: PixTest::trimHotPixels() done
[18:39:32.959] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C0.dat
[18:39:32.965] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C1.dat
[18:39:32.970] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C2.dat
[18:39:32.976] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C3.dat
[18:39:32.981] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C4.dat
[18:39:32.986] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C5.dat
[18:39:32.992] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C6.dat
[18:39:32.997] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C7.dat
[18:39:33.003] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C8.dat
[18:39:33.008] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C9.dat
[18:39:33.014] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C10.dat
[18:39:33.019] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C11.dat
[18:39:33.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C12.dat
[18:39:33.031] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C13.dat
[18:39:33.036] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C14.dat
[18:39:33.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C15.dat
[18:39:33.047] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//defaultMaskFile.dat
[18:39:33.057] INFO: enter test to run
[18:40:09.725] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[18:40:09.725] INFO: running: highrate
[18:40:09.730] INFO: ----------------------------------------------------------------------
[18:40:09.730] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[18:40:09.730] INFO: ----------------------------------------------------------------------
[18:40:09.730] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[18:40:09.730] INFO: edge/corner pixel THR is adjusted
[18:40:09.730] INFO: PixTestHighRate::trimHotPixels: step 0...
[18:40:10.688] INFO: Collecting data for 1 seconds...
[18:40:11.692] INFO: Done with hot pixel readout
[18:40:15.771] INFO: PixTest:: pg_setup set to default.
[18:40:15.772] INFO: 0 hot pixels found in step 0
[18:40:15.778] INFO: 0 hot pixels could not be trimmed and have been masked.
[18:40:15.854] INFO: PixTest::trimHotPixels() done
[18:40:15.854] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C0.dat
[18:40:15.859] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C1.dat
[18:40:15.867] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C2.dat
[18:40:15.873] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C3.dat
[18:40:15.878] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C4.dat
[18:40:15.884] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C5.dat
[18:40:15.889] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C6.dat
[18:40:15.894] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C7.dat
[18:40:15.900] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C8.dat
[18:40:15.905] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C9.dat
[18:40:15.910] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C10.dat
[18:40:15.916] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C11.dat
[18:40:15.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C12.dat
[18:40:15.926] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C13.dat
[18:40:15.932] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C14.dat
[18:40:15.937] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//trimParameters35_C15.dat
[18:40:15.942] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-6-40_FPIXTest-17C-FNAL-160708-1359_2016-07-08_13h59m_1468004393/000_FPIXTest_p17//defaultMaskFile.dat
[18:40:15.952] INFO: enter test to run
[18:40:45.245] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[18:40:45.245] INFO: running: xray
[18:40:45.246] INFO: ----------------------------------------------------------------------
[18:40:45.246] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:40:45.246] INFO: ----------------------------------------------------------------------
[18:40:46.210] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:40:57.707] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[18:41:28.077] INFO: Resuming triggers.
[18:41:39.575] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[18:42:09.764] INFO: Resuming triggers.
[18:42:21.259] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[18:42:51.243] INFO: Resuming triggers.
[18:43:02.740] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[18:43:32.524] INFO: Resuming triggers.
[18:43:44.018] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[18:44:13.799] INFO: Resuming triggers.
[18:44:25.291] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[18:44:55.075] INFO: Resuming triggers.
[18:45:06.571] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[18:45:36.386] INFO: Resuming triggers.
[18:45:47.883] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[18:46:17.604] INFO: Resuming triggers.
[18:46:25.968] INFO: data taking finished, elapsed time: 100 seconds.
[18:46:47.812] INFO: PixTest:: pg_setup set to default.
[18:46:47.815] INFO: PixTestXray::doPhRun() done
[18:46:47.994] INFO: enter test to run
[18:48:04.314] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[18:48:04.314] INFO: running: xray
[18:48:04.315] INFO: ----------------------------------------------------------------------
[18:48:04.315] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[18:48:04.315] INFO: ----------------------------------------------------------------------
[18:48:05.279] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[18:48:12.040] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[18:48:42.550] INFO: Resuming triggers.
[18:48:49.310] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[18:49:19.668] INFO: Resuming triggers.
[18:49:26.429] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[18:49:56.691] INFO: Resuming triggers.
[18:50:03.452] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[18:50:33.778] INFO: Resuming triggers.
[18:50:40.542] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[18:51:11.421] INFO: Resuming triggers.
[18:51:18.181] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[18:51:49.021] INFO: Resuming triggers.
[18:51:55.780] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[18:52:26.814] INFO: Resuming triggers.
[18:52:33.572] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[18:53:05.751] INFO: Resuming triggers.
[18:53:12.510] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[18:53:43.937] INFO: Resuming triggers.
[18:53:50.697] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[18:54:21.260] INFO: Resuming triggers.
[18:54:28.024] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[18:54:58.338] INFO: Resuming triggers.
[18:55:05.101] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[18:55:35.291] INFO: Resuming triggers.
[18:55:42.054] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[18:56:12.303] INFO: Resuming triggers.
[18:56:19.062] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[18:56:49.365] INFO: Resuming triggers.
[18:56:55.046] INFO: data taking finished, elapsed time: 100 seconds.
[18:57:20.683] INFO: PixTest:: pg_setup set to default.
[18:57:20.686] INFO: PixTestXray::doPhRun() done
[18:57:20.834] INFO: enter test to run
[18:58:19.390] INFO: test: HighRate no parameter change
[18:58:19.390] INFO: running: highrate
[18:58:19.391] INFO: ----------------------------------------------------------------------
[18:58:19.391] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[18:58:19.391] INFO: ----------------------------------------------------------------------
[18:58:19.550] INFO: Expecting 768 events.
[18:58:20.684] INFO: 768 events read in total (418ms).
[18:58:20.684] INFO: Test took 1286ms.
[18:58:21.488] INFO: Expecting 41600 events.
[18:58:24.559] INFO: 41600 events read in total (2544ms).
[18:58:24.560] INFO: Test took 3868ms.
[18:58:24.593] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:25.320] INFO: Expecting 41600 events.
[18:58:28.524] INFO: 41600 events read in total (2677ms).
[18:58:28.525] INFO: Test took 3915ms.
[18:58:28.559] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:29.285] INFO: Expecting 41600 events.
[18:58:32.507] INFO: 41600 events read in total (2695ms).
[18:58:32.508] INFO: Test took 3930ms.
[18:58:32.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:33.265] INFO: Expecting 41600 events.
[18:58:36.490] INFO: 41600 events read in total (2698ms).
[18:58:36.491] INFO: Test took 3931ms.
[18:58:36.526] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:37.246] INFO: Expecting 41600 events.
[18:58:40.475] INFO: 41600 events read in total (2702ms).
[18:58:40.476] INFO: Test took 3925ms.
[18:58:40.510] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:41.233] INFO: Expecting 41600 events.
[18:58:44.472] INFO: 41600 events read in total (2712ms).
[18:58:44.473] INFO: Test took 3945ms.
[18:58:44.507] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:45.231] INFO: Expecting 41600 events.
[18:58:48.459] INFO: 41600 events read in total (2702ms).
[18:58:48.460] INFO: Test took 3935ms.
[18:58:48.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:49.221] INFO: Expecting 41600 events.
[18:58:52.449] INFO: 41600 events read in total (2701ms).
[18:58:52.450] INFO: Test took 3937ms.
[18:58:52.484] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:53.206] INFO: Expecting 41600 events.
[18:58:56.459] INFO: 41600 events read in total (2726ms).
[18:58:56.460] INFO: Test took 3957ms.
[18:58:56.494] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:58:57.217] INFO: Expecting 41600 events.
[18:59:00.458] INFO: 41600 events read in total (2715ms).
[18:59:00.459] INFO: Test took 3947ms.
[18:59:00.492] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:01.219] INFO: Expecting 41600 events.
[18:59:04.440] INFO: 41600 events read in total (2694ms).
[18:59:04.441] INFO: Test took 3932ms.
[18:59:04.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:05.200] INFO: Expecting 41600 events.
[18:59:08.445] INFO: 41600 events read in total (2718ms).
[18:59:08.446] INFO: Test took 3953ms.
[18:59:08.481] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:09.201] INFO: Expecting 41600 events.
[18:59:12.442] INFO: 41600 events read in total (2714ms).
[18:59:12.443] INFO: Test took 3944ms.
[18:59:12.477] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:13.200] INFO: Expecting 41600 events.
[18:59:16.439] INFO: 41600 events read in total (2712ms).
[18:59:16.440] INFO: Test took 3946ms.
[18:59:16.474] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:17.195] INFO: Expecting 41600 events.
[18:59:20.415] INFO: 41600 events read in total (2694ms).
[18:59:20.416] INFO: Test took 3924ms.
[18:59:20.450] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:21.177] INFO: Expecting 41600 events.
[18:59:24.409] INFO: 41600 events read in total (2705ms).
[18:59:24.410] INFO: Test took 3942ms.
[18:59:24.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:25.169] INFO: Expecting 41600 events.
[18:59:28.414] INFO: 41600 events read in total (2718ms).
[18:59:28.415] INFO: Test took 3952ms.
[18:59:28.449] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:29.171] INFO: Expecting 41600 events.
[18:59:32.398] INFO: 41600 events read in total (2701ms).
[18:59:32.399] INFO: Test took 3932ms.
[18:59:32.433] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:33.154] INFO: Expecting 41600 events.
[18:59:36.394] INFO: 41600 events read in total (2713ms).
[18:59:36.395] INFO: Test took 3944ms.
[18:59:36.430] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:37.149] INFO: Expecting 41600 events.
[18:59:40.255] INFO: 41600 events read in total (2579ms).
[18:59:40.256] INFO: Test took 3807ms.
[18:59:40.290] INFO: Fetched DAQ statistics. Counters are being reset now.
[18:59:40.646] INFO: enter test to run
[19:01:00.173] INFO: test: HighRate no parameter change
[19:01:00.173] INFO: running: highrate
[19:01:00.197] INFO: ----------------------------------------------------------------------
[19:01:00.197] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:01:00.197] INFO: ----------------------------------------------------------------------
[19:01:00.814] INFO: Expecting 208000 events.
[19:01:12.640] INFO: 208000 events read in total (11299ms).
[19:01:12.643] INFO: Test took 12437ms.
[19:01:12.786] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:01:13.037] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0
[19:01:13.037] INFO: number of red-efficiency pixels: 76 41 64 106 136 153 155 119 94 158 144 109 98 66 31 27
[19:01:13.037] INFO: number of X-ray hits detected: 69138 42665 59087 90863 99528 104863 105013 81475 86237 112179 106017 91607 91313 55959 22866 24818
[19:01:13.037] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:01:13.037] INFO: number of Vcal hits detected: 207923 207957 207934 207892 207863 207842 207844 207876 207900 207841 207751 207887 207901 207933 207968 207973
[19:01:13.037] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[19:01:13.037] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[19:01:13.037] INFO: X-ray hit rate [MHz/cm2]: 20.3 12.5 17.3 26.6 29.2 30.7 30.8 23.9 25.3 32.9 31.1 26.9 26.8 16.4 6.7 7.3
[19:01:13.037] INFO: PixTestHighRate::doXPixelAlive() done
[19:01:13.083] INFO: PixTest:: pg_setup set to default.
[19:01:13.095] INFO: enter test to run
[19:01:34.181] INFO: test: HighRate no parameter change
[19:01:34.181] INFO: running: highrate
[19:01:34.182] INFO: ----------------------------------------------------------------------
[19:01:34.182] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:01:34.182] INFO: ----------------------------------------------------------------------
[19:01:34.795] INFO: Expecting 208000 events.
[19:01:48.313] INFO: 208000 events read in total (12991ms).
[19:01:48.319] INFO: Test took 14128ms.
[19:01:48.610] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:01:48.910] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0
[19:01:48.910] INFO: number of red-efficiency pixels: 294 155 241 293 423 460 433 348 260 548 482 302 300 248 57 62
[19:01:48.910] INFO: number of X-ray hits detected: 141454 87142 121391 186961 202764 215275 214200 167399 175547 227465 217163 186701 185788 115026 46351 50609
[19:01:48.910] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:01:48.910] INFO: number of Vcal hits detected: 207673 207838 207743 207695 207533 207489 207530 207619 207715 207407 207373 207682 207682 207735 207942 207938
[19:01:48.910] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.7 99.8 99.9 99.9 99.9 100.0 100.0
[19:01:48.910] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[19:01:48.910] INFO: X-ray hit rate [MHz/cm2]: 41.5 25.5 35.6 54.8 59.4 63.1 62.8 49.1 51.5 66.7 63.7 54.7 54.5 33.7 13.6 14.8
[19:01:48.910] INFO: PixTestHighRate::doXPixelAlive() done
[19:01:48.962] INFO: PixTest:: pg_setup set to default.
[19:01:48.977] INFO: enter test to run
[19:02:37.740] INFO: test: HighRate no parameter change
[19:02:37.740] INFO: running: highrate
[19:02:37.741] INFO: ----------------------------------------------------------------------
[19:02:37.741] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[19:02:37.741] INFO: ----------------------------------------------------------------------
[19:02:38.362] INFO: Expecting 208000 events.
[19:02:54.144] INFO: 208000 events read in total (15255ms).
[19:02:54.152] INFO: Test took 16402ms.
[19:02:54.592] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:02:54.943] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0
[19:02:54.943] INFO: number of red-efficiency pixels: 589 288 517 647 1053 1104 1142 752 554 1319 1162 624 731 546 104 96
[19:02:54.943] INFO: number of X-ray hits detected: 214339 131762 184292 282985 305723 323131 322382 253460 265576 343533 325563 281186 279359 172369 70260 77078
[19:02:54.943] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[19:02:54.943] INFO: number of Vcal hits detected: 207260 207688 207360 207278 206719 206632 206581 207062 207337 206296 206439 207258 207157 207320 207889 207900
[19:02:54.943] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.7 99.4 99.4 99.4 99.6 99.7 99.3 99.4 99.7 99.6 99.7 99.9 100.0
[19:02:54.943] INFO: Vcal hit overall efficiency (%): 99.6 99.9 99.7 99.7 99.4 99.3 99.3 99.5 99.7 99.2 99.2 99.6 99.6 99.7 99.9 100.0
[19:02:54.943] INFO: X-ray hit rate [MHz/cm2]: 62.8 38.6 54.0 82.9 89.6 94.7 94.5 74.3 77.8 100.7 95.4 82.4 81.9 50.5 20.6 22.6
[19:02:54.943] INFO: PixTestHighRate::doXPixelAlive() done
[19:02:54.991] INFO: PixTest:: pg_setup set to default.
[19:02:55.004] INFO: enter test to run
[19:02:56.740] INFO: test: exit no parameter change
[19:02:57.054] QUIET: Connection to board 33 closed.
[19:02:57.055] INFO: pXar: this is the end, my friend