[17:19:54.043] INFO: *** Welcome to pxar ***
[17:19:54.043] INFO: *** Today: 2016/06/27
[17:19:54.058] INFO: *** Version: v1.9.0-814-g7497
[17:19:54.059] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//dacParameters35_C15.dat
[17:19:54.060] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:19:54.060] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//defaultMaskFile.dat
[17:19:54.060] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C15.dat
[17:19:54.133] INFO: clk: 4
[17:19:54.134] INFO: ctr: 4
[17:19:54.134] INFO: sda: 19
[17:19:54.134] INFO: tin: 9
[17:19:54.134] INFO: level: 15
[17:19:54.134] INFO: triggerdelay: 0
[17:19:54.134] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[17:19:54.134] INFO: Log level: INFO
[17:19:54.152] QUIET: Connection to board DTB_WREK4U opened.
[17:19:54.155] 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:
------------------------------------------------------
[17:19:54.158] INFO: RPC call hashes of host and DTB match: 398089610
[17:19:55.681] INFO: DUT info:
[17:19:55.681] INFO: The DUT currently contains the following objects:
[17:19:55.681] INFO: 2 TBM Cores tbm08c (2 ON)
[17:19:55.681] INFO: TBM Core alpha (0): 7 registers set
[17:19:55.681] INFO: TBM Core beta (1): 7 registers set
[17:19:55.681] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[17:19:55.681] INFO: ROC 0: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:55.681] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[17:19:56.084] INFO: enter 'restricted' command line mode
[17:19:56.084] INFO: enter test to run
[17:19:57.147] INFO: test: timing no parameter change
[17:19:57.147] INFO: running: timing
[17:19:57.156] INFO: ######################################################################
[17:19:57.156] INFO: PixTestTiming::doTest()
[17:19:57.156] INFO: ######################################################################
[17:19:57.156] INFO: ----------------------------------------------------------------------
[17:19:57.156] INFO: PixTestTiming::TBMPhaseScan()
[17:19:57.156] INFO: ----------------------------------------------------------------------
[17:24:32.204] INFO: TBM Phase Settings: 208
[17:24:32.204] INFO: 400MHz Phase: 4
[17:24:32.204] INFO: 160MHz Phase: 6
[17:24:32.204] INFO: Functional Phase Area: 3
[17:24:32.217] INFO: Test took 275061 ms.
[17:24:32.217] INFO: PixTestTiming::TBMPhaseScan() done.
[17:24:32.218] INFO: ----------------------------------------------------------------------
[17:24:32.218] INFO: PixTestTiming::ROCDelayScan()
[17:24:32.218] INFO: ----------------------------------------------------------------------
[17:26:27.941] INFO: ROC Delay Settings: 219
[17:26:27.941] INFO: ROC Header-Trailer/Token Delay: 11
[17:26:27.941] INFO: ROC Port 0 Delay: 3
[17:26:27.941] INFO: ROC Port 1 Delay: 3
[17:26:27.941] INFO: Functional ROC Area: 4
[17:26:27.944] INFO: Test took 115726 ms.
[17:26:27.944] INFO: PixTestTiming::ROCDelayScan() done.
[17:26:27.945] INFO: ----------------------------------------------------------------------
[17:26:27.945] INFO: PixTestTiming::TimingTest()
[17:26:27.945] INFO: ----------------------------------------------------------------------
[17:26:44.093] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:26:59.169] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:27:14.278] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:27:29.451] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:27:44.585] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:27:59.859] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:28:15.139] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:28:30.270] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:28:45.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:29:00.495] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:29:00.873] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:29:00.892] INFO: ----------------------------------------------------------------------
[17:29:00.892] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[17:29:00.892] INFO: ----------------------------------------------------------------------
[17:29:00.892] INFO: ----------------------------------------------------------------------
[17:29:00.892] INFO: Read back bit status: 1
[17:29:00.892] INFO: ----------------------------------------------------------------------
[17:29:00.892] INFO: ----------------------------------------------------------------------
[17:29:00.892] INFO: Timings are good!
[17:29:00.892] INFO: ----------------------------------------------------------------------
[17:29:00.892] INFO: Test took 152947 ms.
[17:29:00.892] INFO: PixTestTiming::TimingTest() done.
[17:29:00.898] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//tbmParameters_C0a.dat
[17:29:00.898] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//tbmParameters_C0b.dat
[17:29:00.898] INFO: PixTestTiming::doTest took 543747 ms.
[17:29:00.898] INFO: PixTestTiming::doTest() done
[17:29:00.898] INFO: Write out TBMPhaseScan_0_V0
[17:29:00.922] INFO: Write out TBMPhaseScan_1_V0
[17:29:00.922] INFO: Write out CombinedTBMPhaseScan_V0
[17:29:00.963] INFO: Write out ROCDelayScan3_V0
[17:29:00.965] INFO: enter test to run
[17:29:31.591] INFO: test: PixelAlive no parameter change
[17:29:31.591] INFO: running: pixelalive
[17:29:31.596] INFO: ----------------------------------------------------------------------
[17:29:31.596] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[17:29:31.596] INFO: ----------------------------------------------------------------------
[17:29:31.914] INFO: Expecting 41600 events.
[17:29:36.244] INFO: 41600 events read in total (3615ms).
[17:29:36.244] INFO: Test took 4646ms.
[17:29:36.251] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:29:36.648] INFO: PixTestAlive::aliveTest() done
[17:29:36.649] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 1 0
[17:29:36.652] INFO: enter test to run
[17:30:53.030] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[17:30:53.031] INFO: running: highrate
[17:30:53.031] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[17:30:53.191] INFO: ----------------------------------------------------------------------
[17:30:53.191] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[17:30:53.191] INFO: ----------------------------------------------------------------------
[17:30:53.191] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[17:30:53.191] INFO: edge/corner pixel THR is adjusted
[17:30:53.191] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:30:54.150] INFO: Collecting data for 5 seconds...
[17:30:59.166] INFO: Done with hot pixel readout
[17:31:10.684] INFO: PixTest:: pg_setup set to default.
[17:31:10.685] INFO: 6 hot pixels found in step 0
[17:31:11.676] INFO: Collecting data for 5 seconds...
[17:31:16.692] INFO: Done with hot pixel readout
[17:31:28.154] INFO: PixTest:: pg_setup set to default.
[17:31:28.155] INFO: 4 hot pixels found in step 1
[17:31:29.147] INFO: Collecting data for 5 seconds...
[17:31:34.163] INFO: Done with hot pixel readout
[17:31:45.620] INFO: PixTest:: pg_setup set to default.
[17:31:45.621] INFO: 2 hot pixels found in step 2
[17:31:46.611] INFO: Collecting data for 5 seconds...
[17:31:51.628] INFO: Done with hot pixel readout
[17:32:03.206] INFO: PixTest:: pg_setup set to default.
[17:32:03.207] INFO: 2 hot pixels found in step 3
[17:32:04.198] INFO: Collecting data for 5 seconds...
[17:32:09.215] INFO: Done with hot pixel readout
[17:32:20.801] INFO: PixTest:: pg_setup set to default.
[17:32:20.802] INFO: 5 hot pixels found in step 4
[17:32:21.793] INFO: Collecting data for 5 seconds...
[17:32:26.810] INFO: Done with hot pixel readout
[17:32:38.379] INFO: PixTest:: pg_setup set to default.

