[19:44:25.003] INFO: *** Welcome to pxar ***
[19:44:25.003] INFO: *** Today: 2016/06/24
[19:44:25.019] INFO: *** Version: v1.9.0-814-g7497
[19:44:25.019] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//dacParameters35_C15.dat
[19:44:25.020] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0b.dat
[19:44:25.020] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[19:44:25.020] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[19:44:25.094] INFO: clk: 4
[19:44:25.094] INFO: ctr: 4
[19:44:25.094] INFO: sda: 19
[19:44:25.094] INFO: tin: 9
[19:44:25.094] INFO: level: 15
[19:44:25.094] INFO: triggerdelay: 0
[19:44:25.094] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[19:44:25.094] INFO: Log level: INFO
[19:44:25.107] QUIET: Connection to board DTB_WREK4U opened.
[19:44:25.110] 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:
------------------------------------------------------
[19:44:25.113] INFO: RPC call hashes of host and DTB match: 398089610
[19:44:26.644] INFO: DUT info:
[19:44:26.644] INFO: The DUT currently contains the following objects:
[19:44:26.644] INFO: 2 TBM Cores tbm08c (2 ON)
[19:44:26.644] INFO: TBM Core alpha (0): 7 registers set
[19:44:26.644] INFO: TBM Core beta (1): 7 registers set
[19:44:26.644] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[19:44:26.644] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.644] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.645] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.645] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:26.645] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[19:44:27.047] INFO: enter 'restricted' command line mode
[19:44:27.048] INFO: enter test to run
[19:44:32.893] INFO: test: timing no parameter change
[19:44:32.894] INFO: running: timing
[19:44:32.920] INFO: ######################################################################
[19:44:32.920] INFO: PixTestTiming::doTest()
[19:44:32.920] INFO: ######################################################################
[19:44:32.920] INFO: ----------------------------------------------------------------------
[19:44:32.920] INFO: PixTestTiming::TBMPhaseScan()
[19:44:32.920] INFO: ----------------------------------------------------------------------
[19:49:16.766] INFO: TBM Phase Settings: 232
[19:49:16.766] INFO: 400MHz Phase: 2
[19:49:16.766] INFO: 160MHz Phase: 7
[19:49:16.766] INFO: Functional Phase Area: 3
[19:49:16.786] INFO: Test took 283866 ms.
[19:49:16.786] INFO: PixTestTiming::TBMPhaseScan() done.
[19:49:16.786] INFO: ----------------------------------------------------------------------
[19:49:16.786] INFO: PixTestTiming::ROCDelayScan()
[19:49:16.786] INFO: ----------------------------------------------------------------------
[19:51:24.720] INFO: ROC Delay Settings: 228
[19:51:24.720] INFO: ROC Header-Trailer/Token Delay: 11
[19:51:24.720] INFO: ROC Port 0 Delay: 4
[19:51:24.720] INFO: ROC Port 1 Delay: 4
[19:51:24.720] INFO: Functional ROC Area: 5
[19:51:24.723] INFO: Test took 127937 ms.
[19:51:24.723] INFO: PixTestTiming::ROCDelayScan() done.
[19:51:24.724] INFO: ----------------------------------------------------------------------
[19:51:24.724] INFO: PixTestTiming::TimingTest()
[19:51:24.724] INFO: ----------------------------------------------------------------------
[19:51:40.899] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:51:55.889] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:52:10.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:52:25.863] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:52:40.857] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:52:55.865] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:10.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:25.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:40.844] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:55.857] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:56.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:53:56.257] INFO: ----------------------------------------------------------------------
[19:53:56.257] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[19:53:56.257] INFO: ----------------------------------------------------------------------
[19:53:56.257] INFO: ----------------------------------------------------------------------
[19:53:56.257] INFO: Read back bit status: 1
[19:53:56.257] INFO: ----------------------------------------------------------------------
[19:53:56.257] INFO: ----------------------------------------------------------------------
[19:53:56.257] INFO: Timings are good!
[19:53:56.257] INFO: ----------------------------------------------------------------------
[19:53:56.257] INFO: Test took 151534 ms.
[19:53:56.257] INFO: PixTestTiming::TimingTest() done.
[19:53:56.266] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0a.dat
[19:53:56.266] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//tbmParameters_C0b.dat
[19:53:56.266] INFO: PixTestTiming::doTest took 563351 ms.
[19:53:56.266] INFO: PixTestTiming::doTest() done
[19:53:56.266] INFO: Write out TBMPhaseScan_0_V0
[19:53:56.291] INFO: Write out TBMPhaseScan_1_V0
[19:53:56.291] INFO: Write out CombinedTBMPhaseScan_V0
[19:53:56.293] INFO: Write out ROCDelayScan3_V0
[19:53:56.294] INFO: enter test to run
[19:54:09.730] INFO: test: PixelAlive no parameter change
[19:54:09.730] INFO: running: pixelalive
[19:54:09.734] INFO: ----------------------------------------------------------------------
[19:54:09.734] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[19:54:09.734] INFO: ----------------------------------------------------------------------
[19:54:10.060] INFO: Expecting 41600 events.
[19:54:14.388] INFO: 41600 events read in total (3612ms).
[19:54:14.388] INFO: Test took 4650ms.
[19:54:14.395] INFO: Fetched DAQ statistics. Counters are being reset now.
[19:54:14.790] INFO: PixTestAlive::aliveTest() done
[19:54:14.790] INFO: number of dead pixels (per ROC): 0 8 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[19:54:14.793] INFO: enter test to run
[19:54:40.257] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[19:54:40.257] INFO: running: highrate
[19:54:40.258] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[19:54:40.408] INFO: ----------------------------------------------------------------------
[19:54:40.408] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[19:54:40.408] INFO: ----------------------------------------------------------------------
[19:54:40.408] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[19:54:40.408] INFO: edge/corner pixel THR is adjusted
[19:54:40.408] INFO: PixTestHighRate::trimHotPixels: step 0...
[19:54:41.366] INFO: Collecting data for 5 seconds...
[19:54:46.382] INFO: Done with hot pixel readout
[19:54:57.939] INFO: PixTest:: pg_setup set to default.


