[15:24:10.344] INFO: *** Welcome to pxar ***
[15:24:10.344] INFO: *** Today: 2016/04/06
[15:24:10.406] INFO: *** Version: v1.9.0-796-gef167-dirty
[15:24:10.407] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//dacParameters35_C15.dat
[15:24:10.465] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:24:10.465] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//defaultMaskFile.dat
[15:24:10.466] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C15.dat
[15:24:10.597] INFO: clk: 4
[15:24:10.597] INFO: ctr: 4
[15:24:10.597] INFO: sda: 19
[15:24:10.597] INFO: tin: 9
[15:24:10.597] INFO: level: 15
[15:24:10.597] INFO: triggerdelay: 0
[15:24:10.597] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[15:24:10.597] INFO: Log level: INFO
[15:24:10.616] QUIET: Connection to board DTB_WREKRL opened.
[15:24:10.619] 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:
------------------------------------------------------
[15:24:10.622] INFO: RPC call hashes of host and DTB match: 398089610
[15:24:12.150] INFO: DUT info:
[15:24:12.150] INFO: The DUT currently contains the following objects:
[15:24:12.150] INFO: 2 TBM Cores tbm08c (2 ON)
[15:24:12.150] INFO: TBM Core alpha (0): 7 registers set
[15:24:12.150] INFO: TBM Core beta (1): 7 registers set
[15:24:12.150] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:24:12.150] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.150] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.150] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.150] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.150] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.150] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.150] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.150] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.151] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.151] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.151] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.151] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.151] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.151] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.151] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.151] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:24:12.574] INFO: enter 'restricted' command line mode
[15:24:12.574] INFO: enter test to run
[15:24:23.638] INFO: test: PixelAlive no parameter change
[15:24:23.638] INFO: running: pixelalive
[15:24:23.648] INFO: ----------------------------------------------------------------------
[15:24:23.648] 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:24:23.648] INFO: ----------------------------------------------------------------------
[15:24:23.964] INFO: Expecting 41600 events.
[15:24:28.311] INFO: 41600 events read in total (3628ms).
[15:24:28.477] INFO: Test took 4827ms.
[15:24:28.486] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:24:28.748] INFO: PixTestAlive::aliveTest() done
[15:24:28.749] INFO: number of dead pixels (per ROC): 2 1 0 1 0 0 0 0 0 0 0 0 1 0 0 0
[15:24:28.781] INFO: enter test to run
[15:24:46.206] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:24:46.206] INFO: running: highrate
[15:24:46.206] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:24:46.460] INFO: ----------------------------------------------------------------------
[15:24:46.460] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:24:46.460] INFO: ----------------------------------------------------------------------
[15:24:46.460] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:24:46.460] INFO: edge/corner pixel THR is adjusted
[15:24:46.460] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:24:47.419] INFO: Collecting data for 5 seconds...
[15:24:52.437] INFO: Done with hot pixel readout
[15:25:04.785] INFO: PixTest:: pg_setup set to default.
[15:25:04.785] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:04.785] INFO: 29 hot pixels found in step 0
[15:25:05.806] INFO: Collecting data for 5 seconds...
[15:25:10.822] INFO: Done with hot pixel readout
[15:25:23.155] INFO: PixTest:: pg_setup set to default.
[15:25:23.156] INFO: 25 hot pixels found in step 1
[15:25:24.149] INFO: Collecting data for 5 seconds...
[15:25:29.165] INFO: Done with hot pixel readout
[15:25:41.531] INFO: PixTest:: pg_setup set to default.
[15:25:41.531] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:41.531] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:25:41.532] INFO: 31 hot pixels found in step 2
[15:25:42.524] INFO: Collecting data for 5 seconds...
[15:25:47.541] INFO: Done with hot pixel readout
[15:25:59.889] INFO: PixTest:: pg_setup set to default.
[15:25:59.890] INFO: 29 hot pixels found in step 3
[15:26:00.884] INFO: Collecting data for 5 seconds...
[15:26:05.900] INFO: Done with hot pixel readout
[15:26:15.117] INFO: PixTest:: pg_setup set to default.
[15:26:15.117] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:26:15.117] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:26:15.118] INFO: 28 hot pixels found in step 4
[15:26:16.115] INFO: Collecting data for 5 seconds...
[15:26:21.124] INFO: Done with hot pixel readout
[15:26:33.393] INFO: PixTest:: pg_setup set to default.
[15:26:33.393] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:26:33.394] INFO: 21 hot pixels found in step 5
[15:26:34.386] INFO: Collecting data for 5 seconds...
[15:26:39.402] INFO: Done with hot pixel readout
[15:26:51.727] INFO: PixTest:: pg_setup set to default.
[15:26:51.728] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:26:51.728] INFO: 29 hot pixels found in step 6
[15:26:52.721] INFO: Collecting data for 5 seconds...
[15:26:57.737] INFO: Done with hot pixel readout
[15:27:10.089] INFO: PixTest:: pg_setup set to default.
[15:27:10.090] INFO: 19 hot pixels found in step 7
[15:27:11.083] INFO: Collecting data for 5 seconds...
[15:27:16.098] INFO: Done with hot pixel readout
[15:27:28.436] INFO: PixTest:: pg_setup set to default.
[15:27:28.437] INFO: 16 hot pixels found in step 8
[15:27:29.431] INFO: Collecting data for 5 seconds...
[15:27:34.448] INFO: Done with hot pixel readout
[15:27:46.797] INFO: PixTest:: pg_setup set to default.
[15:27:46.797] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:27:46.798] INFO: 26 hot pixels found in step 9
[15:27:47.790] INFO: Collecting data for 5 seconds...
[15:27:52.806] INFO: Done with hot pixel readout
[15:28:05.221] INFO: PixTest:: pg_setup set to default.
[15:28:05.221] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:28:05.222] INFO: 18 hot pixels found in step 10
[15:28:06.217] INFO: Collecting data for 5 seconds...
[15:28:11.234] INFO: Done with hot pixel readout
[15:28:23.143] INFO: PixTest:: pg_setup set to default.
[15:28:23.143] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:28:23.144] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:28:23.144] INFO: 16 hot pixels found in step 11
[15:28:24.137] INFO: Collecting data for 5 seconds...
[15:28:29.154] INFO: Done with hot pixel readout
[15:28:41.435] INFO: PixTest:: pg_setup set to default.
[15:28:41.435] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:28:41.435] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:28:41.436] INFO: 20 hot pixels found in step 12
[15:28:42.430] INFO: Collecting data for 5 seconds...
[15:28:47.447] INFO: Done with hot pixel readout
[15:28:59.820] INFO: PixTest:: pg_setup set to default.
[15:28:59.820] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:28:59.821] INFO: 13 hot pixels found in step 13
[15:29:00.813] INFO: Collecting data for 5 seconds...
[15:29:05.830] INFO: Done with hot pixel readout
[15:29:18.203] INFO: PixTest:: pg_setup set to default.
[15:29:18.203] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:29:18.203] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:29:18.203] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:29:18.203] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:29:18.203] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:29:18.204] INFO: 33 hot pixels found in step 14
[15:29:18.240] INFO: 33 hot pixels could not be trimmed and have been masked.
[15:29:18.243] INFO: PixTest::trimHotPixels() done
[15:29:18.243] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C0.dat
[15:29:18.249] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C1.dat
[15:29:18.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C2.dat
[15:29:18.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C3.dat
[15:29:18.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C4.dat
[15:29:18.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C5.dat
[15:29:18.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C6.dat
[15:29:18.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C7.dat
[15:29:18.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C8.dat
[15:29:18.312] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C9.dat
[15:29:18.320] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C10.dat
[15:29:18.326] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C11.dat
[15:29:18.331] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C12.dat
[15:29:18.336] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C13.dat
[15:29:18.341] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C14.dat
[15:29:18.346] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C15.dat
[15:29:18.352] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//defaultMaskFile.dat
[15:29:18.362] INFO: enter test to run
[15:30:01.780] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:30:01.780] INFO: running: highrate
[15:30:01.784] INFO: ----------------------------------------------------------------------
[15:30:01.784] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:30:01.785] INFO: ----------------------------------------------------------------------
[15:30:01.785] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:30:01.785] INFO: edge/corner pixel THR is adjusted
[15:30:01.785] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:30:02.743] INFO: Collecting data for 1 seconds...
[15:30:03.747] INFO: Done with hot pixel readout
[15:30:08.031] INFO: PixTest:: pg_setup set to default.
[15:30:08.032] INFO: 0 hot pixels found in step 0
[15:30:08.037] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:30:08.122] INFO: PixTest::trimHotPixels() done
[15:30:08.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C0.dat
[15:30:08.130] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C1.dat
[15:30:08.136] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C2.dat
[15:30:08.141] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C3.dat
[15:30:08.146] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C4.dat
[15:30:08.151] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C5.dat
[15:30:08.157] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C6.dat
[15:30:08.162] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C7.dat
[15:30:08.167] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C8.dat
[15:30:08.172] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C9.dat
[15:30:08.177] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C10.dat
[15:30:08.183] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C11.dat
[15:30:08.188] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C12.dat
[15:30:08.193] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C13.dat
[15:30:08.198] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C14.dat
[15:30:08.203] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//trimParameters35_C15.dat
[15:30:08.209] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-K-2-48_FPIXTest-17C-FNAL-160401-0919_2016-04-01_09h19m_1459520387/000_FPIXTest_p17//defaultMaskFile.dat
[15:30:08.219] INFO: enter test to run
[15:30:23.724] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:30:23.724] INFO: running: xray
[15:30:23.725] INFO: ----------------------------------------------------------------------
[15:30:23.725] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:30:23.725] INFO: ----------------------------------------------------------------------
[15:30:24.688] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:30:35.436] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[15:31:04.850] INFO: Resuming triggers.
[15:31:15.598] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[15:31:45.111] INFO: Resuming triggers.
[15:31:55.857] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[15:32:25.502] INFO: Resuming triggers.
[15:32:36.252] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[15:33:05.834] INFO: Resuming triggers.
[15:33:16.580] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[15:33:46.178] INFO: Resuming triggers.
[15:33:56.927] INFO: run duration 64 seconds, buffer almost full (81%), pausing triggers.
[15:34:26.474] INFO: Resuming triggers.
[15:34:37.222] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[15:35:06.713] INFO: Resuming triggers.
[15:35:17.459] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[15:35:47.028] INFO: Resuming triggers.
[15:35:57.773] INFO: run duration 96 seconds, buffer almost full (81%), pausing triggers.
[15:36:25.110] INFO: Resuming triggers.
[15:36:28.717] INFO: data taking finished, elapsed time: 100 seconds.
[15:36:38.915] INFO: PixTest:: pg_setup set to default.
[15:36:38.918] INFO: PixTestXray::doPhRun() done
[15:36:39.057] INFO: enter test to run
[15:37:43.928] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:37:43.928] INFO: running: xray
[15:37:43.929] INFO: ----------------------------------------------------------------------
[15:37:43.929] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:37:43.929] INFO: ----------------------------------------------------------------------
[15:37:44.902] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:37:51.065] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:38:21.057] INFO: Resuming triggers.
[15:38:27.220] INFO: run duration 12 seconds, buffer almost full (81%), pausing triggers.
[15:38:57.210] INFO: Resuming triggers.
[15:39:03.375] INFO: run duration 18 seconds, buffer almost full (81%), pausing triggers.
[15:39:33.437] INFO: Resuming triggers.
[15:39:39.601] INFO: run duration 24 seconds, buffer almost full (81%), pausing triggers.
[15:40:09.586] INFO: Resuming triggers.
[15:40:15.752] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[15:40:45.801] INFO: Resuming triggers.
[15:40:51.969] INFO: run duration 36 seconds, buffer almost full (81%), pausing triggers.
[15:41:21.942] INFO: Resuming triggers.
[15:41:28.112] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[15:41:58.181] INFO: Resuming triggers.
[15:42:04.346] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[15:42:34.420] INFO: Resuming triggers.
[15:42:40.584] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[15:43:10.562] INFO: Resuming triggers.
[15:43:16.728] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[15:43:46.715] INFO: Resuming triggers.
[15:43:52.884] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:44:22.889] INFO: Resuming triggers.
[15:44:29.055] INFO: run duration 73 seconds, buffer almost full (81%), pausing triggers.
[15:44:59.016] INFO: Resuming triggers.
[15:45:05.180] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:45:35.157] INFO: Resuming triggers.
[15:45:41.321] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[15:46:11.284] INFO: Resuming triggers.
[15:46:17.451] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[15:46:42.977] INFO: Resuming triggers.
[15:46:49.144] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[15:47:19.016] INFO: Resuming triggers.
[15:47:20.702] INFO: data taking finished, elapsed time: 100 seconds.
[15:47:29.231] INFO: PixTest:: pg_setup set to default.
[15:47:29.234] INFO: PixTestXray::doPhRun() done
[15:47:29.385] INFO: enter test to run
[15:48:06.020] INFO: test: HighRate no parameter change
[15:48:06.020] INFO: running: highrate
[15:48:06.040] INFO: ----------------------------------------------------------------------
[15:48:06.040] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[15:48:06.040] INFO: ----------------------------------------------------------------------
[15:48:06.198] INFO: Expecting 768 events.
[15:48:07.339] INFO: 768 events read in total (418ms).
[15:48:07.340] INFO: Test took 1294ms.
[15:48:08.143] INFO: Expecting 41600 events.
[15:48:11.238] INFO: 41600 events read in total (2568ms).
[15:48:11.239] INFO: Test took 3891ms.
[15:48:11.276] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:11.998] INFO: Expecting 41600 events.
[15:48:15.225] INFO: 41600 events read in total (2700ms).
[15:48:15.226] INFO: Test took 3930ms.
[15:48:15.263] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:15.984] INFO: Expecting 41600 events.
[15:48:19.253] INFO: 41600 events read in total (2742ms).
[15:48:19.254] INFO: Test took 3973ms.
[15:48:19.291] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:20.006] INFO: Expecting 41600 events.
[15:48:23.278] INFO: 41600 events read in total (2745ms).
[15:48:23.279] INFO: Test took 3968ms.
[15:48:23.316] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:24.037] INFO: Expecting 41600 events.
[15:48:27.304] INFO: 41600 events read in total (2741ms).
[15:48:27.305] INFO: Test took 3969ms.
[15:48:27.343] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:28.057] INFO: Expecting 41600 events.
[15:48:31.336] INFO: 41600 events read in total (2752ms).
[15:48:31.337] INFO: Test took 3975ms.
[15:48:31.375] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:32.089] INFO: Expecting 41600 events.
[15:48:35.361] INFO: 41600 events read in total (2745ms).
[15:48:35.362] INFO: Test took 3967ms.
[15:48:35.400] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:36.118] INFO: Expecting 41600 events.
[15:48:39.389] INFO: 41600 events read in total (2744ms).
[15:48:39.390] INFO: Test took 3970ms.
[15:48:39.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:40.143] INFO: Expecting 41600 events.
[15:48:43.433] INFO: 41600 events read in total (2763ms).
[15:48:43.434] INFO: Test took 3987ms.
[15:48:43.472] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:44.187] INFO: Expecting 41600 events.
[15:48:47.476] INFO: 41600 events read in total (2762ms).
[15:48:47.477] INFO: Test took 3985ms.
[15:48:47.515] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:48.229] INFO: Expecting 41600 events.
[15:48:51.509] INFO: 41600 events read in total (2753ms).
[15:48:51.510] INFO: Test took 3976ms.
[15:48:51.548] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:52.263] INFO: Expecting 41600 events.
[15:48:55.531] INFO: 41600 events read in total (2741ms).
[15:48:55.532] INFO: Test took 3964ms.
[15:48:55.569] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:48:56.285] INFO: Expecting 41600 events.
[15:48:59.565] INFO: 41600 events read in total (2753ms).
[15:48:59.566] INFO: Test took 3977ms.
[15:48:59.604] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:00.322] INFO: Expecting 41600 events.
[15:49:03.605] INFO: 41600 events read in total (2756ms).
[15:49:03.606] INFO: Test took 3982ms.
[15:49:03.644] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:04.358] INFO: Expecting 41600 events.
[15:49:07.635] INFO: 41600 events read in total (2750ms).
[15:49:07.636] INFO: Test took 3971ms.
[15:49:07.674] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:08.386] INFO: Expecting 41600 events.
[15:49:11.662] INFO: 41600 events read in total (2749ms).
[15:49:11.663] INFO: Test took 3969ms.
[15:49:11.701] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:12.419] INFO: Expecting 41600 events.
[15:49:15.691] INFO: 41600 events read in total (2746ms).
[15:49:15.692] INFO: Test took 3973ms.
[15:49:15.730] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:16.447] INFO: Expecting 41600 events.
[15:49:19.711] INFO: 41600 events read in total (2737ms).
[15:49:19.712] INFO: Test took 3963ms.
[15:49:19.750] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:20.467] INFO: Expecting 41600 events.
[15:49:23.710] INFO: 41600 events read in total (2716ms).
[15:49:23.711] INFO: Test took 3942ms.
[15:49:23.749] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:24.468] INFO: Expecting 41600 events.
[15:49:27.567] INFO: 41600 events read in total (2572ms).
[15:49:27.568] INFO: Test took 3800ms.
[15:49:27.605] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:49:27.961] INFO: enter test to run
[15:49:53.283] INFO: test: HighRate no parameter change
[15:49:53.283] INFO: running: highrate
[15:49:53.284] INFO: ----------------------------------------------------------------------
[15:49:53.284] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:49:53.284] INFO: ----------------------------------------------------------------------
[15:49:53.901] INFO: Expecting 208000 events.
[15:50:05.958] INFO: 208000 events read in total (11530ms).
[15:50:05.962] INFO: Test took 12670ms.
[15:50:06.127] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:50:06.386] INFO: number of dead pixels (per ROC): 2 1 0 1 0 0 0 0 0 0 0 0 1 0 0 0
[15:50:06.386] INFO: number of red-efficiency pixels: 100 44 89 149 165 166 168 123 90 159 151 125 139 82 30 40
[15:50:06.386] INFO: number of X-ray hits detected: 69438 47819 76466 118571 126951 127075 124758 86157 83351 120950 118570 101763 106452 64723 25631 28196
[15:50:06.386] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:50:06.386] INFO: number of Vcal hits detected: 207801 207907 207910 207798 207828 207830 207830 207872 207894 207840 207844 207874 207802 207915 207970 207958
[15:50:06.386] 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 99.9 100.0 100.0 100.0
[15:50:06.386] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[15:50:06.386] INFO: X-ray hit rate [MHz/cm2]: 20.4 14.0 22.4 34.8 37.2 37.2 36.6 25.3 24.4 35.5 34.8 29.8 31.2 19.0 7.5 8.3
[15:50:06.386] INFO: PixTestHighRate::doXPixelAlive() done
[15:50:06.432] INFO: PixTest:: pg_setup set to default.
[15:50:06.443] INFO: enter test to run
[15:50:28.403] INFO: test: HighRate no parameter change
[15:50:28.403] INFO: running: highrate
[15:50:28.404] INFO: ----------------------------------------------------------------------
[15:50:28.404] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:50:28.404] INFO: ----------------------------------------------------------------------
[15:50:29.024] INFO: Expecting 208000 events.
[15:50:43.162] INFO: 208000 events read in total (13611ms).
[15:50:43.168] INFO: Test took 14756ms.
[15:50:43.516] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:50:43.832] INFO: number of dead pixels (per ROC): 2 1 0 1 0 0 0 0 0 0 0 0 1 0 0 0
[15:50:43.832] INFO: number of red-efficiency pixels: 242 142 304 619 531 533 631 346 279 692 564 402 424 260 62 84
[15:50:43.832] INFO: number of X-ray hits detected: 143584 98812 157152 243781 262880 265201 256604 178229 172248 249220 244267 211719 220751 133017 53109 58895
[15:50:43.832] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:50:43.832] INFO: number of Vcal hits detected: 207645 207799 207658 207254 207419 207404 207289 207624 207694 207244 207370 207559 207493 207718 207935 207914
[15:50:43.832] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.7 99.7 99.7 99.7 99.8 99.9 99.7 99.7 99.8 99.8 99.9 100.0 100.0
[15:50:43.832] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.7 99.7 99.7 99.8 99.9 99.6 99.7 99.8 99.8 99.9 100.0 100.0
[15:50:43.832] INFO: X-ray hit rate [MHz/cm2]: 42.1 29.0 46.1 71.5 77.1 77.7 75.2 52.2 50.5 73.0 71.6 62.1 64.7 39.0 15.6 17.3
[15:50:43.832] INFO: PixTestHighRate::doXPixelAlive() done
[15:50:43.878] INFO: PixTest:: pg_setup set to default.
[15:50:43.893] INFO: enter test to run
[15:51:08.594] INFO: test: HighRate no parameter change
[15:51:08.594] INFO: running: highrate
[15:51:08.596] INFO: ----------------------------------------------------------------------
[15:51:08.596] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[15:51:08.596] INFO: ----------------------------------------------------------------------
[15:51:09.206] INFO: Expecting 208000 events.
[15:51:25.665] INFO: 208000 events read in total (15932ms).
[15:51:25.674] INFO: Test took 17068ms.
[15:51:26.199] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:51:26.572] INFO: number of dead pixels (per ROC): 2 1 0 1 0 0 0 0 0 0 0 0 1 0 0 0
[15:51:26.572] INFO: number of red-efficiency pixels: 562 261 732 1466 1156 1196 1535 710 585 1530 1403 852 965 576 110 106
[15:51:26.572] INFO: number of X-ray hits detected: 217170 148925 238231 368844 396504 400120 387625 270063 260434 376621 370440 320552 333524 201007 81035 88975
[15:51:26.572] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[15:51:26.572] INFO: number of Vcal hits detected: 207263 207663 206971 205904 206541 206421 205827 207106 207294 205867 206056 206966 206792 207288 207887 207892
[15:51:26.572] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.6 99.1 99.4 99.3 99.1 99.6 99.7 99.1 99.2 99.6 99.5 99.7 100.0 99.9
[15:51:26.572] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.0 99.3 99.2 99.0 99.6 99.7 99.0 99.1 99.5 99.4 99.7 99.9 99.9
[15:51:26.572] INFO: X-ray hit rate [MHz/cm2]: 63.7 43.7 69.8 108.1 116.2 117.3 113.6 79.2 76.3 110.4 108.6 94.0 97.8 58.9 23.8 26.1
[15:51:26.572] INFO: PixTestHighRate::doXPixelAlive() done
[15:51:26.618] INFO: PixTest:: pg_setup set to default.
[15:51:26.629] INFO: enter test to run
[15:51:28.442] INFO: test: exit no parameter change
[15:51:28.797] QUIET: Connection to board 33 closed.
[15:51:28.798] INFO: pXar: this is the end, my friend