[12:48:53.889] INFO: *** Welcome to pxar ***
[12:48:53.889] INFO: *** Today: 2016/09/08
[12:48:55.146] INFO: *** Version: v1.9.0-818-g96727
[12:48:55.146] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//dacParameters35_C15.dat
[12:48:55.277] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:48:55.292] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//defaultMaskFile.dat
[12:48:55.321] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C15.dat
[12:48:55.692] INFO: clk: 4
[12:48:55.692] INFO: ctr: 4
[12:48:55.692] INFO: sda: 19
[12:48:55.692] INFO: tin: 9
[12:48:55.692] INFO: level: 15
[12:48:55.692] INFO: triggerdelay: 0
[12:48:55.692] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[12:48:55.724] INFO: Log level: INFO
[12:48:55.740] QUIET: Connection to board DTB_WREKRL opened.
[12:48:55.744] 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:
------------------------------------------------------
[12:48:55.746] INFO: RPC call hashes of host and DTB match: 398089610
[12:48:57.282] INFO: DUT info:
[12:48:57.282] INFO: The DUT currently contains the following objects:
[12:48:57.282] INFO: 2 TBM Cores tbm08c (2 ON)
[12:48:57.282] INFO: TBM Core alpha (0): 7 registers set
[12:48:57.282] INFO: TBM Core beta (1): 7 registers set
[12:48:57.282] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[12:48:57.282] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.282] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.282] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.282] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.282] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.283] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[12:48:57.715] INFO: enter 'restricted' command line mode
[12:48:57.715] INFO: enter test to run
[12:48:59.315] INFO: test: PixelAlive no parameter change
[12:48:59.315] INFO: running: pixelalive
[12:48:59.401] INFO: ----------------------------------------------------------------------
[12:48:59.401] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[12:48:59.401] INFO: ----------------------------------------------------------------------
[12:48:59.725] INFO: Expecting 41600 events.
[12:49:04.070] INFO: 41600 events read in total (3627ms).
[12:49:04.225] INFO: Test took 4820ms.
[12:49:04.238] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:49:05.009] INFO: PixTestAlive::aliveTest() done
[12:49:05.009] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0
[12:49:05.175] INFO: enter test to run
[12:49:07.403] INFO: test: timing no parameter change
[12:49:07.403] INFO: running: timing
[12:49:07.419] INFO: ######################################################################
[12:49:07.419] INFO: PixTestTiming::doTest()
[12:49:07.419] INFO: ######################################################################
[12:49:07.419] INFO: ----------------------------------------------------------------------
[12:49:07.419] INFO: PixTestTiming::TBMPhaseScan()
[12:49:07.419] INFO: ----------------------------------------------------------------------
[12:53:52.101] INFO: TBM Phase Settings: 240
[12:53:52.101] INFO: 400MHz Phase: 4
[12:53:52.101] INFO: 160MHz Phase: 7
[12:53:52.101] INFO: Functional Phase Area: 4
[12:53:52.112] INFO: Test took 284693 ms.
[12:53:52.112] INFO: PixTestTiming::TBMPhaseScan() done.
[12:53:52.112] INFO: ----------------------------------------------------------------------
[12:53:52.112] INFO: PixTestTiming::ROCDelayScan()
[12:53:52.112] INFO: ----------------------------------------------------------------------
[12:56:00.024] INFO: ROC Delay Settings: 228
[12:56:00.024] INFO: ROC Header-Trailer/Token Delay: 11
[12:56:00.024] INFO: ROC Port 0 Delay: 4
[12:56:00.024] INFO: ROC Port 1 Delay: 4
[12:56:00.024] INFO: Functional ROC Area: 5
[12:56:00.027] INFO: Test took 127915 ms.
[12:56:00.027] INFO: PixTestTiming::ROCDelayScan() done.
[12:56:00.027] INFO: ----------------------------------------------------------------------
[12:56:00.027] INFO: PixTestTiming::TimingTest()
[12:56:00.028] INFO: ----------------------------------------------------------------------
[12:56:16.178] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:31.148] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:56:46.098] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:01.061] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:16.036] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:31.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:57:45.964] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:00.906] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:15.872] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:30.825] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:31.207] INFO: Fetched DAQ statistics. Counters are being reset now.
[12:58:31.224] INFO: ----------------------------------------------------------------------
[12:58:31.224] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[12:58:31.225] INFO: ----------------------------------------------------------------------
[12:58:31.225] INFO: ----------------------------------------------------------------------
[12:58:31.225] INFO: Read back bit status: 1
[12:58:31.225] INFO: ----------------------------------------------------------------------
[12:58:31.225] INFO: ----------------------------------------------------------------------
[12:58:31.225] INFO: Timings are good!
[12:58:31.225] INFO: ----------------------------------------------------------------------
[12:58:31.225] INFO: Test took 151198 ms.
[12:58:31.225] INFO: PixTestTiming::TimingTest() done.
[12:58:31.225] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//tbmParameters_C0a.dat
[12:58:31.225] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//tbmParameters_C0b.dat
[12:58:31.225] INFO: PixTestTiming::doTest took 563810 ms.
[12:58:31.225] INFO: PixTestTiming::doTest() done
[12:58:31.226] INFO: Write out TBMPhaseScan_0_V0
[12:58:31.226] INFO: Write out TBMPhaseScan_1_V0
[12:58:31.226] INFO: Write out CombinedTBMPhaseScan_V0
[12:58:31.259] INFO: Write out ROCDelayScan3_V0
[12:58:31.259] INFO: enter test to run
[12:59:04.359] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[12:59:04.359] INFO: running: highrate
[12:59:04.359] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[12:59:04.632] INFO: ----------------------------------------------------------------------
[12:59:04.632] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[12:59:04.632] INFO: ----------------------------------------------------------------------
[12:59:04.632] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[12:59:04.632] INFO: edge/corner pixel THR is adjusted
[12:59:04.632] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:59:05.592] INFO: Collecting data for 5 seconds...
[12:59:10.608] INFO: Done with hot pixel readout
[12:59:22.081] INFO: PixTest:: pg_setup set to default.










