[11:19:52.691] INFO: *** Welcome to pxar ***
[11:19:52.691] INFO: *** Today: 2016/06/07
[11:19:52.709] INFO: *** Version: v1.9.0-814-g7497
[11:19:52.709] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//dacParameters35_C15.dat
[11:19:52.767] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//tbmParameters_C0b.dat
[11:19:52.767] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//defaultMaskFile.dat
[11:19:52.775] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C15.dat
[11:19:52.862] INFO: clk: 4
[11:19:52.862] INFO: ctr: 4
[11:19:52.862] INFO: sda: 19
[11:19:52.862] INFO: tin: 9
[11:19:52.862] INFO: level: 15
[11:19:52.862] INFO: triggerdelay: 0
[11:19:52.862] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[11:19:52.862] INFO: Log level: INFO
[11:19:52.879] QUIET: Connection to board DTB_WREK4U opened.
[11:19:52.883] 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:
------------------------------------------------------
[11:19:52.885] INFO: RPC call hashes of host and DTB match: 398089610
[11:19:54.416] INFO: DUT info:
[11:19:54.416] INFO: The DUT currently contains the following objects:
[11:19:54.416] INFO: 2 TBM Cores tbm08c (2 ON)
[11:19:54.416] INFO: TBM Core alpha (0): 7 registers set
[11:19:54.416] INFO: TBM Core beta (1): 7 registers set
[11:19:54.416] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[11:19:54.416] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.416] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[11:19:54.820] INFO: enter 'restricted' command line mode
[11:19:54.820] INFO: enter test to run
[11:20:04.928] INFO: test: PixelAlive no parameter change
[11:20:04.928] INFO: running: pixelalive
[11:20:04.937] INFO: ----------------------------------------------------------------------
[11:20:04.937] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[11:20:04.937] INFO: ----------------------------------------------------------------------
[11:20:05.259] INFO: Expecting 41600 events.
[11:20:09.585] INFO: 41600 events read in total (3608ms).
[11:20:09.753] INFO: Test took 4813ms.
[11:20:09.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:20:10.028] INFO: PixTestAlive::aliveTest() done
[11:20:10.028] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:20:10.060] INFO: enter test to run
[11:20:42.312] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[11:20:42.312] INFO: running: highrate
[11:20:42.312] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[11:20:42.551] INFO: ----------------------------------------------------------------------
[11:20:42.551] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[11:20:42.551] INFO: ----------------------------------------------------------------------
[11:20:42.551] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[11:20:42.551] INFO: edge/corner pixel THR is adjusted
[11:20:42.551] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:20:43.510] INFO: Collecting data for 5 seconds...
[11:20:48.527] INFO: Done with hot pixel readout
[11:21:00.840] INFO: PixTest:: pg_setup set to default.
[11:21:00.841] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:21:00.841] INFO: 16 hot pixels found in step 0
[11:21:01.862] INFO: Collecting data for 5 seconds...
[11:21:06.880] INFO: Done with hot pixel readout
[11:21:19.257] INFO: PixTest:: pg_setup set to default.
[11:21:19.257] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:21:19.257] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:21:19.258] INFO: 19 hot pixels found in step 1
[11:21:20.254] INFO: Collecting data for 5 seconds...
[11:21:25.272] INFO: Done with hot pixel readout
[11:21:37.369] INFO: PixTest:: pg_setup set to default.
[11:21:37.369] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:21:37.369] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:21:37.370] INFO: 16 hot pixels found in step 2
[11:21:38.367] INFO: Collecting data for 5 seconds...
[11:21:43.385] INFO: Done with hot pixel readout
[11:21:55.734] INFO: PixTest:: pg_setup set to default.
[11:21:55.734] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:21:55.735] INFO: 21 hot pixels found in step 3
[11:21:56.732] INFO: Collecting data for 5 seconds...
[11:22:01.751] INFO: Done with hot pixel readout
[11:22:14.030] INFO: PixTest:: pg_setup set to default.
[11:22:14.030] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:22:14.031] INFO: 17 hot pixels found in step 4
[11:22:15.028] INFO: Collecting data for 5 seconds...
[11:22:20.045] INFO: Done with hot pixel readout
[11:22:32.279] INFO: PixTest:: pg_setup set to default.
[11:22:32.280] INFO: 17 hot pixels found in step 5
[11:22:33.278] INFO: Collecting data for 5 seconds...
[11:22:38.296] INFO: Done with hot pixel readout
[11:22:49.802] INFO: PixTest:: pg_setup set to default.
[11:22:49.802] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:22:49.803] INFO: 14 hot pixels found in step 6
[11:22:50.800] INFO: Collecting data for 5 seconds...
[11:22:55.820] INFO: Done with hot pixel readout
[11:23:07.907] INFO: PixTest:: pg_setup set to default.
[11:23:07.907] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:23:07.908] INFO: 20 hot pixels found in step 7
[11:23:08.905] INFO: Collecting data for 5 seconds...
[11:23:13.924] INFO: Done with hot pixel readout
[11:23:26.384] INFO: PixTest:: pg_setup set to default.
[11:23:26.385] INFO: 6 hot pixels found in step 8
[11:23:27.382] INFO: Collecting data for 5 seconds...
[11:23:32.402] INFO: Done with hot pixel readout
[11:23:44.866] INFO: PixTest:: pg_setup set to default.
[11:23:44.866] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:23:44.866] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:23:44.866] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:23:44.867] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:23:44.867] INFO: 17 hot pixels found in step 9
[11:23:45.864] INFO: Collecting data for 5 seconds...
[11:23:50.883] INFO: Done with hot pixel readout
[11:24:03.356] INFO: PixTest:: pg_setup set to default.
[11:24:03.356] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:24:03.356] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:24:03.357] INFO: 16 hot pixels found in step 10
[11:24:04.354] INFO: Collecting data for 5 seconds...
[11:24:09.374] INFO: Done with hot pixel readout
[11:24:21.778] INFO: PixTest:: pg_setup set to default.
[11:24:21.778] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:24:21.779] INFO: 14 hot pixels found in step 11
[11:24:22.777] INFO: Collecting data for 5 seconds...
[11:24:27.799] INFO: Done with hot pixel readout
[11:24:40.300] INFO: PixTest:: pg_setup set to default.
[11:24:40.300] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:24:40.300] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:24:40.301] INFO: 14 hot pixels found in step 12
[11:24:41.299] INFO: Collecting data for 5 seconds...
[11:24:46.319] INFO: Done with hot pixel readout
[11:24:58.637] INFO: PixTest:: pg_setup set to default.
[11:24:58.637] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:24:58.637] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:24:58.637] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:24:58.638] INFO: 14 hot pixels found in step 13
[11:24:59.635] INFO: Collecting data for 5 seconds...
[11:25:04.651] INFO: Done with hot pixel readout
[11:25:16.975] INFO: PixTest:: pg_setup set to default.
[11:25:16.975] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:25:16.975] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:25:16.975] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[11:25:16.976] INFO: 11 hot pixels found in step 14
[11:25:17.017] INFO: 11 hot pixels could not be trimmed and have been masked.
[11:25:17.020] INFO: PixTest::trimHotPixels() done
[11:25:17.020] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C0.dat
[11:25:17.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C1.dat
[11:25:17.032] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C2.dat
[11:25:17.038] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C3.dat
[11:25:17.043] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C4.dat
[11:25:17.048] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C5.dat
[11:25:17.054] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C6.dat
[11:25:17.059] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C7.dat
[11:25:17.064] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C8.dat
[11:25:17.069] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C9.dat
[11:25:17.075] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C10.dat
[11:25:17.080] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C11.dat
[11:25:17.085] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C12.dat
[11:25:17.090] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C13.dat
[11:25:17.095] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C14.dat
[11:25:17.100] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C15.dat
[11:25:17.105] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//defaultMaskFile.dat
[11:25:17.116] INFO: enter test to run
[11:26:06.150] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[11:26:06.150] INFO: running: highrate
[11:26:06.154] INFO: ----------------------------------------------------------------------
[11:26:06.154] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[11:26:06.154] INFO: ----------------------------------------------------------------------
[11:26:06.154] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[11:26:06.154] INFO: edge/corner pixel THR is adjusted
[11:26:06.154] INFO: PixTestHighRate::trimHotPixels: step 0...
[11:26:07.112] INFO: Collecting data for 1 seconds...
[11:26:08.116] INFO: Done with hot pixel readout
[11:26:12.359] INFO: PixTest:: pg_setup set to default.
[11:26:12.360] INFO: 0 hot pixels found in step 0
[11:26:12.366] INFO: 0 hot pixels could not be trimmed and have been masked.
[11:26:12.438] INFO: PixTest::trimHotPixels() done
[11:26:12.438] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C0.dat
[11:26:12.449] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C1.dat
[11:26:12.457] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C2.dat
[11:26:12.462] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C3.dat
[11:26:12.467] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C4.dat
[11:26:12.473] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C5.dat
[11:26:12.478] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C6.dat
[11:26:12.483] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C7.dat
[11:26:12.489] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C8.dat
[11:26:12.494] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C9.dat
[11:26:12.499] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C10.dat
[11:26:12.504] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C11.dat
[11:26:12.509] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C12.dat
[11:26:12.515] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C13.dat
[11:26:12.520] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C14.dat
[11:26:12.525] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//trimParameters35_C15.dat
[11:26:12.530] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Y-N-NA_FPIXTest-17C-FNAL-160601-1210_2016-06-01_12h15m_1464801302/000_FPIXTest_p17//defaultMaskFile.dat
[11:26:12.540] INFO: enter test to run
[11:26:51.565] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[11:26:51.565] INFO: running: xray
[11:26:51.567] INFO: ----------------------------------------------------------------------
[11:26:51.567] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:26:51.567] INFO: ----------------------------------------------------------------------
[11:26:52.529] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:27:03.412] INFO: run duration 10 seconds, buffer almost full (81%), pausing triggers.
[11:27:32.671] INFO: Resuming triggers.
[11:27:43.554] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[11:28:09.345] INFO: Resuming triggers.
[11:28:20.230] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[11:28:48.813] INFO: Resuming triggers.
[11:28:59.697] INFO: run duration 43 seconds, buffer almost full (81%), pausing triggers.
[11:29:26.335] INFO: Resuming triggers.
[11:29:37.219] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[11:30:04.278] INFO: Resuming triggers.
[11:30:15.161] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[11:30:44.092] INFO: Resuming triggers.
[11:30:54.974] INFO: run duration 75 seconds, buffer almost full (81%), pausing triggers.
[11:31:23.781] INFO: Resuming triggers.
[11:31:34.667] INFO: run duration 86 seconds, buffer almost full (81%), pausing triggers.
[11:32:03.254] INFO: Resuming triggers.
[11:32:14.139] INFO: run duration 97 seconds, buffer almost full (81%), pausing triggers.
[11:32:43.085] INFO: Resuming triggers.
[11:32:45.454] INFO: data taking finished, elapsed time: 100 seconds.
[11:32:52.321] INFO: PixTest:: pg_setup set to default.
[11:32:52.324] INFO: PixTestXray::doPhRun() done
[11:32:52.466] INFO: enter test to run
[11:33:35.178] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[11:33:35.178] INFO: running: xray
[11:33:35.180] INFO: ----------------------------------------------------------------------
[11:33:35.180] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[11:33:35.180] INFO: ----------------------------------------------------------------------
[11:33:36.150] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[11:33:42.162] INFO: run duration 5 seconds, buffer almost full (81%), pausing triggers.
[11:34:12.600] INFO: Resuming triggers.
[11:34:18.615] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[11:34:49.211] INFO: Resuming triggers.
[11:34:55.222] INFO: run duration 17 seconds, buffer almost full (81%), pausing triggers.
[11:35:25.452] INFO: Resuming triggers.
[11:35:31.468] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[11:36:01.946] INFO: Resuming triggers.
[11:36:07.958] INFO: run duration 29 seconds, buffer almost full (81%), pausing triggers.
[11:36:38.567] INFO: Resuming triggers.
[11:36:44.584] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[11:37:15.159] INFO: Resuming triggers.
[11:37:21.172] INFO: run duration 41 seconds, buffer almost full (81%), pausing triggers.
[11:37:52.165] INFO: Resuming triggers.
[11:37:58.180] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[11:38:28.044] INFO: Resuming triggers.
[11:38:34.054] INFO: run duration 53 seconds, buffer almost full (81%), pausing triggers.
[11:39:04.069] INFO: Resuming triggers.
[11:39:10.081] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[11:39:40.029] INFO: Resuming triggers.
[11:39:46.042] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[11:40:16.121] INFO: Resuming triggers.
[11:40:22.132] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[11:40:52.151] INFO: Resuming triggers.
[11:40:58.158] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[11:41:28.449] INFO: Resuming triggers.
[11:41:34.457] INFO: run duration 83 seconds, buffer almost full (81%), pausing triggers.
[11:42:04.356] INFO: Resuming triggers.
[11:42:10.364] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[11:42:40.456] INFO: Resuming triggers.
[11:42:46.464] INFO: run duration 95 seconds, buffer almost full (81%), pausing triggers.
[11:43:16.891] INFO: Resuming triggers.
[11:43:21.045] INFO: data taking finished, elapsed time: 100 seconds.
[11:43:42.014] INFO: PixTest:: pg_setup set to default.
[11:43:42.017] INFO: PixTestXray::doPhRun() done
[11:43:42.167] INFO: enter test to run
[11:44:14.182] INFO: test: HighRate no parameter change
[11:44:14.182] INFO: running: highrate
[11:44:14.183] INFO: ----------------------------------------------------------------------
[11:44:14.183] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[11:44:14.183] INFO: ----------------------------------------------------------------------
[11:44:14.324] INFO: Expecting 768 events.
[11:44:15.457] INFO: 768 events read in total (418ms).
[11:44:15.457] INFO: Test took 1268ms.
[11:44:16.261] INFO: Expecting 41600 events.
[11:44:19.372] INFO: 41600 events read in total (2584ms).
[11:44:19.373] INFO: Test took 3907ms.
[11:44:19.410] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:20.128] INFO: Expecting 41600 events.
[11:44:23.362] INFO: 41600 events read in total (2707ms).
[11:44:23.363] INFO: Test took 3933ms.
[11:44:23.401] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:24.118] INFO: Expecting 41600 events.
[11:44:27.404] INFO: 41600 events read in total (2759ms).
[11:44:27.405] INFO: Test took 3984ms.
[11:44:27.443] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:28.156] INFO: Expecting 41600 events.
[11:44:31.426] INFO: 41600 events read in total (2743ms).
[11:44:31.427] INFO: Test took 3964ms.
[11:44:31.466] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:32.181] INFO: Expecting 41600 events.
[11:44:35.458] INFO: 41600 events read in total (2750ms).
[11:44:35.459] INFO: Test took 3973ms.
[11:44:35.498] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:36.214] INFO: Expecting 41600 events.
[11:44:39.493] INFO: 41600 events read in total (2752ms).
[11:44:39.494] INFO: Test took 3976ms.
[11:44:39.533] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:40.250] INFO: Expecting 41600 events.
[11:44:43.560] INFO: 41600 events read in total (2784ms).
[11:44:43.561] INFO: Test took 4008ms.
[11:44:43.599] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:44.318] INFO: Expecting 41600 events.
[11:44:47.602] INFO: 41600 events read in total (2757ms).
[11:44:47.603] INFO: Test took 3985ms.
[11:44:47.641] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:48.357] INFO: Expecting 41600 events.
[11:44:51.637] INFO: 41600 events read in total (2753ms).
[11:44:51.638] INFO: Test took 3976ms.
[11:44:51.676] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:52.394] INFO: Expecting 41600 events.
[11:44:55.664] INFO: 41600 events read in total (2743ms).
[11:44:55.665] INFO: Test took 3969ms.
[11:44:55.703] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:44:56.417] INFO: Expecting 41600 events.
[11:44:59.696] INFO: 41600 events read in total (2752ms).
[11:44:59.697] INFO: Test took 3974ms.
[11:44:59.735] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:00.449] INFO: Expecting 41600 events.
[11:45:03.805] INFO: 41600 events read in total (2829ms).
[11:45:03.806] INFO: Test took 4051ms.
[11:45:03.845] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:04.559] INFO: Expecting 41600 events.
[11:45:07.847] INFO: 41600 events read in total (2761ms).
[11:45:07.848] INFO: Test took 3984ms.
[11:45:07.887] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:08.599] INFO: Expecting 41600 events.
[11:45:11.830] INFO: 41600 events read in total (2704ms).
[11:45:11.831] INFO: Test took 3924ms.
[11:45:11.871] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:12.581] INFO: Expecting 41600 events.
[11:45:15.879] INFO: 41600 events read in total (2771ms).
[11:45:15.880] INFO: Test took 3990ms.
[11:45:15.919] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:16.636] INFO: Expecting 41600 events.
[11:45:19.919] INFO: 41600 events read in total (2756ms).
[11:45:19.920] INFO: Test took 3981ms.
[11:45:19.960] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:20.672] INFO: Expecting 41600 events.
[11:45:23.986] INFO: 41600 events read in total (2787ms).
[11:45:23.987] INFO: Test took 4008ms.
[11:45:24.026] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:24.737] INFO: Expecting 41600 events.
[11:45:27.950] INFO: 41600 events read in total (2686ms).
[11:45:27.951] INFO: Test took 3904ms.
[11:45:27.990] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:28.703] INFO: Expecting 41600 events.
[11:45:31.977] INFO: 41600 events read in total (2747ms).
[11:45:31.978] INFO: Test took 3969ms.
[11:45:32.017] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:32.728] INFO: Expecting 41600 events.
[11:45:35.951] INFO: 41600 events read in total (2696ms).
[11:45:35.952] INFO: Test took 3915ms.
[11:45:35.991] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:36.344] INFO: enter test to run
[11:45:42.061] INFO: test: HighRate no parameter change
[11:45:42.061] INFO: running: highrate
[11:45:42.062] INFO: ----------------------------------------------------------------------
[11:45:42.062] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:45:42.062] INFO: ----------------------------------------------------------------------
[11:45:42.694] INFO: Expecting 208000 events.
[11:45:55.006] INFO: 208000 events read in total (11785ms).
[11:45:55.009] INFO: Test took 12941ms.
[11:45:55.181] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:45:55.442] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:45:55.442] INFO: number of red-efficiency pixels: 80 58 101 148 178 181 184 84 108 144 111 116 106 61 34 37
[11:45:55.442] INFO: number of X-ray hits detected: 71769 49599 81451 122694 132056 134234 132638 90740 88625 114498 115769 97794 102609 62453 27020 31686
[11:45:55.442] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:45:55.442] INFO: number of Vcal hits detected: 207918 207941 207897 207850 207814 207813 207810 207913 207887 207856 207885 207883 207892 207939 207965 207963
[11:45:55.442] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[11:45:55.442] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 99.9 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[11:45:55.442] INFO: X-ray hit rate [MHz/cm2]: 21.0 14.5 23.9 36.0 38.7 39.3 38.9 26.6 26.0 33.6 33.9 28.7 30.1 18.3 7.9 9.3
[11:45:55.442] INFO: PixTestHighRate::doXPixelAlive() done
[11:45:55.488] INFO: PixTest:: pg_setup set to default.
[11:45:55.500] INFO: enter test to run
[11:46:21.205] INFO: test: HighRate no parameter change
[11:46:21.205] INFO: running: highrate
[11:46:21.206] INFO: ----------------------------------------------------------------------
[11:46:21.206] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:46:21.206] INFO: ----------------------------------------------------------------------
[11:46:21.825] INFO: Expecting 208000 events.
[11:46:36.102] INFO: 208000 events read in total (13750ms).
[11:46:36.109] INFO: Test took 14894ms.
[11:46:36.452] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:46:36.772] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:46:36.772] INFO: number of red-efficiency pixels: 299 177 325 524 572 578 766 328 313 577 441 418 348 228 78 79
[11:46:36.773] INFO: number of X-ray hits detected: 149858 103424 171515 256421 276019 280996 276210 190264 185678 238230 240370 203971 215012 131344 56732 66820
[11:46:36.773] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:46:36.773] INFO: number of Vcal hits detected: 207669 207813 207644 207428 207373 207349 207102 207655 207670 207352 207521 207550 207628 207758 207922 207918
[11:46:36.773] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.7 99.6 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[11:46:36.773] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.7 99.7 99.7 99.6 99.8 99.8 99.7 99.8 99.8 99.8 99.9 100.0 100.0
[11:46:36.773] INFO: X-ray hit rate [MHz/cm2]: 43.9 30.3 50.3 75.2 80.9 82.4 81.0 55.8 54.4 69.8 70.5 59.8 63.0 38.5 16.6 19.6
[11:46:36.773] INFO: PixTestHighRate::doXPixelAlive() done
[11:46:36.817] INFO: PixTest:: pg_setup set to default.
[11:46:36.832] INFO: enter test to run
[11:46:59.668] INFO: test: HighRate no parameter change
[11:46:59.668] INFO: running: highrate
[11:46:59.670] INFO: ----------------------------------------------------------------------
[11:46:59.670] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[11:46:59.670] INFO: ----------------------------------------------------------------------
[11:47:00.289] INFO: Expecting 208000 events.
[11:47:17.483] INFO: 208000 events read in total (16667ms).
[11:47:17.492] INFO: Test took 17813ms.
[11:47:18.035] INFO: Fetched DAQ statistics. Counters are being reset now.
[11:47:18.414] INFO: number of dead pixels (per ROC): 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[11:47:18.414] INFO: number of red-efficiency pixels: 596 319 746 1211 1359 1433 1813 727 619 1375 1036 999 773 505 108 134
[11:47:18.414] INFO: number of X-ray hits detected: 225695 156680 259021 386739 416426 425031 416788 287639 281342 360518 363706 307908 324714 198873 85743 101395
[11:47:18.414] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[11:47:18.414] INFO: number of Vcal hits detected: 207242 207654 206993 206425 206171 206042 205277 207062 207276 206187 206699 206726 207114 207374 207879 207859
[11:47:18.414] INFO: Vcal hit fiducial efficiency (%): 99.7 99.8 99.6 99.3 99.2 99.1 98.8 99.6 99.7 99.2 99.4 99.5 99.6 99.7 99.9 99.9
[11:47:18.414] INFO: Vcal hit overall efficiency (%): 99.6 99.8 99.5 99.2 99.1 99.1 98.7 99.5 99.7 99.1 99.4 99.4 99.6 99.7 99.9 99.9
[11:47:18.414] INFO: X-ray hit rate [MHz/cm2]: 66.2 45.9 75.9 113.4 122.1 124.6 122.2 84.3 82.5 105.7 106.6 90.3 95.2 58.3 25.1 29.7
[11:47:18.414] INFO: PixTestHighRate::doXPixelAlive() done
[11:47:18.462] INFO: PixTest:: pg_setup set to default.
[11:47:18.480] INFO: enter test to run
[11:47:21.804] INFO: test: exit no parameter change
[11:47:22.139] QUIET: Connection to board 32 closed.
[11:47:22.141] INFO: pXar: this is the end, my friend