[17:32:38.380] INFO: 4 hot pixels found in step 5
[17:32:39.371] INFO: Collecting data for 5 seconds...
[17:32:44.388] INFO: Done with hot pixel readout
[17:32:55.980] INFO: PixTest:: pg_setup set to default.
[17:32:55.981] INFO: 4 hot pixels found in step 6
[17:32:56.973] INFO: Collecting data for 5 seconds...
[17:33:01.990] INFO: Done with hot pixel readout
[17:33:13.550] INFO: PixTest:: pg_setup set to default.
[17:33:13.551] INFO: 2 hot pixels found in step 7
[17:33:14.543] INFO: Collecting data for 5 seconds...
[17:33:19.560] INFO: Done with hot pixel readout
[17:33:31.083] INFO: PixTest:: pg_setup set to default.
[17:33:31.083] INFO: 2 hot pixels found in step 8
[17:33:32.078] INFO: Collecting data for 5 seconds...
[17:33:37.094] INFO: Done with hot pixel readout
[17:33:48.664] INFO: PixTest:: pg_setup set to default.
[17:33:48.665] INFO: 0 hot pixels found in step 9
[17:33:48.700] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:33:48.703] INFO: PixTest::trimHotPixels() done
[17:33:48.703] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C0.dat
[17:33:48.709] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C1.dat
[17:33:48.715] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C2.dat
[17:33:48.722] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C3.dat
[17:33:48.727] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C4.dat
[17:33:48.732] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C5.dat
[17:33:48.738] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C6.dat
[17:33:48.743] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C7.dat
[17:33:48.748] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C8.dat
[17:33:48.753] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C9.dat
[17:33:48.759] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C10.dat
[17:33:48.764] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C11.dat
[17:33:48.769] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C12.dat
[17:33:48.774] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C13.dat
[17:33:48.780] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C14.dat
[17:33:48.785] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C15.dat
[17:33:48.790] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//defaultMaskFile.dat
[17:33:48.801] INFO: enter test to run
[17:35:02.149] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[17:35:02.149] INFO: running: highrate
[17:35:02.154] INFO: ----------------------------------------------------------------------
[17:35:02.154] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[17:35:02.154] INFO: ----------------------------------------------------------------------
[17:35:02.154] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[17:35:02.154] INFO: edge/corner pixel THR is adjusted
[17:35:02.154] INFO: PixTestHighRate::trimHotPixels: step 0...
[17:35:03.111] INFO: Collecting data for 1 seconds...
[17:35:04.115] INFO: Done with hot pixel readout
[17:35:07.943] INFO: PixTest:: pg_setup set to default.
[17:35:07.944] INFO: 0 hot pixels found in step 0
[17:35:07.951] INFO: 0 hot pixels could not be trimmed and have been masked.
[17:35:08.046] INFO: PixTest::trimHotPixels() done
[17:35:08.046] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C0.dat
[17:35:08.053] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C1.dat
[17:35:08.059] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C2.dat
[17:35:08.065] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C3.dat
[17:35:08.070] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C4.dat
[17:35:08.076] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C5.dat
[17:35:08.081] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C6.dat
[17:35:08.086] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C7.dat
[17:35:08.091] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C8.dat
[17:35:08.096] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C9.dat
[17:35:08.102] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C10.dat
[17:35:08.108] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C11.dat
[17:35:08.113] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C12.dat
[17:35:08.118] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C13.dat
[17:35:08.123] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C14.dat
[17:35:08.128] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//trimParameters35_C15.dat
[17:35:08.134] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-P-3-13_FPIXTest-17C-FNAL-160620-1559_2016-06-20_16h00m_1466456421/000_FPIXTest_p17//defaultMaskFile.dat
[17:35:08.144] INFO: enter test to run
[17:35:34.821] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[17:35:34.821] INFO: running: xray
[17:35:34.822] INFO: ----------------------------------------------------------------------
[17:35:34.822] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:35:34.822] INFO: ----------------------------------------------------------------------
[17:35:35.786] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:35:47.455] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[17:36:16.678] INFO: Resuming triggers.
[17:36:28.352] INFO: run duration 23 seconds, buffer almost full (81%), pausing triggers.
[17:36:57.688] INFO: Resuming triggers.
[17:37:09.359] INFO: run duration 34 seconds, buffer almost full (81%), pausing triggers.
[17:37:38.310] INFO: Resuming triggers.
[17:37:49.985] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[17:38:19.363] INFO: Resuming triggers.
[17:38:31.037] INFO: run duration 58 seconds, buffer almost full (81%), pausing triggers.
[17:39:00.813] INFO: Resuming triggers.
[17:39:12.487] INFO: run duration 69 seconds, buffer almost full (81%), pausing triggers.
[17:39:42.090] INFO: Resuming triggers.
[17:39:53.769] INFO: run duration 81 seconds, buffer almost full (81%), pausing triggers.
[17:40:23.569] INFO: Resuming triggers.
[17:40:35.245] INFO: run duration 93 seconds, buffer almost full (81%), pausing triggers.
[17:41:04.581] INFO: Resuming triggers.
[17:41:11.551] INFO: data taking finished, elapsed time: 100 seconds.
[17:41:29.409] INFO: PixTest:: pg_setup set to default.
[17:41:29.413] INFO: PixTestXray::doPhRun() done
[17:41:29.547] INFO: enter test to run
[17:41:54.570] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[17:41:54.570] INFO: running: xray
[17:41:54.571] INFO: ----------------------------------------------------------------------
[17:41:54.571] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[17:41:54.571] INFO: ----------------------------------------------------------------------
[17:41:55.534] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[17:42:02.579] INFO: run duration 7 seconds, buffer almost full (81%), pausing triggers.
[17:42:32.695] INFO: Resuming triggers.
[17:42:39.746] INFO: run duration 14 seconds, buffer almost full (81%), pausing triggers.
[17:43:09.763] INFO: Resuming triggers.
[17:43:16.808] INFO: run duration 21 seconds, buffer almost full (81%), pausing triggers.
[17:43:46.698] INFO: Resuming triggers.
[17:43:53.748] INFO: run duration 28 seconds, buffer almost full (81%), pausing triggers.
[17:44:23.752] INFO: Resuming triggers.
[17:44:30.801] INFO: run duration 35 seconds, buffer almost full (81%), pausing triggers.
[17:45:00.874] INFO: Resuming triggers.
[17:45:07.924] INFO: run duration 42 seconds, buffer almost full (81%), pausing triggers.
[17:45:37.927] INFO: Resuming triggers.
[17:45:44.978] INFO: run duration 49 seconds, buffer almost full (81%), pausing triggers.
[17:46:15.013] INFO: Resuming triggers.
[17:46:22.064] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[17:46:52.174] INFO: Resuming triggers.
[17:46:59.223] INFO: run duration 63 seconds, buffer almost full (81%), pausing triggers.
[17:47:29.125] INFO: Resuming triggers.
[17:47:36.175] INFO: run duration 70 seconds, buffer almost full (81%), pausing triggers.
[17:48:06.147] INFO: Resuming triggers.
[17:48:13.198] INFO: run duration 77 seconds, buffer almost full (81%), pausing triggers.
[17:48:43.842] INFO: Resuming triggers.
[17:48:50.895] INFO: run duration 84 seconds, buffer almost full (81%), pausing triggers.
[17:49:21.168] INFO: Resuming triggers.
[17:49:28.220] INFO: run duration 91 seconds, buffer almost full (81%), pausing triggers.
[17:49:58.847] INFO: Resuming triggers.
[17:50:05.897] INFO: run duration 98 seconds, buffer almost full (81%), pausing triggers.
[17:50:36.339] INFO: Resuming triggers.
[17:50:37.983] INFO: data taking finished, elapsed time: 100 seconds.
[17:50:45.639] INFO: PixTest:: pg_setup set to default.
[17:50:45.642] INFO: PixTestXray::doPhRun() done
[17:50:45.793] INFO: enter test to run
[17:53:17.934] INFO: test: HighRate no parameter change
[17:53:17.934] INFO: running: highrate
[17:53:17.952] INFO: ----------------------------------------------------------------------
[17:53:17.952] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[17:53:17.952] INFO: ----------------------------------------------------------------------
[17:53:18.107] INFO: Expecting 768 events.
[17:53:19.241] INFO: 768 events read in total (418ms).
[17:53:19.241] INFO: Test took 1268ms.
[17:53:20.044] INFO: Expecting 41600 events.
[17:53:23.158] INFO: 41600 events read in total (2587ms).
[17:53:23.159] INFO: Test took 3912ms.
[17:53:23.191] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:23.922] INFO: Expecting 41600 events.
[17:53:27.117] INFO: 41600 events read in total (2668ms).
[17:53:27.118] INFO: Test took 3910ms.
[17:53:27.149] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:27.877] INFO: Expecting 41600 events.
[17:53:31.101] INFO: 41600 events read in total (2698ms).
[17:53:31.102] INFO: Test took 3935ms.
[17:53:31.134] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:31.860] INFO: Expecting 41600 events.
[17:53:35.075] INFO: 41600 events read in total (2689ms).
[17:53:35.076] INFO: Test took 3926ms.
[17:53:35.108] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:35.836] INFO: Expecting 41600 events.
[17:53:39.069] INFO: 41600 events read in total (2706ms).
[17:53:39.070] INFO: Test took 3945ms.
[17:53:39.103] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:39.829] INFO: Expecting 41600 events.
[17:53:43.042] INFO: 41600 events read in total (2686ms).
[17:53:43.043] INFO: Test took 3922ms.
[17:53:43.076] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:43.803] INFO: Expecting 41600 events.
[17:53:47.024] INFO: 41600 events read in total (2694ms).
[17:53:47.025] INFO: Test took 3931ms.
[17:53:47.056] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:47.782] INFO: Expecting 41600 events.
[17:53:51.009] INFO: 41600 events read in total (2700ms).
[17:53:51.010] INFO: Test took 3936ms.
[17:53:51.042] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:51.768] INFO: Expecting 41600 events.
[17:53:54.982] INFO: 41600 events read in total (2688ms).
[17:53:54.983] INFO: Test took 3923ms.
[17:53:55.015] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:55.743] INFO: Expecting 41600 events.
[17:53:58.944] INFO: 41600 events read in total (2674ms).
[17:53:58.945] INFO: Test took 3912ms.
[17:53:58.977] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:53:59.707] INFO: Expecting 41600 events.
[17:54:02.912] INFO: 41600 events read in total (2678ms).
[17:54:02.913] INFO: Test took 3918ms.
[17:54:02.945] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:03.670] INFO: Expecting 41600 events.
[17:54:06.876] INFO: 41600 events read in total (2679ms).
[17:54:06.877] INFO: Test took 3914ms.
[17:54:06.916] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:07.637] INFO: Expecting 41600 events.
[17:54:10.833] INFO: 41600 events read in total (2669ms).
[17:54:10.834] INFO: Test took 3900ms.
[17:54:10.866] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:11.593] INFO: Expecting 41600 events.
[17:54:14.771] INFO: 41600 events read in total (2651ms).
[17:54:14.773] INFO: Test took 3890ms.
[17:54:14.805] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:15.533] INFO: Expecting 41600 events.
[17:54:18.744] INFO: 41600 events read in total (2684ms).
[17:54:18.745] INFO: Test took 3921ms.
[17:54:18.777] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:19.505] INFO: Expecting 41600 events.
[17:54:22.678] INFO: 41600 events read in total (2646ms).
[17:54:22.679] INFO: Test took 3884ms.
[17:54:22.710] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:23.440] INFO: Expecting 41600 events.
[17:54:26.624] INFO: 41600 events read in total (2657ms).
[17:54:26.625] INFO: Test took 3898ms.
[17:54:26.657] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:27.386] INFO: Expecting 41600 events.
[17:54:30.596] INFO: 41600 events read in total (2683ms).
[17:54:30.597] INFO: Test took 3922ms.
[17:54:30.630] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:31.353] INFO: Expecting 41600 events.
[17:54:34.510] INFO: 41600 events read in total (2630ms).
[17:54:34.511] INFO: Test took 3864ms.
[17:54:34.543] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:35.273] INFO: Expecting 41600 events.
[17:54:38.266] INFO: 41600 events read in total (2466ms).
[17:54:38.268] INFO: Test took 3707ms.
[17:54:38.301] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:54:38.672] INFO: enter test to run
[17:55:59.764] INFO: test: HighRate no parameter change
[17:55:59.765] INFO: running: highrate
[17:55:59.766] INFO: ----------------------------------------------------------------------
[17:55:59.766] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:55:59.766] INFO: ----------------------------------------------------------------------
[17:56:00.379] INFO: Expecting 208000 events.
[17:56:12.090] INFO: 208000 events read in total (11184ms).
[17:56:12.093] INFO: Test took 12318ms.
[17:56:12.229] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:56:12.479] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 1 0
[17:56:12.479] INFO: number of red-efficiency pixels: 80 51 77 125 100 127 132 110 72 113 71 97 82 65 25 21
[17:56:12.479] INFO: number of X-ray hits detected: 67333 42432 63236 95959 104956 111256 110823 78317 72211 88359 85939 73247 75317 44376 20162 21198
[17:56:12.479] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:56:12.479] INFO: number of Vcal hits detected: 207920 207949 207922 207871 207893 207818 207866 207887 207928 207884 207927 207903 207916 207935 207926 207979
[17:56:12.479] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0 100.0
[17:56:12.479] INFO: Vcal hit overall efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0 100.0
[17:56:12.479] INFO: X-ray hit rate [MHz/cm2]: 19.7 12.4 18.5 28.1 30.8 32.6 32.5 23.0 21.2 25.9 25.2 21.5 22.1 13.0 5.9 6.2
[17:56:12.479] INFO: PixTestHighRate::doXPixelAlive() done
[17:56:12.530] INFO: PixTest:: pg_setup set to default.
[17:56:12.544] INFO: enter test to run
[17:56:51.644] INFO: test: HighRate no parameter change
[17:56:51.644] INFO: running: highrate
[17:56:51.645] INFO: ----------------------------------------------------------------------
[17:56:51.645] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:56:51.645] INFO: ----------------------------------------------------------------------
[17:56:52.262] INFO: Expecting 208000 events.
[17:57:05.624] INFO: 208000 events read in total (12835ms).
[17:57:05.629] INFO: Test took 13972ms.
[17:57:05.898] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:06.190] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 1 0
[17:57:06.190] INFO: number of red-efficiency pixels: 260 120 189 368 448 395 466 314 256 316 254 263 253 150 49 48
[17:57:06.190] INFO: number of X-ray hits detected: 139919 87592 131575 197682 216977 229599 227892 161312 149383 183251 178923 151915 156241 92543 41715 43989
[17:57:06.190] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:57:06.190] INFO: number of Vcal hits detected: 207715 207877 207794 207607 207514 207529 207502 207660 207738 207656 207734 207728 207738 207842 207902 207952
[17:57:06.190] 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
[17:57:06.190] INFO: Vcal hit overall efficiency (%): 99.9 99.9 99.9 99.8 99.8 99.8 99.8 99.8 99.9 99.8 99.9 99.9 99.9 99.9 100.0 100.0
[17:57:06.190] INFO: X-ray hit rate [MHz/cm2]: 41.0 25.7 38.6 57.9 63.6 67.3 66.8 47.3 43.8 53.7 52.4 44.5 45.8 27.1 12.2 12.9
[17:57:06.190] INFO: PixTestHighRate::doXPixelAlive() done
[17:57:06.239] INFO: PixTest:: pg_setup set to default.
[17:57:06.256] INFO: enter test to run
[17:57:27.420] INFO: test: HighRate no parameter change
[17:57:27.420] INFO: running: highrate
[17:57:27.421] INFO: ----------------------------------------------------------------------
[17:57:27.421] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[17:57:27.421] INFO: ----------------------------------------------------------------------
[17:57:28.039] INFO: Expecting 208000 events.
[17:57:43.031] INFO: 208000 events read in total (14465ms).
[17:57:43.038] INFO: Test took 15608ms.
[17:57:43.446] INFO: Fetched DAQ statistics. Counters are being reset now.
[17:57:43.783] INFO: number of dead pixels (per ROC): 0 0 0 0 0 1 0 0 0 0 0 0 0 0 1 0
[17:57:43.783] INFO: number of red-efficiency pixels: 545 283 437 769 1019 861 1147 639 498 742 547 533 547 315 58 83
[17:57:43.783] INFO: number of X-ray hits detected: 207642 130968 196952 295383 325385 343600 343015 242662 224795 272923 267041 226983 234622 139489 62961 66275
[17:57:43.783] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[17:57:43.783] INFO: number of Vcal hits detected: 207312 207691 207474 207076 206771 206897 206533 207226 207448 207133 207391 207407 207410 207646 207892 207914
[17:57:43.783] INFO: Vcal hit fiducial efficiency (%): 99.7 99.9 99.8 99.6 99.5 99.5 99.4 99.7 99.8 99.6 99.7 99.7 99.7 99.8 100.0 100.0
[17:57:43.783] INFO: Vcal hit overall efficiency (%): 99.7 99.9 99.7 99.6 99.4 99.5 99.3 99.6 99.7 99.6 99.7 99.7 99.7 99.8 99.9 100.0
[17:57:43.783] INFO: X-ray hit rate [MHz/cm2]: 60.9 38.4 57.7 86.6 95.4 100.7 100.5 71.1 65.9 80.0 78.3 66.5 68.8 40.9 18.5 19.4
[17:57:43.783] INFO: PixTestHighRate::doXPixelAlive() done
[17:57:43.834] INFO: PixTest:: pg_setup set to default.
[17:57:43.852] INFO: enter test to run
[17:57:56.139] INFO: test: exit no parameter change
[17:57:56.551] QUIET: Connection to board 32 closed.
[17:57:56.552] INFO: pXar: this is the end, my friend