[12:59:22.082] INFO: 10 hot pixels found in step 0
[12:59:22.117] INFO: 10 hot pixels could not be trimmed and have been masked.
[12:59:22.120] INFO: PixTest::trimHotPixels() done
[12:59:22.121] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C0.dat
[12:59:22.126] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C1.dat
[12:59:22.132] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C2.dat
[12:59:22.137] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C3.dat
[12:59:22.142] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C4.dat
[12:59:22.148] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C5.dat
[12:59:22.153] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C6.dat
[12:59:22.158] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C7.dat
[12:59:22.163] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C8.dat
[12:59:22.169] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C9.dat
[12:59:22.174] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C10.dat
[12:59:22.179] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C11.dat
[12:59:22.184] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C12.dat
[12:59:22.209] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C13.dat
[12:59:22.221] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C14.dat
[12:59:22.229] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C15.dat
[12:59:22.234] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//defaultMaskFile.dat
[12:59:22.251] INFO: enter test to run
[12:59:48.926] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[12:59:48.926] INFO: running: highrate
[12:59:48.931] INFO: ----------------------------------------------------------------------
[12:59:48.931] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[12:59:48.931] INFO: ----------------------------------------------------------------------
[12:59:48.931] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[12:59:48.931] INFO: edge/corner pixel THR is adjusted
[12:59:48.931] INFO: PixTestHighRate::trimHotPixels: step 0...
[12:59:49.888] INFO: Collecting data for 1 seconds...
[12:59:50.892] INFO: Done with hot pixel readout
[12:59:54.788] INFO: PixTest:: pg_setup set to default.
[12:59:54.789] INFO: 0 hot pixels found in step 0
[12:59:54.794] INFO: 0 hot pixels could not be trimmed and have been masked.
[12:59:54.885] INFO: PixTest::trimHotPixels() done
[12:59:54.885] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C0.dat
[12:59:54.893] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C1.dat
[12:59:54.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C2.dat
[12:59:54.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C3.dat
[12:59:54.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C4.dat
[12:59:54.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C5.dat
[12:59:54.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C6.dat
[12:59:54.925] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C7.dat
[12:59:54.930] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C8.dat
[12:59:54.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C9.dat
[12:59:54.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C10.dat
[12:59:54.946] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C11.dat
[12:59:54.951] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C12.dat
[12:59:54.957] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C13.dat
[12:59:54.962] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C14.dat
[12:59:54.967] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//trimParameters35_C15.dat
[12:59:54.972] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-5-28_FPIXTest-17C-FNAL-160822-1330-300V_2016-08-22_13h30m_1471890647/000_FPIXTest_p17//defaultMaskFile.dat
[12:59:54.982] INFO: enter test to run
[13:00:17.678] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[13:00:17.678] INFO: running: xray
[13:00:17.679] INFO: ----------------------------------------------------------------------
[13:00:17.679] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:00:17.680] INFO: ----------------------------------------------------------------------
[13:00:18.642] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:00:30.181] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[13:00:59.507] INFO: Resuming triggers.
[13:01:11.143] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[13:01:40.645] INFO: Resuming triggers.
[13:01:52.187] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[13:02:22.042] INFO: Resuming triggers.
[13:02:33.583] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[13:03:03.854] INFO: Resuming triggers.
[13:03:15.397] INFO: run duration 57 seconds, buffer almost full (81%), pausing triggers.
[13:03:45.621] INFO: Resuming triggers.
[13:03:57.160] INFO: run duration 68 seconds, buffer almost full (81%), pausing triggers.
[13:04:27.321] INFO: Resuming triggers.
[13:04:38.861] INFO: run duration 80 seconds, buffer almost full (81%), pausing triggers.
[13:05:08.132] INFO: Resuming triggers.
[13:05:19.675] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[13:05:49.032] INFO: Resuming triggers.
[13:05:57.075] INFO: data taking finished, elapsed time: 100 seconds.
[13:06:17.827] INFO: PixTest:: pg_setup set to default.
[13:06:17.830] INFO: PixTestXray::doPhRun() done
[13:06:17.967] INFO: enter test to run
[13:11:34.202] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[13:11:34.202] INFO: running: xray
[13:11:34.203] INFO: ----------------------------------------------------------------------
[13:11:34.203] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[13:11:34.203] INFO: ----------------------------------------------------------------------
[13:11:35.167] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[13:11:41.950] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[13:12:12.063] INFO: Resuming triggers.
[13:12:18.844] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[13:12:49.868] INFO: Resuming triggers.
[13:12:56.655] INFO: run duration 20 seconds, buffer almost full (81%), pausing triggers.
[13:13:27.367] INFO: Resuming triggers.
[13:13:34.146] INFO: run duration 27 seconds, buffer almost full (81%), pausing triggers.
[13:14:05.156] INFO: Resuming triggers.
[13:14:11.944] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[13:14:42.842] INFO: Resuming triggers.
[13:14:49.628] INFO: run duration 40 seconds, buffer almost full (81%), pausing triggers.
[13:15:21.204] INFO: Resuming triggers.
[13:15:27.987] INFO: run duration 47 seconds, buffer almost full (81%), pausing triggers.
[13:15:59.224] INFO: Resuming triggers.
[13:16:05.005] INFO: run duration 54 seconds, buffer almost full (81%), pausing triggers.
[13:16:37.033] INFO: Resuming triggers.
[13:16:43.808] INFO: run duration 60 seconds, buffer almost full (81%), pausing triggers.
[13:17:13.004] INFO: Resuming triggers.
[13:17:20.778] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[13:17:50.952] INFO: Resuming triggers.
[13:17:57.729] INFO: run duration 74 seconds, buffer almost full (81%), pausing triggers.
[13:18:27.946] INFO: Resuming triggers.
[13:18:34.721] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[13:19:04.846] INFO: Resuming triggers.
[13:19:11.617] INFO: run duration 87 seconds, buffer almost full (81%), pausing triggers.
[13:19:41.862] INFO: Resuming triggers.
[13:19:48.637] INFO: run duration 94 seconds, buffer almost full (81%), pausing triggers.
[13:20:18.690] INFO: Resuming triggers.
[13:20:24.121] INFO: data taking finished, elapsed time: 100 seconds.
[13:20:48.560] INFO: PixTest:: pg_setup set to default.
[13:20:48.563] INFO: PixTestXray::doPhRun() done
[13:20:48.732] INFO: enter test to run
[13:21:13.318] INFO: test: HighRate no parameter change
[13:21:13.318] INFO: running: highrate
[13:21:13.365] INFO: ----------------------------------------------------------------------
[13:21:13.365] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[13:21:13.365] INFO: ----------------------------------------------------------------------
[13:21:13.529] INFO: Expecting 768 events.
[13:21:14.663] INFO: 768 events read in total (419ms).
[13:21:14.664] INFO: Test took 1270ms.
[13:21:15.467] INFO: Expecting 41600 events.
[13:21:18.537] INFO: 41600 events read in total (2543ms).
[13:21:18.538] INFO: Test took 3867ms.
[13:21:18.570] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:19.301] INFO: Expecting 41600 events.
[13:21:22.488] INFO: 41600 events read in total (2660ms).
[13:21:22.489] INFO: Test took 3901ms.
[13:21:22.522] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:23.249] INFO: Expecting 41600 events.
[13:21:26.481] INFO: 41600 events read in total (2705ms).
[13:21:26.482] INFO: Test took 3942ms.
[13:21:26.518] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:27.237] INFO: Expecting 41600 events.
[13:21:30.454] INFO: 41600 events read in total (2690ms).
[13:21:30.455] INFO: Test took 3918ms.
[13:21:30.488] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:31.211] INFO: Expecting 41600 events.
[13:21:34.394] INFO: 41600 events read in total (2656ms).
[13:21:34.395] INFO: Test took 3889ms.
[13:21:34.428] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:35.155] INFO: Expecting 41600 events.
[13:21:38.388] INFO: 41600 events read in total (2706ms).
[13:21:38.389] INFO: Test took 3944ms.
[13:21:38.422] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:39.148] INFO: Expecting 41600 events.
[13:21:42.369] INFO: 41600 events read in total (2694ms).
[13:21:42.370] INFO: Test took 3930ms.
[13:21:42.404] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:43.127] INFO: Expecting 41600 events.
[13:21:46.358] INFO: 41600 events read in total (2704ms).
[13:21:46.359] INFO: Test took 3937ms.
[13:21:46.392] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:47.120] INFO: Expecting 41600 events.
[13:21:50.347] INFO: 41600 events read in total (2700ms).
[13:21:50.348] INFO: Test took 3937ms.
[13:21:50.382] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:51.101] INFO: Expecting 41600 events.
[13:21:54.338] INFO: 41600 events read in total (2710ms).
[13:21:54.339] INFO: Test took 3940ms.
[13:21:54.374] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:55.099] INFO: Expecting 41600 events.
[13:21:58.342] INFO: 41600 events read in total (2716ms).
[13:21:58.343] INFO: Test took 3951ms.
[13:21:58.376] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:21:59.099] INFO: Expecting 41600 events.
[13:22:02.325] INFO: 41600 events read in total (2699ms).
[13:22:02.326] INFO: Test took 3931ms.
[13:22:02.359] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:03.082] INFO: Expecting 41600 events.
[13:22:06.300] INFO: 41600 events read in total (2691ms).
[13:22:06.301] INFO: Test took 3923ms.
[13:22:06.334] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:07.061] INFO: Expecting 41600 events.
[13:22:10.299] INFO: 41600 events read in total (2711ms).
[13:22:10.300] INFO: Test took 3949ms.
[13:22:10.333] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:11.059] INFO: Expecting 41600 events.
[13:22:14.291] INFO: 41600 events read in total (2705ms).
[13:22:14.292] INFO: Test took 3942ms.
[13:22:14.325] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:15.049] INFO: Expecting 41600 events.
[13:22:18.275] INFO: 41600 events read in total (2699ms).
[13:22:18.276] INFO: Test took 3932ms.
[13:22:18.308] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:19.033] INFO: Expecting 41600 events.
[13:22:22.284] INFO: 41600 events read in total (2724ms).
[13:22:22.285] INFO: Test took 3958ms.
[13:22:22.318] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:23.044] INFO: Expecting 41600 events.
[13:22:26.280] INFO: 41600 events read in total (2709ms).
[13:22:26.281] INFO: Test took 3944ms.
[13:22:26.313] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:27.040] INFO: Expecting 41600 events.
[13:22:30.254] INFO: 41600 events read in total (2687ms).
[13:22:30.255] INFO: Test took 3923ms.
[13:22:30.288] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:31.017] INFO: Expecting 41600 events.
[13:22:34.136] INFO: 41600 events read in total (2593ms).
[13:22:34.137] INFO: Test took 3832ms.
[13:22:34.169] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:22:34.535] INFO: enter test to run
[13:22:54.077] INFO: test: HighRate no parameter change
[13:22:54.077] INFO: running: highrate
[13:22:54.078] INFO: ----------------------------------------------------------------------
[13:22:54.078] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:22:54.078] INFO: ----------------------------------------------------------------------
[13:22:54.692] INFO: Expecting 208000 events.
[13:23:06.490] INFO: 208000 events read in total (11271ms).
[13:23:06.493] INFO: Test took 12404ms.
[13:23:06.633] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:06.883] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0
[13:23:06.884] INFO: number of red-efficiency pixels: 72 51 84 106 131 146 133 87 76 124 114 107 86 76 23 22
[13:23:06.884] INFO: number of X-ray hits detected: 67695 43212 68330 102473 107167 112371 105584 74160 68534 95216 94064 80719 85977 51909 22089 24227
[13:23:06.884] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:23:06.884] INFO: number of Vcal hits detected: 207926 207946 207916 207792 207865 207851 207867 207911 207924 207874 207885 207891 207911 207923 207977 207978
[13:23:06.884] 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
[13:23:06.884] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 99.9 99.9 99.9 100.0 100.0 100.0 100.0
[13:23:06.884] INFO: X-ray hit rate [MHz/cm2]: 19.8 12.7 20.0 30.0 31.4 32.9 30.9 21.7 20.1 27.9 27.6 23.7 25.2 15.2 6.5 7.1
[13:23:06.884] INFO: PixTestHighRate::doXPixelAlive() done
[13:23:06.935] INFO: PixTest:: pg_setup set to default.
[13:23:06.951] INFO: enter test to run
[13:23:27.189] INFO: test: HighRate no parameter change
[13:23:27.189] INFO: running: highrate
[13:23:27.190] INFO: ----------------------------------------------------------------------
[13:23:27.190] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:23:27.190] INFO: ----------------------------------------------------------------------
[13:23:27.809] INFO: Expecting 208000 events.
[13:23:41.252] INFO: 208000 events read in total (12916ms).
[13:23:41.257] INFO: Test took 14058ms.
[13:23:41.538] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:23:41.835] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0
[13:23:41.835] INFO: number of red-efficiency pixels: 282 116 295 371 509 426 439 250 237 401 309 302 295 195 56 43
[13:23:41.835] INFO: number of X-ray hits detected: 139471 88989 140524 208931 220189 230597 217182 152636 141750 194733 192516 166436 176421 106315 45890 50149
[13:23:41.835] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:23:41.835] INFO: number of Vcal hits detected: 207696 207880 207676 207496 207445 207530 207521 207732 207749 207576 207677 207682 207695 207795 207940 207957
[13:23:41.835] INFO: Vcal hit fiducial efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.9 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[13:23:41.835] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.8 99.8 99.7 99.8 99.8 99.9 99.9 99.8 99.8 99.8 99.9 99.9 100.0 100.0
[13:23:41.835] INFO: X-ray hit rate [MHz/cm2]: 40.9 26.1 41.2 61.2 64.5 67.6 63.7 44.7 41.5 57.1 56.4 48.8 51.7 31.2 13.5 14.7
[13:23:41.835] INFO: PixTestHighRate::doXPixelAlive() done
[13:23:41.882] INFO: PixTest:: pg_setup set to default.
[13:23:41.895] INFO: enter test to run
[13:24:01.141] INFO: test: HighRate no parameter change
[13:24:01.141] INFO: running: highrate
[13:24:01.142] INFO: ----------------------------------------------------------------------
[13:24:01.142] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[13:24:01.142] INFO: ----------------------------------------------------------------------
[13:24:01.759] INFO: Expecting 208000 events.
[13:24:16.960] INFO: 208000 events read in total (14674ms).
[13:24:16.967] INFO: Test took 15816ms.
[13:24:17.372] INFO: Fetched DAQ statistics. Counters are being reset now.
[13:24:17.713] INFO: number of dead pixels (per ROC): 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0
[13:24:17.713] INFO: number of red-efficiency pixels: 536 242 641 751 1152 1018 1123 490 486 909 686 683 607 449 115 66
[13:24:17.713] INFO: number of X-ray hits detected: 209028 133570 212014 315623 331445 345486 326883 228154 212631 295164 290342 251512 264894 160460 68989 75553
[13:24:17.713] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[13:24:17.713] INFO: number of Vcal hits detected: 207291 207735 207186 207016 206531 206753 206569 207431 207456 206901 207219 207221 207317 207475 207881 207934
[13:24:17.713] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.7 99.6 99.4 99.5 99.4 99.7 99.8 99.5 99.7 99.7 99.7 99.8 99.9 100.0
[13:24:17.713] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.6 99.5 99.3 99.4 99.3 99.7 99.7 99.5 99.6 99.6 99.7 99.7 99.9 100.0
[13:24:17.713] INFO: X-ray hit rate [MHz/cm2]: 61.3 39.2 62.1 92.5 97.1 101.3 95.8 66.9 62.3 86.5 85.1 73.7 77.6 47.0 20.2 22.1
[13:24:17.713] INFO: PixTestHighRate::doXPixelAlive() done
[13:24:17.763] INFO: PixTest:: pg_setup set to default.
[13:24:17.779] INFO: enter test to run
[13:24:33.132] INFO: test: exit no parameter change
[13:24:33.486] QUIET: Connection to board 33 closed.
[13:24:33.494] INFO: pXar: this is the end, my friend