[15:30:27.919] INFO: *** Welcome to pxar ***
[15:30:27.919] INFO: *** Today: 2016/07/20
[15:30:27.935] INFO: *** Version: v1.9.0-814-g7497
[15:30:27.935] INFO: readRocDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//dacParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//dacParameters35_C15.dat
[15:30:27.936] INFO: readTbmDacs: /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//tbmParameters_C0a.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:30:27.936] INFO: readMaskFile: /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//defaultMaskFile.dat
[15:30:27.936] INFO: MASKED Roc 0 col/row: 1 7
[15:30:27.936] INFO: MASKED Roc 0 col/row: 2 4
[15:30:27.936] INFO: readTrimFile: /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C15.dat
[15:30:27.936] INFO: masking Roc 0 col/row: 1 7
[15:30:27.936] INFO: masking Roc 0 col/row: 2 4
[15:30:28.010] INFO: clk: 4
[15:30:28.010] INFO: ctr: 4
[15:30:28.010] INFO: sda: 19
[15:30:28.010] INFO: tin: 9
[15:30:28.010] INFO: level: 15
[15:30:28.010] INFO: triggerdelay: 0
[15:30:28.010] QUIET: Instanciating API for pxar v1.9.0+814~g74979a6
[15:30:28.010] INFO: Log level: INFO
[15:30:28.027] QUIET: Connection to board DTB_WREKRL opened.
[15:30:28.030] 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:
------------------------------------------------------
[15:30:28.033] INFO: RPC call hashes of host and DTB match: 398089610
[15:30:29.557] INFO: DUT info:
[15:30:29.557] INFO: The DUT currently contains the following objects:
[15:30:29.557] INFO: 2 TBM Cores tbm08c (2 ON)
[15:30:29.557] INFO: TBM Core alpha (0): 7 registers set
[15:30:29.557] INFO: TBM Core beta (1): 7 registers set
[15:30:29.557] INFO: 16 ROCs psi46digv21respin (16 ON) with 4160 pixelConfigs
[15:30:29.557] INFO: ROC 0: 19 DACs set, Pixels: 2 masked, 0 active.
[15:30:29.557] INFO: ROC 1: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 2: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 3: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 4: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 5: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 6: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 7: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 8: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 9: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 10: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 11: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 12: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 13: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 14: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.557] INFO: ROC 15: 19 DACs set, Pixels: 0 masked, 0 active.
[15:30:29.960] INFO: enter 'restricted' command line mode
[15:30:29.960] INFO: enter test to run
[15:30:46.812] INFO: test: PixelAlive no parameter change
[15:30:46.812] INFO: running: pixelalive
[15:30:46.818] INFO: ----------------------------------------------------------------------
[15:30:46.819] INFO: PixTestAlive::aliveTest() ntrig = 10, vcal = 200 (ctrlreg = 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0)
[15:30:46.819] INFO: ----------------------------------------------------------------------
[15:30:46.822] INFO: ROC 0 masking pixel 1/7
[15:30:46.822] INFO: ROC 0 masking pixel 2/4
[15:30:47.137] INFO: Expecting 41600 events.
[15:30:51.468] INFO: 41600 events read in total (3612ms).
[15:30:51.634] INFO: Test took 4812ms.
[15:30:51.643] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:30:51.905] INFO: PixTestAlive::aliveTest() done
[15:30:51.905] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 1 0 0 17 0 0 0
[15:30:51.905] INFO: ROC 0 masking pixel 1/7
[15:30:51.905] INFO: ROC 0 masking pixel 2/4
[15:30:51.935] INFO: enter test to run
[15:30:59.724] INFO: test: timing no parameter change
[15:30:59.724] INFO: running: timing
[15:30:59.727] INFO: ######################################################################
[15:30:59.727] INFO: PixTestTiming::doTest()
[15:30:59.727] INFO: ######################################################################
[15:30:59.727] INFO: ----------------------------------------------------------------------
[15:30:59.727] INFO: PixTestTiming::TBMPhaseScan()
[15:30:59.727] INFO: ----------------------------------------------------------------------
[15:39:06.437] INFO: TBM Phase Settings: 232
[15:39:06.437] INFO: 400MHz Phase: 2
[15:39:06.437] INFO: 160MHz Phase: 7
[15:39:06.437] INFO: Functional Phase Area: 3
[15:39:06.440] INFO: Test took 486713 ms.
[15:39:06.441] INFO: PixTestTiming::TBMPhaseScan() done.
[15:39:06.441] INFO: ROC 0 masking pixel 1/7
[15:39:06.441] INFO: ROC 0 masking pixel 2/4
[15:39:06.441] INFO: ----------------------------------------------------------------------
[15:39:06.441] INFO: PixTestTiming::ROCDelayScan()
[15:39:06.441] INFO: ----------------------------------------------------------------------
[15:41:05.703] INFO: ROC Delay Settings: 236
[15:41:05.703] INFO: ROC Header-Trailer/Token Delay: 11
[15:41:05.703] INFO: ROC Port 0 Delay: 4
[15:41:05.703] INFO: ROC Port 1 Delay: 5
[15:41:05.703] INFO: Functional ROC Area: 4
[15:41:05.706] INFO: Test took 119265 ms.
[15:41:05.706] INFO: PixTestTiming::ROCDelayScan() done.
[15:41:05.706] INFO: ROC 0 masking pixel 1/7
[15:41:05.707] INFO: ROC 0 masking pixel 2/4
[15:41:05.707] INFO: ----------------------------------------------------------------------
[15:41:05.707] INFO: PixTestTiming::TimingTest()
[15:41:05.707] INFO: ----------------------------------------------------------------------
[15:41:21.867] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:36.870] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:41:51.848] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:06.826] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:21.801] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:36.807] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:42:51.798] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:06.760] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:21.739] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:36.728] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:37.110] INFO: Fetched DAQ statistics. Counters are being reset now.
[15:43:37.128] INFO: ----------------------------------------------------------------------
[15:43:37.128] INFO: The fraction of properly decoded events is 100.00%: 10000000/10000000
[15:43:37.128] INFO: ----------------------------------------------------------------------
[15:43:37.128] INFO: ----------------------------------------------------------------------
[15:43:37.128] INFO: Read back bit status: 1
[15:43:37.128] INFO: ----------------------------------------------------------------------
[15:43:37.128] INFO: ----------------------------------------------------------------------
[15:43:37.128] INFO: Timings are good!
[15:43:37.128] INFO: ----------------------------------------------------------------------
[15:43:37.128] INFO: Test took 151421 ms.
[15:43:37.128] INFO: PixTestTiming::TimingTest() done.
[15:43:37.128] INFO: ROC 0 masking pixel 1/7
[15:43:37.128] INFO: ROC 0 masking pixel 2/4
[15:43:37.129] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//tbmParameters_C0a.dat
[15:43:37.129] INFO: write tbm parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//tbmParameters_C0b.dat
[15:43:37.129] INFO: PixTestTiming::doTest took 757405 ms.
[15:43:37.129] INFO: PixTestTiming::doTest() done
[15:43:37.129] INFO: ROC 0 masking pixel 1/7
[15:43:37.129] INFO: ROC 0 masking pixel 2/4
[15:43:37.129] INFO: Write out TBMPhaseScan_0_V0
[15:43:37.129] INFO: Write out TBMPhaseScan_1_V0
[15:43:37.129] INFO: Write out CombinedTBMPhaseScan_V0
[15:43:37.131] INFO: Write out ROCDelayScan3_V0
[15:43:37.132] INFO: enter test to run
[15:43:57.911] INFO: test: HighRate setting parameters: ->runsecondshotpixels=5;trimhotpixelthr=200<-
[15:43:57.911] INFO: running: highrate
[15:43:57.911] INFO: readGainPedestalParameters /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//phCalibrationFitErr35_C0.dat .. /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//phCalibrationFitErr35_C15.dat
[15:43:58.065] INFO: ----------------------------------------------------------------------
[15:43:58.065] INFO: PixTest::trimHotPixels() running for 5 seconds with 100 kHz trigger rate
[15:43:58.065] INFO: ----------------------------------------------------------------------
[15:43:58.065] INFO: THR = 200, corresponding to ~ 106.667 MHz/cm2
[15:43:58.065] INFO: edge/corner pixel THR is adjusted
[15:43:58.065] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:43:59.023] INFO: Collecting data for 5 seconds...
[15:44:04.039] INFO: Done with hot pixel readout
[15:44:15.923] INFO: PixTest:: pg_setup set to default.
[15:44:15.923] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:44:15.924] INFO: 2 hot pixels found in step 0
[15:44:16.917] INFO: Collecting data for 5 seconds...
[15:44:21.934] INFO: Done with hot pixel readout
[15:44:33.828] INFO: PixTest:: pg_setup set to default.
[15:44:33.828] WARNING: => trimBits already at highest possible threshold, 'real' hot pixel found
[15:44:33.829] INFO: 1 hot pixels found in step 1
[15:44:33.866] INFO: 1 hot pixels could not be trimmed and have been masked.
[15:44:33.870] INFO: PixTest::trimHotPixels() done
[15:44:33.870] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C0.dat
[15:44:33.875] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C1.dat
[15:44:33.881] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C2.dat
[15:44:33.887] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C3.dat
[15:44:33.893] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C4.dat
[15:44:33.898] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C5.dat
[15:44:33.904] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C6.dat
[15:44:33.909] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C7.dat
[15:44:33.915] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C8.dat
[15:44:33.920] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C9.dat
[15:44:33.925] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C10.dat
[15:44:33.931] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C11.dat
[15:44:33.936] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C12.dat
[15:44:33.941] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C13.dat
[15:44:33.947] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C14.dat
[15:44:33.952] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C15.dat
[15:44:33.958] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//defaultMaskFile.dat
[15:44:33.968] INFO: enter test to run
[15:46:05.366] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:46:05.366] INFO: running: highrate
[15:46:05.370] INFO: ----------------------------------------------------------------------
[15:46:05.370] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:46:05.370] INFO: ----------------------------------------------------------------------
[15:46:05.370] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:46:05.370] INFO: edge/corner pixel THR is adjusted
[15:46:05.370] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:46:06.328] INFO: Collecting data for 1 seconds...
[15:46:07.332] INFO: Done with hot pixel readout
[15:46:10.068] INFO: PixTest:: pg_setup set to default.
[15:46:10.069] INFO: 0 hot pixels found in step 0
[15:46:10.074] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:46:10.216] INFO: PixTest::trimHotPixels() done
[15:46:10.216] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C0.dat
[15:46:10.228] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C1.dat
[15:46:10.239] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C2.dat
[15:46:10.245] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C3.dat
[15:46:10.250] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C4.dat
[15:46:10.255] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C5.dat
[15:46:10.261] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C6.dat
[15:46:10.266] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C7.dat
[15:46:10.271] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C8.dat
[15:46:10.277] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C9.dat
[15:46:10.282] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C10.dat
[15:46:10.287] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C11.dat
[15:46:10.293] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C12.dat
[15:46:10.298] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C13.dat
[15:46:10.303] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C14.dat
[15:46:10.309] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C15.dat
[15:46:10.314] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//defaultMaskFile.dat
[15:46:10.323] INFO: enter test to run
[15:47:23.653] INFO: test: HighRate setting parameters: ->runsecondshotpixels=1;trimhotpixelthr=200<-
[15:47:23.653] INFO: running: highrate
[15:47:23.658] INFO: ----------------------------------------------------------------------
[15:47:23.658] INFO: PixTest::trimHotPixels() running for 1 seconds with 100 kHz trigger rate
[15:47:23.658] INFO: ----------------------------------------------------------------------
[15:47:23.658] INFO: THR = 200, corresponding to ~ 533.333 MHz/cm2
[15:47:23.658] INFO: edge/corner pixel THR is adjusted
[15:47:23.658] INFO: PixTestHighRate::trimHotPixels: step 0...
[15:47:24.615] INFO: Collecting data for 1 seconds...
[15:47:25.618] INFO: Done with hot pixel readout
[15:47:29.623] INFO: PixTest:: pg_setup set to default.
[15:47:29.624] INFO: 0 hot pixels found in step 0
[15:47:29.629] INFO: 0 hot pixels could not be trimmed and have been masked.
[15:47:29.718] INFO: PixTest::trimHotPixels() done
[15:47:29.718] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C0.dat
[15:47:29.728] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C1.dat
[15:47:29.734] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C2.dat
[15:47:29.739] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C3.dat
[15:47:29.745] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C4.dat
[15:47:29.751] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C5.dat
[15:47:29.756] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C6.dat
[15:47:29.762] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C7.dat
[15:47:29.767] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C8.dat
[15:47:29.773] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C9.dat
[15:47:29.778] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C10.dat
[15:47:29.784] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C11.dat
[15:47:29.789] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C12.dat
[15:47:29.795] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C13.dat
[15:47:29.800] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C14.dat
[15:47:29.806] INFO: write trim parameters into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//trimParameters35_C15.dat
[15:47:29.811] INFO: write masked pixels into /home/uicpirepix2/ProductionTestResults/M-L-2-40_FPIXTest-17C-FNAL-160615-1339_2016-06-15_13h39m_1466015983/000_FPIXTest_p17//defaultMaskFile.dat
[15:47:29.820] INFO: enter test to run
[15:47:50.605] INFO: test: Xray setting parameters: ->source=DCLowRate<-
[15:47:50.605] INFO: running: xray
[15:47:50.606] INFO: ----------------------------------------------------------------------
[15:47:50.606] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:47:50.606] INFO: ----------------------------------------------------------------------
[15:47:50.610] INFO: ROC 0 masking hot pixel 1/7
[15:47:50.610] INFO: ROC 0 masking hot pixel 2/4
[15:47:50.610] INFO: ROC 0 masking pixel 1/7
[15:47:50.610] INFO: ROC 0 masking pixel 2/4
[15:47:51.569] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:48:02.939] INFO: run duration 11 seconds, buffer almost full (81%), pausing triggers.
[15:48:32.424] INFO: Resuming triggers.
[15:48:43.793] INFO: run duration 22 seconds, buffer almost full (81%), pausing triggers.
[15:49:13.823] INFO: Resuming triggers.
[15:49:25.191] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:49:55.372] INFO: Resuming triggers.
[15:50:06.741] INFO: run duration 45 seconds, buffer almost full (81%), pausing triggers.
[15:50:36.351] INFO: Resuming triggers.
[15:50:47.718] INFO: run duration 56 seconds, buffer almost full (81%), pausing triggers.
[15:51:17.116] INFO: Resuming triggers.
[15:51:28.488] INFO: run duration 67 seconds, buffer almost full (81%), pausing triggers.
[15:51:57.841] INFO: Resuming triggers.
[15:52:09.210] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[15:52:38.651] INFO: Resuming triggers.
[15:52:50.023] INFO: run duration 90 seconds, buffer almost full (81%), pausing triggers.
[15:53:19.419] INFO: Resuming triggers.
[15:53:28.810] INFO: data taking finished, elapsed time: 100 seconds.
[15:53:53.214] INFO: PixTest:: pg_setup set to default.
[15:53:53.217] INFO: PixTestXray::doPhRun() done
[15:53:53.352] INFO: enter test to run
[15:54:20.754] INFO: test: Xray setting parameters: ->source=DCHighRate<-
[15:54:20.754] INFO: running: xray
[15:54:20.755] INFO: ----------------------------------------------------------------------
[15:54:20.755] INFO: PixTestXray::doPhRun() fParRunSeconds = 100
[15:54:20.755] INFO: ----------------------------------------------------------------------
[15:54:20.759] INFO: ROC 0 masking hot pixel 1/7
[15:54:20.759] INFO: ROC 0 masking hot pixel 2/4
[15:54:20.759] INFO: ROC 0 masking pixel 1/7
[15:54:20.759] INFO: ROC 0 masking pixel 2/4
[15:54:21.719] INFO: PixTestXray::doPhRun start TriggerLoop with trigger frequency 100 kHz, period 405 and duration 100 seconds, fEventsMax = 10000000
[15:54:28.354] INFO: run duration 6 seconds, buffer almost full (81%), pausing triggers.
[15:54:58.437] INFO: Resuming triggers.
[15:55:05.073] INFO: run duration 13 seconds, buffer almost full (81%), pausing triggers.
[15:55:35.015] INFO: Resuming triggers.
[15:55:41.651] INFO: run duration 19 seconds, buffer almost full (81%), pausing triggers.
[15:56:11.565] INFO: Resuming triggers.
[15:56:18.202] INFO: run duration 26 seconds, buffer almost full (81%), pausing triggers.
[15:56:48.023] INFO: Resuming triggers.
[15:56:54.662] INFO: run duration 33 seconds, buffer almost full (81%), pausing triggers.
[15:57:24.738] INFO: Resuming triggers.
[15:57:31.371] INFO: run duration 39 seconds, buffer almost full (81%), pausing triggers.
[15:58:01.397] INFO: Resuming triggers.
[15:58:08.030] INFO: run duration 46 seconds, buffer almost full (81%), pausing triggers.
[15:58:39.140] INFO: Resuming triggers.
[15:58:45.774] INFO: run duration 52 seconds, buffer almost full (81%), pausing triggers.
[15:59:17.183] INFO: Resuming triggers.
[15:59:23.818] INFO: run duration 59 seconds, buffer almost full (81%), pausing triggers.
[15:59:54.363] INFO: Resuming triggers.
[16:00:00.995] INFO: run duration 66 seconds, buffer almost full (81%), pausing triggers.
[16:00:31.791] INFO: Resuming triggers.
[16:00:38.423] INFO: run duration 72 seconds, buffer almost full (81%), pausing triggers.
[16:01:09.307] INFO: Resuming triggers.
[16:01:15.939] INFO: run duration 79 seconds, buffer almost full (81%), pausing triggers.
[16:01:47.230] INFO: Resuming triggers.
[16:01:53.861] INFO: run duration 85 seconds, buffer almost full (81%), pausing triggers.
[16:02:24.078] INFO: Resuming triggers.
[16:02:30.709] INFO: run duration 92 seconds, buffer almost full (81%), pausing triggers.
[16:03:00.754] INFO: Resuming triggers.
[16:03:07.384] INFO: run duration 99 seconds, buffer almost full (81%), pausing triggers.
[16:03:37.441] INFO: Resuming triggers.
[16:03:38.283] INFO: data taking finished, elapsed time: 100 seconds.
[16:03:42.470] INFO: PixTest:: pg_setup set to default.
[16:03:42.473] INFO: PixTestXray::doPhRun() done
[16:03:42.623] INFO: enter test to run
[16:06:15.294] INFO: test: HighRate no parameter change
[16:06:15.294] INFO: running: highrate
[16:06:15.295] INFO: ----------------------------------------------------------------------
[16:06:15.295] INFO: PixTestHighRate::calDelScan() ntrig = 10, vcal = 200
[16:06:15.295] INFO: ----------------------------------------------------------------------
[16:06:15.435] INFO: Expecting 768 events.
[16:06:16.569] INFO: 768 events read in total (418ms).
[16:06:16.570] INFO: Test took 1269ms.
[16:06:16.574] INFO: ROC 0 masking pixel 1/7
[16:06:16.574] INFO: ROC 0 masking pixel 2/4
[16:06:17.373] INFO: Expecting 41600 events.
[16:06:20.410] INFO: 41600 events read in total (2510ms).
[16:06:20.411] INFO: Test took 3834ms.
[16:06:20.445] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:21.176] INFO: Expecting 41600 events.
[16:06:24.371] INFO: 41600 events read in total (2668ms).
[16:06:24.372] INFO: Test took 3909ms.
[16:06:24.407] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:25.129] INFO: Expecting 41600 events.
[16:06:28.357] INFO: 41600 events read in total (2701ms).
[16:06:28.358] INFO: Test took 3932ms.
[16:06:28.394] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:29.116] INFO: Expecting 41600 events.
[16:06:32.379] INFO: 41600 events read in total (2736ms).
[16:06:32.380] INFO: Test took 3968ms.
[16:06:32.414] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:33.139] INFO: Expecting 41600 events.
[16:06:36.385] INFO: 41600 events read in total (2719ms).
[16:06:36.386] INFO: Test took 3954ms.
[16:06:36.420] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:37.143] INFO: Expecting 41600 events.
[16:06:40.390] INFO: 41600 events read in total (2720ms).
[16:06:40.391] INFO: Test took 3954ms.
[16:06:40.427] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:41.144] INFO: Expecting 41600 events.
[16:06:44.389] INFO: 41600 events read in total (2718ms).
[16:06:44.390] INFO: Test took 3944ms.
[16:06:44.424] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:45.148] INFO: Expecting 41600 events.
[16:06:48.408] INFO: 41600 events read in total (2734ms).
[16:06:48.409] INFO: Test took 3966ms.
[16:06:48.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:49.165] INFO: Expecting 41600 events.
[16:06:52.415] INFO: 41600 events read in total (2723ms).
[16:06:52.416] INFO: Test took 3954ms.
[16:06:52.450] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:53.170] INFO: Expecting 41600 events.
[16:06:56.423] INFO: 41600 events read in total (2726ms).
[16:06:56.424] INFO: Test took 3955ms.
[16:06:56.459] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:06:57.179] INFO: Expecting 41600 events.
[16:07:00.424] INFO: 41600 events read in total (2718ms).
[16:07:00.425] INFO: Test took 3946ms.
[16:07:00.459] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:01.185] INFO: Expecting 41600 events.
[16:07:04.440] INFO: 41600 events read in total (2728ms).
[16:07:04.441] INFO: Test took 3964ms.
[16:07:04.476] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:05.197] INFO: Expecting 41600 events.
[16:07:08.449] INFO: 41600 events read in total (2725ms).
[16:07:08.450] INFO: Test took 3956ms.
[16:07:08.485] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:09.209] INFO: Expecting 41600 events.
[16:07:12.458] INFO: 41600 events read in total (2722ms).
[16:07:12.459] INFO: Test took 3956ms.
[16:07:12.493] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:13.217] INFO: Expecting 41600 events.
[16:07:16.476] INFO: 41600 events read in total (2732ms).
[16:07:16.477] INFO: Test took 3966ms.
[16:07:16.512] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:17.231] INFO: Expecting 41600 events.
[16:07:20.474] INFO: 41600 events read in total (2716ms).
[16:07:20.475] INFO: Test took 3945ms.
[16:07:20.510] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:21.234] INFO: Expecting 41600 events.
[16:07:24.495] INFO: 41600 events read in total (2734ms).
[16:07:24.496] INFO: Test took 3967ms.
[16:07:24.531] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:25.255] INFO: Expecting 41600 events.
[16:07:28.502] INFO: 41600 events read in total (2720ms).
[16:07:28.503] INFO: Test took 3954ms.
[16:07:28.539] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:29.260] INFO: Expecting 41600 events.
[16:07:32.500] INFO: 41600 events read in total (2713ms).
[16:07:32.501] INFO: Test took 3942ms.
[16:07:32.536] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:33.259] INFO: Expecting 41600 events.
[16:07:36.408] INFO: 41600 events read in total (2622ms).
[16:07:36.409] INFO: Test took 3853ms.
[16:07:36.444] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:07:36.804] INFO: enter test to run
[16:07:53.773] INFO: test: HighRate no parameter change
[16:07:53.773] INFO: running: highrate
[16:07:53.774] INFO: ----------------------------------------------------------------------
[16:07:53.774] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:07:53.774] INFO: ----------------------------------------------------------------------
[16:07:53.782] INFO: ROC 0 masking pixel 1/7
[16:07:53.782] INFO: ROC 0 masking pixel 2/4
[16:07:54.392] INFO: Expecting 208000 events.
[16:08:06.303] INFO: 208000 events read in total (11384ms).
[16:08:06.306] INFO: Test took 12523ms.
[16:08:06.457] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:08:06.710] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 1 0 0 17 0 0 0
[16:08:06.710] INFO: number of red-efficiency pixels: 100 64 94 140 145 174 155 129 117 107 128 102 121 61 21 28
[16:08:06.711] INFO: number of X-ray hits detected: 68180 45423 73201 111174 112819 119772 122461 86445 83423 103480 100739 83953 83341 53491 23017 28187
[16:08:06.711] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:08:06.711] INFO: number of Vcal hits detected: 207799 207933 207905 207857 207852 207823 207843 207868 207883 207842 207870 207895 207043 207939 207979 207972
[16:08:06.711] INFO: Vcal hit fiducial efficiency (%): 100.0 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 100.0 99.9 100.0 100.0 100.0 100.0 100.0
[16:08:06.711] INFO: Vcal hit overall efficiency (%): 99.9 100.0 100.0 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.9 99.5 100.0 100.0 100.0
[16:08:06.711] INFO: X-ray hit rate [MHz/cm2]: 20.0 13.3 21.5 32.6 33.1 35.1 35.9 25.3 24.5 30.3 29.5 24.6 24.4 15.7 6.7 8.3
[16:08:06.711] INFO: PixTestHighRate::doXPixelAlive() done
[16:08:06.763] INFO: PixTest:: pg_setup set to default.
[16:08:06.774] INFO: enter test to run
[16:09:15.508] INFO: test: HighRate no parameter change
[16:09:15.508] INFO: running: highrate
[16:09:15.509] INFO: ----------------------------------------------------------------------
[16:09:15.509] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:09:15.509] INFO: ----------------------------------------------------------------------
[16:09:15.518] INFO: ROC 0 masking pixel 1/7
[16:09:15.518] INFO: ROC 0 masking pixel 2/4
[16:09:16.124] INFO: Expecting 208000 events.
[16:09:29.808] INFO: 208000 events read in total (13157ms).
[16:09:29.813] INFO: Test took 14295ms.
[16:09:30.108] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:09:30.412] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 1 0 0 17 0 0 0
[16:09:30.412] INFO: number of red-efficiency pixels: 217 146 312 481 369 515 454 408 246 319 363 331 332 168 49 84
[16:09:30.412] INFO: number of X-ray hits detected: 138026 93147 149040 224489 230087 242823 248459 175026 170485 209998 205329 171040 170397 110225 47399 57628
[16:09:30.412] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:09:30.412] INFO: number of Vcal hits detected: 207678 207849 207659 207482 207606 207423 207512 207547 207744 207616 207613 207659 206819 207827 207951 207915
[16:09:30.412] INFO: Vcal hit fiducial efficiency (%): 99.9 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 100.0 100.0
[16:09:30.412] INFO: Vcal hit overall efficiency (%): 99.8 99.9 99.8 99.8 99.8 99.7 99.8 99.8 99.9 99.8 99.8 99.8 99.4 99.9 100.0 100.0
[16:09:30.412] INFO: X-ray hit rate [MHz/cm2]: 40.5 27.3 43.7 65.8 67.4 71.2 72.8 51.3 50.0 61.6 60.2 50.1 49.9 32.3 13.9 16.9
[16:09:30.412] INFO: PixTestHighRate::doXPixelAlive() done
[16:09:30.460] INFO: PixTest:: pg_setup set to default.
[16:09:30.474] INFO: enter test to run
[16:09:55.196] INFO: test: HighRate no parameter change
[16:09:55.196] INFO: running: highrate
[16:09:55.197] INFO: ----------------------------------------------------------------------
[16:09:55.197] INFO: PixTestHighRate::xPixelAlive() ntrig = 50, vcal = 200
[16:09:55.197] INFO: ----------------------------------------------------------------------
[16:09:55.206] INFO: ROC 0 masking pixel 1/7
[16:09:55.206] INFO: ROC 0 masking pixel 2/4
[16:09:55.816] INFO: Expecting 208000 events.
[16:10:11.363] INFO: 208000 events read in total (15020ms).
[16:10:11.371] INFO: Test took 16165ms.
[16:10:11.813] INFO: Fetched DAQ statistics. Counters are being reset now.
[16:10:12.162] INFO: number of dead pixels (per ROC): 2 0 0 0 0 0 0 0 0 1 0 0 17 0 0 0
[16:10:12.162] INFO: number of red-efficiency pixels: 378 287 728 1040 867 1351 1106 820 542 692 764 684 642 329 89 122
[16:10:12.162] INFO: number of X-ray hits detected: 207743 139916 224991 338634 346272 365878 374186 264511 256716 317619 307955 259086 256435 165502 70974 88077
[16:10:12.162] INFO: number of triggers sent (total per ROC): 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000 208000
[16:10:12.162] INFO: number of Vcal hits detected: 207468 207682 207017 206666 206974 206211 206672 206975 207403 207164 207113 207193 206470 207641 207907 207872
[16:10:12.162] INFO: Vcal hit fiducial efficiency (%): 99.8 99.9 99.6 99.4 99.5 99.2 99.4 99.6 99.7 99.7 99.6 99.7 99.7 99.8 100.0 99.9
[16:10:12.162] INFO: Vcal hit overall efficiency (%): 99.7 99.8 99.5 99.4 99.5 99.1 99.4 99.5 99.7 99.6 99.6 99.6 99.3 99.8 100.0 99.9
[16:10:12.162] INFO: X-ray hit rate [MHz/cm2]: 60.9 41.0 65.9 99.3 101.5 107.2 109.7 77.5 75.2 93.1 90.3 75.9 75.2 48.5 20.8 25.8
[16:10:12.162] INFO: PixTestHighRate::doXPixelAlive() done
[16:10:12.210] INFO: PixTest:: pg_setup set to default.
[16:10:12.224] INFO: enter test to run
[16:10:24.580] INFO: test: exit no parameter change
[16:10:24.960] QUIET: Connection to board 33 closed.
[16:10:24.961] INFO: pXar: this is the end, my friend