[14:03:38.135] INFO: *** Welcome to pxar ***
[14:03:38.135] INFO: *** Today: 2016/09/16
[14:03:39.299] INFO: *** Version: v1.9.0-818-g96727
[14:03:39.299] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//dacParameters35_C15.dat
[14:03:39.324] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//tbmParameters_C0b.dat
[14:03:39.343] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//defaultMaskFile.dat
[14:03:39.361] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C15.dat
[14:03:39.574] INFO: clk: 4
[14:03:39.574] INFO: ctr: 4
[14:03:39.574] INFO: sda: 19
[14:03:39.574] INFO: tin: 9
[14:03:39.574] INFO: level: 15
[14:03:39.574] INFO: triggerdelay: 0
[14:03:39.574] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[14:03:39.574] INFO: Log level: INFO
[14:03:39.590] QUIET: Connection to board DTB_WREKRL opened.
[14:03:39.593] 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:
------------------------------------------------------
[14:03:39.596] INFO: RPC call hashes of host and DTB match: 398089610
[14:03:41.130] INFO: DUT info:
[14:03:41.130] INFO: The DUT currently contains the following objects:
[14:03:41.130] INFO: 2 TBM Cores tbm08c (2 ON)
[14:03:41.130] INFO: TBM Core alpha (0): 7 registers set
[14:03:41.130] INFO: TBM Core beta (1): 7 registers set
[14:03:41.130] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[14:03:41.130] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.130] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.130] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.130] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.130] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.130] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.130] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.130] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.131] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.131] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.131] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.131] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.131] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.131] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.131] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.131] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[14:03:41.534] INFO: enter 'restricted' command line mode
[14:03:41.534] INFO: enter test to run
[14:03:49.802] INFO: test: PixelAlive no parameter change
[14:03:49.802] INFO: running: pixelalive
[14:03:49.811] INFO: ----------------------------------------------------------------------
[14:03:49.812] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[14:03:49.812] INFO: ----------------------------------------------------------------------
[14:03:50.135] INFO: Expecting 41600 events.
[14:03:54.507] INFO: 41600 events read in total (3654ms).
[14:03:54.670] INFO: Test took 4855ms.
[14:03:54.683] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:03:54.952] INFO: PixTestAlive::aliveTest() done
[14:03:54.952] INFO: number of dead pixels (per ROC): 0 0 0 1 0 0 0 0 0 0 0 0 2 0 0 0
[14:03:54.990] INFO: enter test to run
[14:04:14.650] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[14:04:14.650] INFO: running: highrate
[14:04:14.651] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[14:04:15.104] INFO: ----------------------------------------------------------------------
[14:04:15.104] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[14:04:15.104] INFO: ----------------------------------------------------------------------
[14:04:15.104] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[14:04:15.104] INFO: edge/corner pixel THR is adjusted
[14:04:15.104] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:04:16.063] INFO: Collecting data for 5 seconds...
[14:04:21.083] INFO: Done with hot pixel readout
[14:04:36.410] INFO: PixTest:: pg_setup set to default.
[14:04:36.442] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:04:36.442] INFO: 679 hot pixels found in step 0
[14:04:37.440] INFO: Collecting data for 5 seconds...
[14:04:42.460] INFO: Done with hot pixel readout
[14:04:55.570] INFO: PixTest:: pg_setup set to default.
[14:04:55.571] INFO: 556 hot pixels found in step 1
[14:04:56.573] INFO: Collecting data for 5 seconds...
[14:05:01.593] INFO: Done with hot pixel readout
[14:05:13.647] INFO: PixTest:: pg_setup set to default.
[14:05:13.647] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:05:13.648] INFO: 306 hot pixels found in step 2
[14:05:14.646] INFO: Collecting data for 5 seconds...
[14:05:19.667] INFO: Done with hot pixel readout
[14:05:31.152] INFO: PixTest:: pg_setup set to default.
[14:05:31.153] INFO: 91 hot pixels found in step 3
[14:05:32.146] INFO: Collecting data for 5 seconds...
[14:05:37.162] INFO: Done with hot pixel readout
[14:05:48.939] INFO: PixTest:: pg_setup set to default.
[14:05:48.940] INFO: 29 hot pixels found in step 4
[14:05:49.935] INFO: Collecting data for 5 seconds...
[14:05:54.952] INFO: Done with hot pixel readout
[14:06:06.477] INFO: PixTest:: pg_setup set to default.
[14:06:06.477] INFO: 39 hot pixels found in step 5
[14:06:07.472] INFO: Collecting data for 5 seconds...
[14:06:12.491] INFO: Done with hot pixel readout
[14:06:23.474] INFO: PixTest:: pg_setup set to default.
[14:06:23.475] INFO: 22 hot pixels found in step 6
[14:06:24.470] INFO: Collecting data for 5 seconds...
[14:06:29.487] INFO: Done with hot pixel readout
[14:06:41.273] INFO: PixTest:: pg_setup set to default.
[14:06:41.274] INFO: 27 hot pixels found in step 7
[14:06:42.268] INFO: Collecting data for 5 seconds...
[14:06:47.284] INFO: Done with hot pixel readout
[14:06:59.175] INFO: PixTest:: pg_setup set to default.
[14:06:59.175] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[14:06:59.176] INFO: 20 hot pixels found in step 8
[14:07:00.171] INFO: Collecting data for 5 seconds...
[14:07:05.186] INFO: Done with hot pixel readout
[14:07:17.099] INFO: PixTest:: pg_setup set to default.
[14:07:17.100] INFO: 15 hot pixels found in step 9
[14:07:18.095] INFO: Collecting data for 5 seconds...
[14:07:23.112] INFO: Done with hot pixel readout
[14:07:34.975] INFO: PixTest:: pg_setup set to default.
[14:07:34.976] INFO: 22 hot pixels found in step 10
[14:07:35.971] INFO: Collecting data for 5 seconds...
[14:07:40.988] INFO: Done with hot pixel readout
[14:07:52.886] INFO: PixTest:: pg_setup set to default.
[14:07:52.887] INFO: 19 hot pixels found in step 11
[14:07:53.882] INFO: Collecting data for 5 seconds...
[14:07:58.898] INFO: Done with hot pixel readout
[14:08:10.788] INFO: PixTest:: pg_setup set to default.
[14:08:10.789] INFO: 21 hot pixels found in step 12
[14:08:11.783] INFO: Collecting data for 5 seconds...
[14:08:16.800] INFO: Done with hot pixel readout
[14:08:28.685] INFO: PixTest:: pg_setup set to default.
[14:08:28.686] INFO: 18 hot pixels found in step 13
[14:08:29.681] INFO: Collecting data for 5 seconds...
[14:08:34.698] INFO: Done with hot pixel readout
[14:08:46.565] INFO: PixTest:: pg_setup set to default.
[14:08:46.566] INFO: 13 hot pixels found in step 14
[14:08:46.606] INFO: 13 hot pixels could not be trimmed and have been masked.
[14:08:46.690] INFO: PixTest::trimHotPixels() done
[14:08:46.704] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C0.dat
[14:08:46.710] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C1.dat
[14:08:46.715] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C2.dat
[14:08:46.721] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C3.dat
[14:08:46.726] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C4.dat
[14:08:46.731] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C5.dat
[14:08:46.737] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C6.dat
[14:08:46.742] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C7.dat
[14:08:46.747] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C8.dat
[14:08:46.753] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C9.dat
[14:08:46.758] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C10.dat
[14:08:46.763] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C11.dat
[14:08:46.769] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C12.dat
[14:08:46.774] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C13.dat
[14:08:46.779] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C14.dat
[14:08:46.785] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C15.dat
[14:08:46.790] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//defaultMaskFile.dat
[14:08:46.808] INFO: enter test to run
[14:09:07.216] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[14:09:07.216] INFO: running: highrate
[14:09:07.221] INFO: ----------------------------------------------------------------------
[14:09:07.221] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[14:09:07.221] INFO: ----------------------------------------------------------------------
[14:09:07.221] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[14:09:07.221] INFO: edge/corner pixel THR is adjusted
[14:09:07.221] INFO: PixTestHighRate::trimHotPixels: step 0...
[14:09:08.179] INFO: Collecting data for 1 seconds...
[14:09:09.183] INFO: Done with hot pixel readout
[14:09:13.256] INFO: PixTest:: pg_setup set to default.
[14:09:13.257] INFO: 0 hot pixels found in step 0
[14:09:13.262] INFO: 0 hot pixels could not be trimmed and have been masked.
[14:09:13.351] INFO: PixTest::trimHotPixels() done
[14:09:13.351] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C0.dat
[14:09:13.363] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C1.dat
[14:09:13.372] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C2.dat
[14:09:13.377] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C3.dat
[14:09:13.383] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C4.dat
[14:09:13.388] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C5.dat
[14:09:13.393] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C6.dat
[14:09:13.398] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C7.dat
[14:09:13.403] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C8.dat
[14:09:13.408] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C9.dat
[14:09:13.413] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C10.dat
[14:09:13.419] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C11.dat
[14:09:13.424] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C12.dat
[14:09:13.429] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C13.dat
[14:09:13.434] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C14.dat
[14:09:13.439] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//trimParameters35_C15.dat
[14:09:13.445] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-Q-3-28_FPIXTest-17C-Nebraska-160901-1350-150V_2016-09-01_13h50m_1472755855/000_FPIXTest_p17//defaultMaskFile.dat
[14:09:13.456] INFO: enter test to run
[14:09:35.480] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[14:09:35.480] INFO: running: xray
[14:09:35.499] INFO: ----------------------------------------------------------------------
[14:09:35.499] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:09:35.499] INFO: ----------------------------------------------------------------------
[14:09:36.486] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:09:47.707] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[14:10:17.205] INFO: Resuming triggers.
[14:10:28.431] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[14:10:58.084] INFO: Resuming triggers.
[14:11:09.305] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[14:11:38.875] INFO: Resuming triggers.
[14:11:50.090] INFO: run duration 44 seconds, buffer almost full (81%), pausing triggers.
[14:12:19.526] INFO: Resuming triggers.
[14:12:30.742] INFO: run duration 55 seconds, buffer almost full (81%), pausing triggers.
[14:13:00.957] INFO: Resuming triggers.
[14:13:12.168] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[14:13:41.325] INFO: Resuming triggers.
[14:13:52.530] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:14:22.758] INFO: Resuming triggers.
[14:14:33.940] INFO: run duration 89 seconds, buffer almost full (81%), pausing triggers.
[14:15:03.653] INFO: Resuming triggers.
[14:15:14.302] INFO: data taking finished, elapsed time: 100 seconds.
[14:15:43.028] INFO: PixTest:: pg_setup set to default.
[14:15:43.031] INFO: PixTestXray::doPhRun() done
[14:15:43.171] INFO: enter test to run
[14:16:22.693] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[14:16:22.693] INFO: running: xray
[14:16:22.694] INFO: ----------------------------------------------------------------------
[14:16:22.695] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[14:16:22.695] INFO: ----------------------------------------------------------------------
[14:16:23.658] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[14:16:30.221] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[14:17:01.714] INFO: Resuming triggers.
[14:17:08.283] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[14:17:39.815] INFO: Resuming triggers.
[14:17:46.382] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[14:18:17.518] INFO: Resuming triggers.
[14:18:24.086] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[14:18:54.923] INFO: Resuming triggers.
[14:19:01.488] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[14:19:32.855] INFO: Resuming triggers.
[14:19:39.420] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[14:20:10.228] INFO: Resuming triggers.
[14:20:16.801] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[14:20:47.013] INFO: Resuming triggers.
[14:20:53.583] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[14:21:23.749] INFO: Resuming triggers.
[14:21:30.318] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[14:22:00.542] INFO: Resuming triggers.
[14:22:07.115] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[14:22:37.406] INFO: Resuming triggers.
[14:22:43.975] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[14:23:14.248] INFO: Resuming triggers.
[14:23:20.819] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[14:23:50.979] INFO: Resuming triggers.
[14:23:57.546] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[14:24:27.802] INFO: Resuming triggers.
[14:24:34.364] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[14:25:04.542] INFO: Resuming triggers.
[14:25:11.106] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[14:25:41.340] INFO: Resuming triggers.
[14:25:43.178] INFO: data taking finished, elapsed time: 100 seconds.
[14:25:51.991] INFO: PixTest:: pg_setup set to default.
[14:25:51.994] INFO: PixTestXray::doPhRun() done
[14:25:52.173] INFO: enter test to run
[14:26:41.409] INFO: test: HighRate no parameter change
[14:26:41.409] INFO: running: highrate
[14:26:41.425] INFO: ----------------------------------------------------------------------
[14:26:41.425] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[14:26:41.425] INFO: ----------------------------------------------------------------------
[14:26:41.579] INFO: Expecting 768 events.
[14:26:42.725] INFO: 768 events read in total (431ms).
[14:26:42.725] INFO: Test took 1280ms.
[14:26:43.528] INFO: Expecting 41600 events.
[14:26:46.768] INFO: 41600 events read in total (2713ms).
[14:26:46.769] INFO: Test took 4012ms.
[14:26:46.810] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:47.516] INFO: Expecting 41600 events.
[14:26:50.833] INFO: 41600 events read in total (2790ms).
[14:26:50.834] INFO: Test took 4004ms.
[14:26:50.876] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:51.584] INFO: Expecting 41600 events.
[14:26:54.898] INFO: 41600 events read in total (2787ms).
[14:26:54.899] INFO: Test took 4002ms.
[14:26:54.942] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:55.644] INFO: Expecting 41600 events.
[14:26:58.921] INFO: 41600 events read in total (2751ms).
[14:26:58.922] INFO: Test took 3957ms.
[14:26:58.966] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:26:59.670] INFO: Expecting 41600 events.
[14:27:03.037] INFO: 41600 events read in total (2840ms).
[14:27:03.039] INFO: Test took 4051ms.
[14:27:03.084] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:03.782] INFO: Expecting 41600 events.
[14:27:07.094] INFO: 41600 events read in total (2785ms).
[14:27:07.095] INFO: Test took 3991ms.
[14:27:07.143] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:07.833] INFO: Expecting 41600 events.
[14:27:11.165] INFO: 41600 events read in total (2805ms).
[14:27:11.166] INFO: Test took 4002ms.
[14:27:11.208] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:11.917] INFO: Expecting 41600 events.
[14:27:15.299] INFO: 41600 events read in total (2855ms).
[14:27:15.300] INFO: Test took 4072ms.
[14:27:15.343] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:16.045] INFO: Expecting 41600 events.
[14:27:19.329] INFO: 41600 events read in total (2757ms).
[14:27:19.330] INFO: Test took 3965ms.
[14:27:19.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:20.077] INFO: Expecting 41600 events.
[14:27:23.464] INFO: 41600 events read in total (2860ms).
[14:27:23.466] INFO: Test took 4073ms.
[14:27:23.508] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:24.205] INFO: Expecting 41600 events.
[14:27:27.502] INFO: 41600 events read in total (2771ms).
[14:27:27.503] INFO: Test took 3973ms.
[14:27:27.545] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:28.251] INFO: Expecting 41600 events.
[14:27:31.463] INFO: 41600 events read in total (2685ms).
[14:27:31.464] INFO: Test took 3897ms.
[14:27:31.512] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:32.190] INFO: Expecting 41600 events.
[14:27:35.551] INFO: 41600 events read in total (2834ms).
[14:27:35.552] INFO: Test took 4017ms.
[14:27:35.592] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:36.301] INFO: Expecting 41600 events.
[14:27:39.569] INFO: 41600 events read in total (2741ms).
[14:27:39.570] INFO: Test took 3958ms.
[14:27:39.611] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:40.317] INFO: Expecting 41600 events.
[14:27:43.660] INFO: 41600 events read in total (2817ms).
[14:27:43.661] INFO: Test took 4029ms.
[14:27:43.700] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:44.400] INFO: Expecting 41600 events.
[14:27:47.724] INFO: 41600 events read in total (2797ms).
[14:27:47.725] INFO: Test took 3999ms.
[14:27:47.766] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:48.476] INFO: Expecting 41600 events.
[14:27:51.763] INFO: 41600 events read in total (2760ms).
[14:27:51.765] INFO: Test took 3979ms.
[14:27:51.807] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:52.505] INFO: Expecting 41600 events.
[14:27:55.809] INFO: 41600 events read in total (2778ms).
[14:27:55.810] INFO: Test took 3982ms.
[14:27:55.847] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:27:56.565] INFO: Expecting 41600 events.
[14:27:59.713] INFO: 41600 events read in total (2621ms).
[14:27:59.714] INFO: Test took 3847ms.
[14:27:59.752] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:00.459] INFO: Expecting 41600 events.
[14:28:03.601] INFO: 41600 events read in total (2615ms).
[14:28:03.602] INFO: Test took 3830ms.
[14:28:03.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:28:03.996] INFO: enter test to run
[14:29:20.056] INFO: test: HighRate no parameter change
[14:29:20.056] INFO: running: highrate
[14:29:20.057] INFO: ----------------------------------------------------------------------
[14:29:20.057] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:29:20.057] INFO: ----------------------------------------------------------------------
[14:29:20.676] INFO: Expecting 208000 events.
[14:29:32.710] INFO: 208000 events read in total (11507ms).
[14:29:32.714] INFO: Test took 12648ms.
[14:29:32.867] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:29:33.123] INFO: number of dead pixels (per ROC): 0 38 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[14:29:33.123] INFO: number of red-efficiency pixels: 124 2466 85 339 179 150 156 106 95 127 143 91 110 64 23 34
[14:29:33.123] INFO: number of X-ray hits detected: 69106 73985 68872 111079 115883 122306 118584 82415 73427 101562 100571 83571 90447 53216 19148 21078
[14:29:33.123] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:29:33.123] INFO: number of Vcal hits detected: 207709 202364 207911 206849 207731 207849 207835 207894 207904 207872 207856 207906 207840 207935 207977 207965
[14:29:33.123] INFO: Vcal hit fiducial efficiency (%): 99.9 98.2 100.0 99.4 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:29:33.123] INFO: Vcal hit overall efficiency (%): 99.9 97.3 100.0 99.4 99.9 99.9 99.9 99.9 100.0 99.9 99.9 100.0 99.9 100.0 100.0 100.0
[14:29:33.123] INFO: X-ray hit rate [MHz/cm2]: 20.3 21.7 20.2 32.6 34.0 35.8 34.8 24.2 21.5 29.8 29.5 24.5 26.5 15.6 5.6 6.2
[14:29:33.123] INFO: PixTestHighRate::doXPixelAlive() done
[14:29:33.170] INFO: PixTest:: pg_setup set to default.
[14:29:33.187] INFO: enter test to run
[14:30:17.568] INFO: test: HighRate no parameter change
[14:30:17.568] INFO: running: highrate
[14:30:17.569] INFO: ----------------------------------------------------------------------
[14:30:17.569] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:30:17.569] INFO: ----------------------------------------------------------------------
[14:30:18.192] INFO: Expecting 208000 events.
[14:30:32.057] INFO: 208000 events read in total (13338ms).
[14:30:32.064] INFO: Test took 14486ms.
[14:30:32.378] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:30:32.688] INFO: number of dead pixels (per ROC): 0 37 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[14:30:32.688] INFO: number of red-efficiency pixels: 305 2168 244 704 522 540 518 322 280 409 411 339 310 233 46 74
[14:30:32.688] INFO: number of X-ray hits detected: 144998 133317 143178 230136 240158 255955 246950 171260 154026 210981 209534 174558 188511 111890 39920 44094
[14:30:32.688] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:30:32.688] INFO: number of Vcal hits detected: 207433 202321 207729 205907 207283 207389 207412 207643 207710 207557 207557 207640 207624 207748 207952 207925
[14:30:32.688] INFO: Vcal hit fiducial efficiency (%): 99.7 98.2 99.9 99.0 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[14:30:32.688] INFO: Vcal hit overall efficiency (%): 99.7 97.3 99.9 99.0 99.7 99.7 99.7 99.8 99.9 99.8 99.8 99.8 99.8 99.9 100.0 100.0
[14:30:32.688] INFO: X-ray hit rate [MHz/cm2]: 42.5 39.1 42.0 67.5 70.4 75.0 72.4 50.2 45.1 61.8 61.4 51.2 55.3 32.8 11.7 12.9
[14:30:32.688] INFO: PixTestHighRate::doXPixelAlive() done
[14:30:32.744] INFO: PixTest:: pg_setup set to default.
[14:30:32.762] INFO: enter test to run
[14:31:15.736] INFO: test: HighRate no parameter change
[14:31:15.736] INFO: running: highrate
[14:31:15.737] INFO: ----------------------------------------------------------------------
[14:31:15.737] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[14:31:15.737] INFO: ----------------------------------------------------------------------
[14:31:16.357] INFO: Expecting 208000 events.
[14:31:32.444] INFO: 208000 events read in total (15561ms).
[14:31:32.451] INFO: Test took 16705ms.
[14:31:32.925] INFO: Fetched DAQ statistics. Counters are being reset now.
[14:31:33.284] INFO: number of dead pixels (per ROC): 0 37 0 0 0 0 0 0 0 0 0 0 1 0 0 0
[14:31:33.284] INFO: number of red-efficiency pixels: 558 1722 549 1349 1186 1261 1252 691 588 892 1026 795 744 479 81 89
[14:31:33.284] INFO: number of X-ray hits detected: 218944 181019 217292 349484 365609 386850 374793 260540 234056 321188 316801 264355 286704 170596 60292 66901
[14:31:33.284] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[14:31:33.284] INFO: number of Vcal hits detected: 206968 202395 207314 203977 206224 206292 206325 207119 207330 206941 206730 207091 207098 207410 207917 207905
[14:31:33.284] INFO: Vcal hit fiducial efficiency (%): 99.5 98.2 99.7 98.1 99.2 99.3 99.3 99.6 99.7 99.5 99.4 99.6 99.6 99.8 100.0 100.0
[14:31:33.284] INFO: Vcal hit overall efficiency (%): 99.5 97.3 99.7 98.1 99.1 99.2 99.2 99.6 99.7 99.5 99.4 99.6 99.6 99.7 100.0 100.0
[14:31:33.284] INFO: X-ray hit rate [MHz/cm2]: 64.2 53.1 63.7 102.4 107.2 113.4 109.9 76.4 68.6 94.1 92.9 77.5 84.0 50.0 17.7 19.6
[14:31:33.284] INFO: PixTestHighRate::doXPixelAlive() done
[14:31:33.337] INFO: PixTest:: pg_setup set to default.
[14:31:33.354] INFO: enter test to run
[14:31:56.383] INFO: test: exit no parameter change
[14:31:56.821] QUIET: Connection to board 33 closed.
[14:31:56.835] INFO: pXar: this is the end, my friend