[19:54:57.940] INFO: 2 hot pixels found in step 0
[19:54:57.974] INFO: 2 hot pixels could not be trimmed and have been masked.
[19:54:57.978] INFO: PixTest::trimHotPixels() done
[19:54:57.978] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat
[19:54:57.983] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C1.dat
[19:54:57.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C2.dat
[19:54:57.995] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C3.dat
[19:54:57.001] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C4.dat
[19:54:58.006] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C5.dat
[19:54:58.011] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C6.dat
[19:54:58.016] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C7.dat
[19:54:58.021] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C8.dat
[19:54:58.026] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C9.dat
[19:54:58.032] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C10.dat
[19:54:58.037] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C11.dat
[19:54:58.042] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C12.dat
[19:54:58.047] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C13.dat
[19:54:58.052] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C14.dat
[19:54:58.057] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[19:54:58.063] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[19:54:58.073] INFO: enter test to run
[19:55:17.865] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[19:55:17.865] INFO: running: highrate
[19:55:17.869] INFO: ----------------------------------------------------------------------
[19:55:17.870] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[19:55:17.870] INFO: ----------------------------------------------------------------------
[19:55:17.870] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[19:55:17.870] INFO: edge/corner pixel THR is adjusted
[19:55:17.870] INFO: PixTestHighRate::trimHotPixels: step 0...
[19:55:18.828] INFO: Collecting data for 1 seconds...
[19:55:19.831] INFO: Done with hot pixel readout
[19:55:23.842] INFO: PixTest:: pg_setup set to default.
[19:55:23.843] INFO: 0 hot pixels found in step 0
[19:55:23.849] INFO: 0 hot pixels could not be trimmed and have been masked.
[19:55:23.939] INFO: PixTest::trimHotPixels() done
[19:55:23.939] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C0.dat
[19:55:23.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C1.dat
[19:55:23.958] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C2.dat
[19:55:23.963] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C3.dat
[19:55:23.968] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C4.dat
[19:55:23.973] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C5.dat
[19:55:23.979] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C6.dat
[19:55:23.984] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C7.dat
[19:55:23.989] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C8.dat
[19:55:23.994] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C9.dat
[19:55:23.999] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C10.dat
[19:55:24.004] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C11.dat
[19:55:24.010] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C12.dat
[19:55:24.015] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C13.dat
[19:55:24.020] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C14.dat
[19:55:24.025] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//trimParameters35_C15.dat
[19:55:24.030] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-1-05_FPIXTest-17C-FNAL-160623-1419_2016-06-23_14h20m_1466709614/000_FPIXTest_p17//defaultMaskFile.dat
[19:55:24.040] INFO: enter test to run
[19:55:44.057] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[19:55:44.057] INFO: running: xray
[19:55:44.058] INFO: ----------------------------------------------------------------------
[19:55:44.058] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[19:55:44.058] INFO: ----------------------------------------------------------------------
[19:55:45.021] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[19:55:56.593] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[19:56:26.007] INFO: Resuming triggers.
[19:56:37.581] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[19:57:07.123] INFO: Resuming triggers.
[19:57:18.697] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[19:57:48.213] INFO: Resuming triggers.
[19:57:59.787] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[19:58:29.590] INFO: Resuming triggers.
[19:58:41.164] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[19:59:10.988] INFO: Resuming triggers.
[19:59:22.559] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[19:59:52.064] INFO: Resuming triggers.
[20:00:03.638] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[20:00:33.660] INFO: Resuming triggers.
[20:00:45.231] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[20:01:15.108] INFO: Resuming triggers.
[20:01:22.875] INFO: data taking finished, elapsed time: 100 seconds.
[20:01:43.174] INFO: PixTest:: pg_setup set to default.
[20:01:43.177] INFO: PixTestXray::doPhRun() done
[20:01:43.317] INFO: enter test to run
[20:02:04.398] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[20:02:04.399] INFO: running: xray
[20:02:04.400] INFO: ----------------------------------------------------------------------
[20:02:04.400] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[20:02:04.400] INFO: ----------------------------------------------------------------------
[20:02:05.364] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[20:02:11.928] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[20:02:42.044] INFO: Resuming triggers.
[20:02:48.613] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[20:03:18.836] INFO: Resuming triggers.
[20:03:25.400] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[20:03:55.539] INFO: Resuming triggers.
[20:04:02.110] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[20:04:32.272] INFO: Resuming triggers.
[20:04:38.839] INFO: run duration 32 seconds, buffer almost full (81%), pausing triggers.
[20:05:08.951] INFO: Resuming triggers.
[20:05:15.518] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[20:05:45.706] INFO: Resuming triggers.
[20:05:52.268] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[20:06:22.431] INFO: Resuming triggers.
[20:06:28.993] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[20:06:59.221] INFO: Resuming triggers.
[20:07:05.784] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[20:07:35.972] INFO: Resuming triggers.
[20:07:42.534] INFO: run duration 65 seconds, buffer almost full (81%), pausing triggers.
[20:08:12.654] INFO: Resuming triggers.
[20:08:19.220] INFO: run duration 71 seconds, buffer almost full (81%), pausing triggers.
[20:08:49.384] INFO: Resuming triggers.
[20:08:55.945] INFO: run duration 78 seconds, buffer almost full (81%), pausing triggers.
[20:09:26.112] INFO: Resuming triggers.
[20:09:32.675] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[20:10:03.116] INFO: Resuming triggers.
[20:10:09.672] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[20:10:40.499] INFO: Resuming triggers.
[20:10:47.064] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[20:11:17.907] INFO: Resuming triggers.
[20:11:19.772] INFO: data taking finished, elapsed time: 100 seconds.
[20:11:28.898] INFO: PixTest:: pg_setup set to default.
[20:11:28.901] INFO: PixTestXray::doPhRun() done
[20:11:29.052] INFO: enter test to run
[20:11:47.290] INFO: test: HighRate no parameter change
[20:11:47.291] INFO: running: highrate
[20:11:47.292] INFO: ----------------------------------------------------------------------
[20:11:47.292] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[20:11:47.292] INFO: ----------------------------------------------------------------------
[20:11:47.439] INFO: Expecting 768 events.
[20:11:48.577] INFO: 768 events read in total (422ms).
[20:11:48.577] INFO: Test took 1272ms.
[20:11:49.380] INFO: Expecting 41600 events.
[20:11:52.534] INFO: 41600 events read in total (2627ms).
[20:11:52.535] INFO: Test took 3951ms.
[20:11:52.568] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:53.297] INFO: Expecting 41600 events.
[20:11:56.532] INFO: 41600 events read in total (2708ms).
[20:11:56.533] INFO: Test took 3948ms.
[20:11:56.567] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:11:57.291] INFO: Expecting 41600 events.
[20:12:00.526] INFO: 41600 events read in total (2709ms).
[20:12:00.527] INFO: Test took 3943ms.
[20:12:00.560] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:01.282] INFO: Expecting 41600 events.
[20:12:04.597] INFO: 41600 events read in total (2788ms).
[20:12:04.597] INFO: Test took 4019ms.
[20:12:04.632] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:05.356] INFO: Expecting 41600 events.
[20:12:08.627] INFO: 41600 events read in total (2744ms).
[20:12:08.627] INFO: Test took 3978ms.
[20:12:08.662] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:09.384] INFO: Expecting 41600 events.
[20:12:12.703] INFO: 41600 events read in total (2793ms).
[20:12:12.704] INFO: Test took 4024ms.
[20:12:12.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:13.442] INFO: Expecting 41600 events.
[20:12:16.725] INFO: 41600 events read in total (2756ms).
[20:12:16.726] INFO: Test took 3970ms.
[20:12:16.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:17.482] INFO: Expecting 41600 events.
[20:12:20.785] INFO: 41600 events read in total (2777ms).
[20:12:20.786] INFO: Test took 4009ms.
[20:12:20.820] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:21.541] INFO: Expecting 41600 events.
[20:12:24.804] INFO: 41600 events read in total (2736ms).
[20:12:24.805] INFO: Test took 3968ms.
[20:12:24.838] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:25.562] INFO: Expecting 41600 events.
[20:12:28.855] INFO: 41600 events read in total (2766ms).
[20:12:28.855] INFO: Test took 3999ms.
[20:12:28.890] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:29.601] INFO: Expecting 41600 events.
[20:12:32.835] INFO: 41600 events read in total (2707ms).
[20:12:32.836] INFO: Test took 3929ms.
[20:12:32.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:33.596] INFO: Expecting 41600 events.
[20:12:36.853] INFO: 41600 events read in total (2730ms).
[20:12:36.854] INFO: Test took 3967ms.
[20:12:36.887] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:37.612] INFO: Expecting 41600 events.
[20:12:40.892] INFO: 41600 events read in total (2753ms).
[20:12:40.893] INFO: Test took 3988ms.
[20:12:40.926] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:41.645] INFO: Expecting 41600 events.
[20:12:44.890] INFO: 41600 events read in total (2718ms).
[20:12:44.891] INFO: Test took 3948ms.
[20:12:44.925] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:45.645] INFO: Expecting 41600 events.
[20:12:48.946] INFO: 41600 events read in total (2774ms).
[20:12:48.946] INFO: Test took 4004ms.
[20:12:48.981] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:49.701] INFO: Expecting 41600 events.
[20:12:52.974] INFO: 41600 events read in total (2746ms).
[20:12:52.974] INFO: Test took 3976ms.
[20:12:53.008] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:53.730] INFO: Expecting 41600 events.
[20:12:57.011] INFO: 41600 events read in total (2754ms).
[20:12:57.012] INFO: Test took 3987ms.
[20:12:57.047] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:12:57.769] INFO: Expecting 41600 events.
[20:13:01.071] INFO: 41600 events read in total (2775ms).
[20:13:01.072] INFO: Test took 4007ms.
[20:13:01.107] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:13:01.833] INFO: Expecting 41600 events.
[20:13:05.136] INFO: 41600 events read in total (2777ms).
[20:13:05.137] INFO: Test took 4012ms.
[20:13:05.170] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:13:05.889] INFO: Expecting 41600 events.
[20:13:08.951] INFO: 41600 events read in total (2535ms).
[20:13:08.952] INFO: Test took 3764ms.
[20:13:08.985] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:13:09.352] INFO: enter test to run
[20:13:22.202] INFO: test: HighRate no parameter change
[20:13:22.202] INFO: running: highrate
[20:13:22.203] INFO: ----------------------------------------------------------------------
[20:13:22.203] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[20:13:22.203] INFO: ----------------------------------------------------------------------
[20:13:22.825] INFO: Expecting 208000 events.
[20:13:34.696] INFO: 208000 events read in total (11344ms).
[20:13:34.699] INFO: Test took 12487ms.
[20:13:34.841] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:13:35.091] INFO: number of dead pixels (per ROC): 0 9 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[20:13:35.091] INFO: number of red-efficiency pixels: 80 55 79 111 112 131 136 96 96 106 120 105 106 61 20 23
[20:13:35.091] INFO: number of X-ray hits detected: 60616 39657 63085 100184 104732 111003 105026 77525 74073 98989 97497 85010 88737 52702 21578 23551
[20:13:35.091] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[20:13:35.091] INFO: number of Vcal hits detected: 207919 207504 207920 207887 207877 207863 207856 207903 207904 207891 207877 207894 207892 207938 207979 207977
[20:13:35.091] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 100.0 100.0 100.0 100.0 100.0
[20:13:35.091] INFO: Vcal hit overall efficiency (%): 100.0 99.8 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0
[20:13:35.091] INFO: X-ray hit rate [MHz/cm2]: 17.8 11.6 18.5 29.4 30.7 32.5 30.8 22.7 21.7 29.0 28.6 24.9 26.0 15.4 6.3 6.9
[20:13:35.091] INFO: PixTestHighRate::doXPixelAlive() done
[20:13:35.137] INFO: PixTest:: pg_setup set to default.
[20:13:35.152] INFO: enter test to run
[20:13:48.610] INFO: test: HighRate no parameter change
[20:13:48.610] INFO: running: highrate
[20:13:48.611] INFO: ----------------------------------------------------------------------
[20:13:48.611] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[20:13:48.611] INFO: ----------------------------------------------------------------------
[20:13:49.228] INFO: Expecting 208000 events.
[20:14:02.835] INFO: 208000 events read in total (13080ms).
[20:14:02.840] INFO: Test took 14219ms.
[20:14:03.140] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:14:03.440] INFO: number of dead pixels (per ROC): 0 9 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[20:14:03.440] INFO: number of red-efficiency pixels: 197 107 245 393 395 564 480 270 281 312 300 249 339 210 55 66
[20:14:03.440] INFO: number of X-ray hits detected: 129773 84306 134498 212638 220923 235747 221477 165927 158034 209701 208384 182397 188257 113583 46492 50858
[20:14:03.440] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[20:14:03.440] INFO: number of Vcal hits detected: 207796 207451 207733 207581 207576 207352 207470 207702 207708 207672 207686 207737 207643 207774 207943 207934
[20:14:03.440] INFO: Vcal hit fiducial efficiency (%): 99.9 100.0 99.9 99.8 99.8 99.7 99.8 99.9 99.9 99.9 99.9 99.9 99.8 99.9 100.0 100.0
[20:14:03.440] INFO: Vcal hit overall efficiency (%): 99.9 99.7 99.9 99.8 99.8 99.7 99.7 99.9 99.9 99.8 99.8 99.9 99.8 99.9 100.0 100.0
[20:14:03.440] INFO: X-ray hit rate [MHz/cm2]: 38.0 24.7 39.4 62.3 64.8 69.1 64.9 48.6 46.3 61.5 61.1 53.5 55.2 33.3 13.6 14.9
[20:14:03.440] INFO: PixTestHighRate::doXPixelAlive() done
[20:14:03.485] INFO: PixTest:: pg_setup set to default.
[20:14:03.498] INFO: enter test to run
[20:14:21.090] INFO: test: HighRate no parameter change
[20:14:21.090] INFO: running: highrate
[20:14:21.091] INFO: ----------------------------------------------------------------------
[20:14:21.091] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[20:14:21.091] INFO: ----------------------------------------------------------------------
[20:14:21.705] INFO: Expecting 208000 events.
[20:14:37.189] INFO: 208000 events read in total (14957ms).
[20:14:37.196] INFO: Test took 16094ms.
[20:14:37.639] INFO: Fetched DAQ statistics. Counters are being reset now.
[20:14:37.985] INFO: number of dead pixels (per ROC): 0 9 0 0 0 0 0 0 0 0 0 0 0 0 0 0
[20:14:37.985] INFO: number of red-efficiency pixels: 407 216 575 851 836 1274 1174 673 598 775 653 599 776 465 98 80
[20:14:37.985] INFO: number of X-ray hits detected: 195786 127878 203500 320263 335027 355425 337014 251494 238301 317302 315498 275341 285821 170577 70089 77267
[20:14:37.985] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[20:14:37.985] INFO: number of Vcal hits detected: 207515 207329 207239 206972 206951 206261 206534 207198 207315 207124 207200 207323 207086 207430 207897 207919
[20:14:37.985] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.7 99.6 99.5 99.2 99.4 99.7 99.7 99.6 99.6 99.7 99.6 99.8 100.0 100.0
[20:14:37.985] INFO: Vcal hit overall efficiency (%): 99.8 99.7 99.6 99.5 99.5 99.2 99.3 99.6 99.7 99.6 99.6 99.7 99.6 99.7 100.0 100.0
[20:14:37.985] INFO: X-ray hit rate [MHz/cm2]: 57.4 37.5 59.6 93.9 98.2 104.2 98.8 73.7 69.8 93.0 92.5 80.7 83.8 50.0 20.5 22.6
[20:14:37.985] INFO: PixTestHighRate::doXPixelAlive() done
[20:14:38.040] INFO: PixTest:: pg_setup set to default.
[20:14:38.057] INFO: enter test to run
[20:14:41.497] INFO: test: exit no parameter change
[20:14:41.959] QUIET: Connection to board 32 closed.
[20:14:41.959] INFO: pXar: this is the end, my friend