[12:53:27.201] INFO: *** Welcome to pxar ***
[12:53:27.201] INFO: *** Today: 2016/05/19
[12:53:28.801] INFO: *** Version: v1.9.0-796-gef167-dirty
[12:53:28.801] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//dacParameters35_C15.dat
[12:53:29.048] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:53:29.048] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//defaultMaskFile.dat
[12:53:29.093] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C15.dat
[12:53:30.063] INFO: clk: 4
[12:53:30.063] INFO: ctr: 4
[12:53:30.063] INFO: sda: 19
[12:53:30.063] INFO: tin: 9
[12:53:30.063] INFO: level: 15
[12:53:30.063] INFO: triggerdelay: 0
[12:53:30.063] QUIET: Instanciating API for pxar v1.9.0+796~gef16747
[12:53:30.063] INFO: Log level: INFO
[12:53:30.080] QUIET: Connection to board DTB_WREK4U opened.
[12:53:30.084] 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:
------------------------------------------------------
[12:53:30.087] INFO: RPC call hashes of host and DTB match: 398089610
[12:53:31.620] INFO: DUT info:
[12:53:31.620] INFO: The DUT currently contains the following objects:
[12:53:31.620] INFO: 2 TBM Cores tbm08c (2 ON)
[12:53:31.620] INFO: TBM Core alpha (0): 7 registers set
[12:53:31.620] INFO: TBM Core beta (1): 7 registers set
[12:53:31.620] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:53:31.620] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:31.620] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:53:32.046] INFO: enter 'restricted' command line mode
[12:53:32.047] INFO: enter test to run
[12:53:39.891] INFO: test: PixelAlive no parameter change
[12:53:39.891] INFO: running: pixelalive
[12:53:39.900] INFO: ----------------------------------------------------------------------
[12:53:39.900] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:53:39.900] INFO: ----------------------------------------------------------------------
[12:53:40.221] INFO: Expecting 41600 events.
[12:53:44.548] INFO: 41600 events read in total (3608ms).
[12:53:44.717] INFO: Test took 4814ms.
[12:53:44.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:53:44.989] INFO: PixTestAlive::aliveTest() done
[12:53:44.989] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[12:53:45.023] INFO: enter test to run
[12:54:10.923] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:54:10.923] INFO: running: highrate
[12:54:10.923] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:54:11.130] INFO: ----------------------------------------------------------------------
[12:54:11.130] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:54:11.130] INFO: ----------------------------------------------------------------------
[12:54:11.130] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:54:11.130] INFO: edge/corner pixel THR is adjusted
[12:54:11.130] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:54:12.088] INFO: Collecting data for 5 seconds...
[12:54:17.105] INFO: Done with hot pixel readout
[12:54:30.031] INFO: PixTest:: pg_setup set to default.
[12:54:30.031] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:54:30.032] INFO: 80 hot pixels found in step 0
[12:54:31.029] INFO: Collecting data for 5 seconds...
[12:54:36.045] INFO: Done with hot pixel readout
[12:54:48.943] INFO: PixTest:: pg_setup set to default.
[12:54:48.943] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:54:48.944] INFO: 63 hot pixels found in step 1
[12:54:49.940] INFO: Collecting data for 5 seconds...
[12:54:54.957] INFO: Done with hot pixel readout
[12:55:07.890] INFO: PixTest:: pg_setup set to default.
[12:55:07.891] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:55:07.891] INFO: 81 hot pixels found in step 2
[12:55:08.892] INFO: Collecting data for 5 seconds...
[12:55:13.909] INFO: Done with hot pixel readout
[12:55:26.666] INFO: PixTest:: pg_setup set to default.
[12:55:26.667] INFO: 71 hot pixels found in step 3
[12:55:27.667] INFO: Collecting data for 5 seconds...
[12:55:32.684] INFO: Done with hot pixel readout
[12:55:45.088] INFO: PixTest:: pg_setup set to default.
[12:55:45.089] INFO: 65 hot pixels found in step 4
[12:55:46.088] INFO: Collecting data for 5 seconds...
[12:55:51.105] INFO: Done with hot pixel readout
[12:56:03.217] INFO: PixTest:: pg_setup set to default.
[12:56:03.218] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:03.218] INFO: 76 hot pixels found in step 5
[12:56:04.219] INFO: Collecting data for 5 seconds...
[12:56:09.236] INFO: Done with hot pixel readout
[12:56:21.784] INFO: PixTest:: pg_setup set to default.
[12:56:21.784] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:21.784] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:21.785] INFO: 64 hot pixels found in step 6
[12:56:22.784] INFO: Collecting data for 5 seconds...
[12:56:27.800] INFO: Done with hot pixel readout
[12:56:40.427] INFO: PixTest:: pg_setup set to default.
[12:56:40.427] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:40.427] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:40.427] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:40.427] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:40.427] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:40.428] INFO: 61 hot pixels found in step 7
[12:56:41.428] INFO: Collecting data for 5 seconds...
[12:56:46.445] INFO: Done with hot pixel readout
[12:56:59.422] INFO: PixTest:: pg_setup set to default.
[12:56:59.422] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:56:59.423] INFO: 62 hot pixels found in step 8
[12:57:00.422] INFO: Collecting data for 5 seconds...
[12:57:05.440] INFO: Done with hot pixel readout
[12:57:18.418] INFO: PixTest:: pg_setup set to default.
[12:57:18.418] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:57:18.419] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:57:18.419] INFO: 52 hot pixels found in step 9
[12:57:19.420] INFO: Collecting data for 5 seconds...
[12:57:24.438] INFO: Done with hot pixel readout
[12:57:37.096] INFO: PixTest:: pg_setup set to default.
[12:57:37.096] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:57:37.097] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:57:37.097] INFO: 54 hot pixels found in step 10
[12:57:38.097] INFO: Collecting data for 5 seconds...
[12:57:43.113] INFO: Done with hot pixel readout
[12:57:56.007] INFO: PixTest:: pg_setup set to default.
[12:57:56.008] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:57:56.008] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:57:56.008] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:57:56.008] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:57:56.008] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:57:56.008] INFO: 56 hot pixels found in step 11
[12:57:57.007] INFO: Collecting data for 5 seconds...
[12:58:02.024] INFO: Done with hot pixel readout
[12:58:14.867] INFO: PixTest:: pg_setup set to default.
[12:58:14.868] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:58:14.868] INFO: 38 hot pixels found in step 12
[12:58:15.868] INFO: Collecting data for 5 seconds...
[12:58:20.886] INFO: Done with hot pixel readout
[12:58:33.606] INFO: PixTest:: pg_setup set to default.
[12:58:33.606] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:58:33.606] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:58:33.606] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:58:33.606] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:58:33.606] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[12:58:33.607] INFO: 34 hot pixels found in step 13
[12:58:34.608] INFO: Collecting data for 5 seconds...
[12:58:39.625] INFO: Done with hot pixel readout
[12:58:52.179] INFO: PixTest:: pg_setup set to default.
[12:58:52.180] INFO: 40 hot pixels found in step 14
[12:58:52.223] INFO: 40 hot pixels could not be trimmed and have been masked.
[12:58:52.226] INFO: PixTest::trimHotPixels() done
[12:58:52.227] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C0.dat
[12:58:52.232] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C1.dat
[12:58:52.281] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C2.dat
[12:58:52.286] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C3.dat
[12:58:52.294] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C4.dat
[12:58:52.301] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C5.dat
[12:58:52.306] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C6.dat
[12:58:52.311] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C7.dat
[12:58:52.316] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C8.dat
[12:58:52.322] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C9.dat
[12:58:52.327] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C10.dat
[12:58:52.332] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C11.dat
[12:58:52.337] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C12.dat
[12:58:52.342] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C13.dat
[12:58:52.347] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C14.dat
[12:58:52.352] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C15.dat
[12:58:52.358] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//defaultMaskFile.dat
[12:58:52.368] INFO: enter test to run
[12:59:19.280] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:59:19.281] INFO: running: highrate
[12:59:19.286] INFO: ----------------------------------------------------------------------
[12:59:19.286] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:59:19.286] INFO: ----------------------------------------------------------------------
[12:59:19.286] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:59:19.286] INFO: edge/corner pixel THR is adjusted
[12:59:19.286] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:59:20.244] INFO: Collecting data for 1 seconds...
[12:59:21.248] INFO: Done with hot pixel readout
[12:59:25.841] INFO: PixTest:: pg_setup set to default.
[12:59:25.842] INFO: 0 hot pixels found in step 0
[12:59:25.847] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:59:25.909] INFO: PixTest::trimHotPixels() done
[12:59:25.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C0.dat
[12:59:25.921] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C1.dat
[12:59:25.933] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C2.dat
[12:59:25.939] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C3.dat
[12:59:25.944] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C4.dat
[12:59:25.949] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C5.dat
[12:59:25.955] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C6.dat
[12:59:25.960] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C7.dat
[12:59:25.965] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C8.dat
[12:59:25.971] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C9.dat
[12:59:25.976] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C10.dat
[12:59:25.982] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C11.dat
[12:59:25.987] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C12.dat
[12:59:25.992] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C13.dat
[12:59:25.998] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C14.dat
[12:59:26.003] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//trimParameters35_C15.dat
[12:59:26.009] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-A-NS_FPIXTest-17C-FNAL-160517-0929_2016-05-17_09h29m_1463495357/000_FPIXTest_p17//defaultMaskFile.dat
[12:59:26.019] INFO: enter test to run
[12:59:55.120] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[12:59:55.120] INFO: running: xray
[12:59:55.121] INFO: ----------------------------------------------------------------------
[12:59:55.121] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[12:59:55.121] INFO: ----------------------------------------------------------------------
[12:59:56.087] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:00:06.332] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[13:00:36.246] INFO: Resuming triggers.
[13:00:46.496] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:01:16.207] INFO: Resuming triggers.
[13:01:26.459] INFO: run duration 30 seconds, buffer almost full (81%), pausing triggers.
[13:01:56.718] INFO: Resuming triggers.
[13:02:06.969] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[13:02:37.437] INFO: Resuming triggers.
[13:02:47.688] INFO: run duration 51 seconds, buffer almost full (81%), pausing triggers.
[13:03:18.342] INFO: Resuming triggers.
[13:03:28.592] INFO: run duration 61 seconds, buffer almost full (81%), pausing triggers.
[13:03:58.383] INFO: Resuming triggers.
[13:04:08.636] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:04:38.136] INFO: Resuming triggers.
[13:04:48.386] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:05:18.045] INFO: Resuming triggers.
[13:05:28.294] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:05:57.919] INFO: Resuming triggers.
[13:06:06.023] INFO: data taking finished, elapsed time: 100 seconds.
[13:06:29.672] INFO: PixTest:: pg_setup set to default.
[13:06:29.675] INFO: PixTestXray::doPhRun() done
[13:06:29.816] INFO: enter test to run
[13:06:54.821] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:06:54.821] INFO: running: xray
[13:06:54.822] INFO: ----------------------------------------------------------------------
[13:06:54.822] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:06:54.822] INFO: ----------------------------------------------------------------------
[13:06:55.800] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:07:01.343] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[13:07:31.532] INFO: Resuming triggers.
[13:07:37.076] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:08:07.200] INFO: Resuming triggers.
[13:08:12.740] INFO: run duration 16 seconds, buffer almost full (81%), pausing triggers.
[13:08:42.858] INFO: Resuming triggers.
[13:08:48.402] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:09:18.587] INFO: Resuming triggers.
[13:09:24.130] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:09:54.295] INFO: Resuming triggers.
[13:09:59.841] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:10:29.916] INFO: Resuming triggers.
[13:10:35.462] INFO: run duration 38 seconds, buffer almost full (81%), pausing triggers.
[13:11:06.521] INFO: Resuming triggers.
[13:11:12.065] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[13:11:42.961] INFO: Resuming triggers.
[13:11:48.506] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[13:12:18.708] INFO: Resuming triggers.
[13:12:24.253] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[13:12:55.065] INFO: Resuming triggers.
[13:13:00.613] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[13:13:32.134] INFO: Resuming triggers.
[13:13:37.680] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[13:14:08.805] INFO: Resuming triggers.
[13:14:14.351] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[13:14:44.613] INFO: Resuming triggers.
[13:14:50.157] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[13:15:20.612] INFO: Resuming triggers.
[13:15:26.156] INFO: run duration 82 seconds, buffer almost full (81%), pausing triggers.
[13:15:55.736] INFO: Resuming triggers.
[13:16:01.280] INFO: run duration 88 seconds, buffer almost full (81%), pausing triggers.
[13:16:31.602] INFO: Resuming triggers.
[13:16:37.143] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[13:17:06.913] INFO: Resuming triggers.
[13:17:12.454] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[13:17:42.155] INFO: Resuming triggers.
[13:17:42.706] INFO: data taking finished, elapsed time: 100 seconds.
[13:17:46.052] INFO: PixTest:: pg_setup set to default.
[13:17:46.055] INFO: PixTestXray::doPhRun() done
[13:17:46.216] INFO: enter test to run
[13:19:07.208] INFO: test: HighRate no parameter change
[13:19:07.208] INFO: running: highrate
[13:19:07.229] INFO: ----------------------------------------------------------------------
[13:19:07.229] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:19:07.229] INFO: ----------------------------------------------------------------------
[13:19:07.502] INFO: Expecting 768 events.
[13:19:08.636] INFO: 768 events read in total (419ms).
[13:19:08.636] INFO: Test took 1269ms.
[13:19:09.440] INFO: Expecting 41600 events.
[13:19:12.556] INFO: 41600 events read in total (2589ms).
[13:19:12.557] INFO: Test took 3887ms.
[13:19:12.600] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:13.312] INFO: Expecting 41600 events.
[13:19:16.420] INFO: 41600 events read in total (2581ms).
[13:19:16.421] INFO: Test took 3799ms.
[13:19:16.467] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:17.161] INFO: Expecting 41600 events.
[13:19:20.458] INFO: 41600 events read in total (2771ms).
[13:19:20.460] INFO: Test took 3970ms.
[13:19:20.505] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:21.210] INFO: Expecting 41600 events.
[13:19:24.283] INFO: 41600 events read in total (2546ms).
[13:19:24.285] INFO: Test took 3758ms.
[13:19:24.332] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:25.034] INFO: Expecting 41600 events.
[13:19:28.398] INFO: 41600 events read in total (2837ms).
[13:19:28.399] INFO: Test took 4043ms.
[13:19:28.446] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:29.138] INFO: Expecting 41600 events.
[13:19:32.395] INFO: 41600 events read in total (2730ms).
[13:19:32.396] INFO: Test took 3928ms.
[13:19:32.441] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:33.144] INFO: Expecting 41600 events.
[13:19:36.487] INFO: 41600 events read in total (2816ms).
[13:19:36.489] INFO: Test took 4027ms.
[13:19:36.534] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:37.234] INFO: Expecting 41600 events.
[13:19:40.579] INFO: 41600 events read in total (2819ms).
[13:19:40.580] INFO: Test took 4023ms.
[13:19:40.626] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:41.326] INFO: Expecting 41600 events.
[13:19:44.675] INFO: 41600 events read in total (2822ms).
[13:19:44.676] INFO: Test took 4028ms.
[13:19:44.722] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:45.425] INFO: Expecting 41600 events.
[13:19:48.780] INFO: 41600 events read in total (2829ms).
[13:19:48.782] INFO: Test took 4037ms.
[13:19:48.828] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:49.531] INFO: Expecting 41600 events.
[13:19:52.815] INFO: 41600 events read in total (2758ms).
[13:19:52.817] INFO: Test took 3966ms.
[13:19:52.873] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:53.553] INFO: Expecting 41600 events.
[13:19:56.798] INFO: 41600 events read in total (2718ms).
[13:19:56.800] INFO: Test took 3893ms.
[13:19:56.847] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:19:57.544] INFO: Expecting 41600 events.
[13:20:00.801] INFO: 41600 events read in total (2731ms).
[13:20:00.802] INFO: Test took 3932ms.
[13:20:00.846] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:01.551] INFO: Expecting 41600 events.
[13:20:04.664] INFO: 41600 events read in total (2586ms).
[13:20:04.665] INFO: Test took 3797ms.
[13:20:04.711] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:05.407] INFO: Expecting 41600 events.
[13:20:08.744] INFO: 41600 events read in total (2810ms).
[13:20:08.745] INFO: Test took 4010ms.
[13:20:08.791] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:09.489] INFO: Expecting 41600 events.
[13:20:12.737] INFO: 41600 events read in total (2722ms).
[13:20:12.739] INFO: Test took 3925ms.
[13:20:12.786] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:13.487] INFO: Expecting 41600 events.
[13:20:16.783] INFO: 41600 events read in total (2770ms).
[13:20:16.784] INFO: Test took 3975ms.
[13:20:16.829] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:17.530] INFO: Expecting 41600 events.
[13:20:20.782] INFO: 41600 events read in total (2725ms).
[13:20:20.821] INFO: Test took 3970ms.
[13:20:20.873] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:21.532] INFO: Expecting 41600 events.
[13:20:24.848] INFO: 41600 events read in total (2789ms).
[13:20:24.849] INFO: Test took 3954ms.
[13:20:24.895] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:25.597] INFO: Expecting 41600 events.
[13:20:28.588] INFO: 41600 events read in total (2465ms).
[13:20:28.590] INFO: Test took 3671ms.
[13:20:28.636] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:20:28.970] INFO: enter test to run
[13:21:05.007] INFO: test: HighRate no parameter change
[13:21:05.007] INFO: running: highrate
[13:21:05.008] INFO: ----------------------------------------------------------------------
[13:21:05.008] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:21:05.008] INFO: ----------------------------------------------------------------------
[13:21:05.623] INFO: Expecting 208000 events.
[13:21:17.900] INFO: 208000 events read in total (11750ms).
[13:21:17.904] INFO: Test took 12889ms.
[13:21:18.100] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:18.368] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[13:21:18.368] INFO: number of red-efficiency pixels: 93 72 109 234 249 197 229 161 122 232 173 191 149 101 29 40
[13:21:18.369] INFO: number of X-ray hits detected: 85254 56358 87540 146304 161018 152674 154268 119921 110288 140914 137216 122089 127328 71927 29533 33909
[13:21:18.369] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:21:18.369] INFO: number of Vcal hits detected: 207904 207926 207889 207734 207743 207798 207765 207833 207875 207763 207825 207804 207849 207897 207970 207862
[13:21:18.369] INFO: Vcal hit fiducial efficiency (%): 100.0 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
[13:21:18.369] INFO: Vcal hit overall efficiency (%): 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 100.0 100.0 99.9
[13:21:18.369] INFO: X-ray hit rate [MHz/cm2]: 25.0 16.5 25.7 42.9 47.2 44.7 45.2 35.1 32.3 41.3 40.2 35.8 37.3 21.1 8.7 9.9
[13:21:18.369] INFO: PixTestHighRate::doXPixelAlive() done
[13:21:18.419] INFO: PixTest:: pg_setup set to default.
[13:21:18.429] INFO: enter test to run
[13:21:37.415] INFO: test: HighRate no parameter change
[13:21:37.415] INFO: running: highrate
[13:21:37.416] INFO: ----------------------------------------------------------------------
[13:21:37.416] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:21:37.416] INFO: ----------------------------------------------------------------------
[13:21:38.034] INFO: Expecting 208000 events.
[13:21:52.686] INFO: 208000 events read in total (14125ms).
[13:21:52.693] INFO: Test took 15269ms.
[13:21:53.105] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:53.443] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[13:21:53.443] INFO: number of red-efficiency pixels: 306 208 354 710 940 672 980 492 450 810 566 611 497 328 75 85
[13:21:53.443] INFO: number of X-ray hits detected: 172412 114843 176811 294936 324877 307083 310486 242718 223407 284232 277645 245938 257818 146177 59848 68055
[13:21:53.443] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:21:53.443] INFO: number of Vcal hits detected: 207653 207775 207618 207104 206853 207231 206831 207441 207500 207075 207382 207302 207454 207637 207924 207815
[13:21:53.443] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.8 99.6 99.5 99.7 99.5 99.8 99.8 99.6 99.7 99.7 99.8 99.8 100.0 100.0
[13:21:53.443] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.6 99.4 99.6 99.4 99.7 99.8 99.6 99.7 99.7 99.7 99.8 100.0 99.9
[13:21:53.443] INFO: X-ray hit rate [MHz/cm2]: 50.5 33.7 51.8 86.4 95.2 90.0 91.0 71.1 65.5 83.3 81.4 72.1 75.6 42.8 17.5 19.9
[13:21:53.443] INFO: PixTestHighRate::doXPixelAlive() done
[13:21:53.487] INFO: PixTest:: pg_setup set to default.
[13:21:53.502] INFO: enter test to run
[13:22:18.982] INFO: test: HighRate no parameter change
[13:22:18.983] INFO: running: highrate
[13:22:18.984] INFO: ----------------------------------------------------------------------
[13:22:18.984] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:22:18.984] INFO: ----------------------------------------------------------------------
[13:22:19.608] INFO: Expecting 208000 events.
[13:22:37.550] INFO: 208000 events read in total (17416ms).
[13:22:37.559] INFO: Test took 18565ms.
[13:22:38.194] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:38.602] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2
[13:22:38.602] INFO: number of red-efficiency pixels: 653 432 832 1719 2195 1627 2267 1163 1029 1959 1386 1478 1214 799 138 145
[13:22:38.602] INFO: number of X-ray hits detected: 263637 175400 270328 451612 495579 468979 475954 370418 341094 436477 425278 377384 395139 223264 91370 105423
[13:22:38.602] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:22:38.603] INFO: number of Vcal hits detected: 207167 207497 206816 205267 204303 205606 204096 206338 206666 204981 206098 205880 206428 206873 207856 207748
[13:22:38.603] INFO: Vcal hit fiducial efficiency (%): 99.6 99.8 99.5 98.8 98.4 99.0 98.3 99.3 99.4 98.7 99.2 99.1 99.3 99.5 99.9 99.9
[13:22:38.603] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.4 98.7 98.2 98.8 98.1 99.2 99.4 98.5 99.1 99.0 99.2 99.5 99.9 99.9
[13:22:38.603] INFO: X-ray hit rate [MHz/cm2]: 77.3 51.4 79.2 132.4 145.3 137.5 139.5 108.6 100.0 127.9 124.7 110.6 115.8 65.4 26.8 30.9
[13:22:38.603] INFO: PixTestHighRate::doXPixelAlive() done
[13:22:38.647] INFO: PixTest:: pg_setup set to default.
[13:22:38.661] INFO: enter test to run
[13:22:59.294] INFO: test: exit no parameter change
[13:22:59.671] QUIET: Connection to board 32 closed.
[13:22:59.683] INFO: pXar: this is the end, my friend